Test failures with recent pull

[dj-mcg]

Hi @pierrebai-adsk - I have a question inline in one of your changes here:
f17afcc#r150119645

Bottom line, several tests are failing when saving a maya scene due to the MayaStagesSubject being in an unexpected state. I'm still poking at it but I wanted to run it past you to see if you had any thoughts/ideas of what might be wrong in my environment that could be causing this issue. Thanks!

[pierrebai-adsk]

Hi Dan, The changes that comes to mind are changes we made in Maya, so they cannot affect you right now. The fact that this happens at Pixar but not for us is strange and concerning. I'll ask around, maybe someone else here has the same issues but kept them private? Pierre B.

[dj-mcg]

Would you expect that MayaStagesSubject::clearListeners would be getting called as part of the OpenMaya::saveAs call in the test script, therefore putting that object in the correct state prior to the onStageSet notice getting triggered and handled?

[pierrebai-adsk]

Quick look around and I see that MayaUsdProxyShapeBase sends out a MayaUsdProxyStageInvalidateNotice when the filePathAttr is dirty, and that MayaStagesSubject::onStageInvalidate clears the listener in response to that.

So I'd say yes? If you do a SaveAs, or generally save a stage under a new file name, the file path changes and would cause the listeners to be cleared. That code has existed for a long time, so IDK why it would only start to cause problems now and only for you.

[seando-adsk]

@dj-mcg To help us narrow down the problem can you tell us what version of Maya, USD and what platform you are using? And confirm that this would be a RelWithDebInfo build.

Thanks, Sean

[dj-mcg]

This is in Maya 2023, but we are using the most recent internal dev build of USD. We are on Linux EL9

This is new behavior in the most recent pull of Autodesk MayaUsd changes, but the current changelist is rather large given that it contains about a month's worth of work. Last pull was on 11/4

[dj-mcg]

I should also mention that this is happening within our build environment as we merge the mayaUsd code directly into our tree, so I'm using our SCons-based build system rather than using the makefiles in the build. I'm wondering if there may be some sort of build option or environment variable I need to enable for whatever behavior change was introduced regarding stage observation or perhaps ProxyShapeBase (which is involved in sending the notices that MayaStagesSubject is handling)

[pierrebai-adsk]

Is there something special we need to do to make TF_VERIFY cause a hard failure? Even with debug builds of both Maya and MayaUSD, when I run the test the TF_VERIFY prints something in the output but does not cause the test to fail. Is the Pixar build system parsing the output and failing when detecting "Error:" or something similar? I get in the test output:

3: Error: Failed verification: ' UsdStageMap::getInstance().isDirty() '
3: Error: Failed verification: ' _stageListeners.empty() '
3: File read in  0.035 seconds.
3: .
3: ----------------------------------------------------------------------
3: Ran 1 test in 1.020s
3: 
3: OK
1/1 Test #3: testMayaUsdCreateStageInMayaRef ...   Passed   28.57 sec

[dj-mcg]

Oh interesting - so these verifies are failing in the test for you as well? That's good to know.

Yes, we do auto-fail tests when we encounter any failed verifies, or coding or runtime errors. I can disable this, but I'm fairly certain I run into a different problem if I do. I can respond with that here.

One question, though - is it ok that these verifies are failing? If so, why are they there? If not, maybe the test needs to be updated?

[pierrebai-adsk]

Like I said earlier, IDK what the intention were when these assertions were written - obviously they're failing now without any apparent ill effect.

(I did have to fix that when a fatal error was logged MayauSD would deadlock on exit, that's where I spent my time so far. Im surprised it does not cause problems for your setup, but maybe the behavior is different on Linux, the bug is very dependent on the order of destruction of global variables. PR here: #4043)

[dj-mcg]

When I ignore the verifies, the test seems to pass but crashes on exit. Is this similar to the issue you're describing? Here's the stack I'm seeing:

Stack trace:
/lib64/libc.so.6(+0x1598c1) [0x7f32f9d598c1]
Tstack::getTopElement(void*) const
Tstack::popElement(void*)
TcommandEngine::popLanguageContext(TcommandLanguageContext&)
TpythonInterpreter::dispatchMayaCommand(TmetaCommand&, _object*, _object*)
pythonDispatchMayaCommand(TmetaCommand&, _object*, _object*)
/dist/sw/maya/2023.update3/lib/libExtensionLayer.so(+0x3541f7) [0x7f32ddac41f7]
/dist/d2sets/fedora-11-x86_64/vfx2022.005/lib/libpython3.9.so.1.0(+0x19c43c) [0x7f32fa55443c]
_PyObject_MakeTpCall
_PyEval_EvalFrameDefault
_PyFunction_Vectorcall
_PyEval_EvalFrameDefault
/dist/d2sets/fedora-11-x86_64/vfx2022.005/lib/libpython3.9.so.1.0(+0x1d6864) [0x7f32fa58e864]
_PyEval_EvalCodeWithName
PyEval_EvalCode
/dist/d2sets/fedora-11-x86_64/vfx2022.005/lib/libpython3.9.so.1.0(+0x2b28d3) [0x7f32fa66a8d3]
/dist/d2sets/fedora-11-x86_64/vfx2022.005/lib/libpython3.9.so.1.0(+0x1ac984) [0x7f32fa564984]
_PyEval_EvalFrameDefault
/dist/d2sets/fedora-11-x86_64/vfx2022.005/lib/libpython3.9.so.1.0(+0x1d6864) [0x7f32fa58e864]
_PyEval_EvalCodeWithName
PyEval_EvalCode
/dist/d2sets/fedora-11-x86_64/vfx2022.005/lib/libpython3.9.so.1.0(+0x285cdd) [0x7f32fa63dcdd]
/dist/d2sets/fedora-11-x86_64/vfx2022.005/lib/libpython3.9.so.1.0(+0x29d1bb) [0x7f32fa6551bb]
/dist/d2sets/fedora-11-x86_64/vfx2022.005/lib/libpython3.9.so.1.0(+0x11dd0f) [0x7f32fa4d5d0f]
PyRun_SimpleFileExFlags
Py_RunMain
Py_Main
main
/lib64/libc.so.6(+0x29590) [0x7f32f9c29590]
__libc_start_main

[pierrebai-adsk]

No, completely different. The bug I fixed was a deadlock that prevented the test from ever exiting. Yours seems like a destruction order problem, might be due to Python holding a reference to an object, I've seen these kind of crash when a test fails in the past, when the Python test happened to hold an object. When Python exits, the object is already gone and Maya crashes.

[dj-mcg]

I was trying to figure out what was different about the old version of this test (testCreateStageInMayaRef) and the one with the most recent changes. It turns out that the onStageInvalidate notice is not getting fired when calling OM.MFileIO.saveAs when mayaUsd_SerializedUsdEditsLocation is set to SAVE_USD_TO_MAYA_SCENE. The old test would set this option to USD_EXPORT_SETTING, which did cause the onStageInvalidate to fire. Stage invalidation clears the listeners in MayaStagesSubject which allows the verifies to pass. However, I still run into the crash I mentioned in the above thread

Could this potentially be a bug in the proxyShapeBase?

[pierrebai-adsk]

Yes, I did change that since setting it to USD_EXPORT_SETTING made no sense at all, it is entirely unrelated. Saving a stage inside the Maya scene does not set the file path attribute since it is not saved to a file. It is still unclear to me that the assertions are necessary and what they are meant to protect against.

[csyshing]

+1 for this kind of assertion error. In fact we have seen this error for a long time (> 2 years).

I did attempt to simplify the production scene, hoping I could get a simple enough reproducible example to report but unfortunately it happens a bit randomly in production.

It's hard to reproduce without our proprietary toolset and dataset, I had not seen anyone else report this (until now!), I thought it might because our studio has a special setup that triggered this error.

Out production setup indeed has multiple proxy shape exist at the same time, was thinking that could be the reason because MayaStagesSubject::clearListeners() does not bind to any proxy shape instance, but I have not been able to get a chance to verify that.

[pierrebai-adsk]

When reading the code for this bug, I was wondering what would be the behavior when multiple stages are present. I felt the assertions might not be entirely correct when there is more than one stage.