SlicerPreview Nightly build fail

[DouSam]

When we open the CDash to see if the tests are running correctly, which means the tutorials are generated correctly, we see the two tests fail.
For example, this day, https://slicer.cdash.org/viewTest.php?onlyfailed&buildid=3744956
Besides the tests giving an "OK," the test is still failing with this error

Ran 2 tests in 68.940s

OK
Switch to module:  ""
Switch to module:  ""
error: [/Users/svc-dashboard/D/P/A/Slicer-build/bin/Slicer.app/Contents/MacOS/./Slicer] exit abnormally - Report the problem.

And I don't know why the test is exiting in this way.

When I run the tests on my computer, I see no errors in the log.
When I run a tutorial, sometimes after running all the processes, Slicer just closes and doesn't log anything about it, similar to what the Africam team reported. Should we open this on the forum? @lassoan

[miiranta]

I managed to replicate the error here.

1. Build the Slicer directly from the Slicer repository (might not be necessary, also takes forever).
2. Build TutorialMaker with Cmake/make

cmake /path/to/TutorialMaker -G "Unix Makefiles" -DSlicer_DIR=/path/to/Slicer-build/Slicer-build

3. Run the tests:

./Slicer \
--testing \
--additional-module-paths /path/to/TutorialMaker-build-test/lib/Slicer-5.9/qt-scripted-modules \
--python-code "import TutorialMaker; t = TutorialMaker.TutorialMakerTest(); t.runTest()"

./Slicer \
--no-splash \
--testing \
--launcher-additional-settings /path/to/TutorialMaker-build-test/AdditionalLauncherSettings.ini \
--no-main-window \
--disable-cli-modules \
--additional-module-path /path/to/TutorialMaker-build-test/lib/Slicer-5.9/qt-scripted-modules \
--additional-module-paths /path/to/TutorialMaker-build-test/lib/Slicer-5.9/qt-scripted-modules \
--additional-module-paths /path/to/TutorialMaker-build-test/lib/Slicer-5.9/qt-loadable-modules \
--python-code "import slicer.testing; slicer.testing.runUnitTest(['/path/to/TutorialMaker-build-test/TutorialMaker', '/path/to/TutorialMaker/TutorialMaker'], 'qSlicerTutorialMakerModuleGenericTest')"

You should see:

Switch to module: ""
Switch to module: ""
error: [/home/lucas-miranda/Desktop/SlicerTest/Slicer-build/Slicer-build/bin/./SlicerApp-real] exit abnormally - Report the problem.

The actual tests pass, you can verify that in the link you sent in the issue description. The problem is something to do with the clean up after the tests are executed, when slicer tries to "close" TutorialMaker. I'm still trying to figure out why TutorialMaker creates an exception while other modules don't.

[DouSam]

I think we can open an issue on the ExtensionsIndex repository. But first, we have a error on the tests, you can see here the last build.
If you click on the "Failed" you can see the log,

ERROR: runTest (TutorialMaker.TutorialMakerTest.runTest)
Run as few or as many tests as needed here.
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/work/Preview/S-0-E-b/TutorialMaker-build/lib/Slicer-5.9/qt-scripted-modules/TutorialMaker.py", line 340, in setUp
    Lib.TutorialUtils.Util.verifyOutputFolders(self)
TypeError: Util.verifyOutputFolders() takes 0 positional arguments but 1 was given

Since we have changed the Utils to be a static class on the last version, this problem is probably related to that.

[miiranta]

The error "TypeError: Util.verifyOutputFolders() takes 0 positional arguments but 1 was given", by first glance, you just need to remove "self" (Lib.TutorialUtils.Util.verifyOutputFolders(self) to Lib.TutorialUtils.Util.verifyOutputFolders()) and it should work. This one is not related to the one we were discussing tho.

Speaking of the original error, so far i was not able to fix it.
Some things i found that might help:

1. It's something related to the unloading of the module and it seems to be a problem with slicer itself.
   It can be either:

• An object that was destroyed and it tries to destroy it again.
• An object that should be destroyed is not destroyed.

2. It happens if you instantiate TutorialEditor and probably related to QT objects that are not handled well.

3. Probably a bug in PythonQT API from Slicer.

For the best if we open an Issue in Slicer, should we?

[miiranta]

An update:

I still wasn't able to fully figure out how to solve this error, but i got some extra clues that might help someone else.

I still think it might be related to the QTtimer handling, since its done poorly in TutorialMaker. The timers are not killed when the module is closed, and that might be causing some issues in theory, but i couldn't find a way to confirm that.

First of all, this time i built Slicer in debug mode for Windows instead of the normal Linux version, following the official instructions:

https://slicer.readthedocs.io/en/latest/developer_guide/build_instructions/windows.html

cmake -G "Visual Studio 17 2022" -A x64 ^
  -DQt5_DIR:PATH="path\to\Qt5" ^
  -S ./SLICER_SOURCE ^
  -B ./SLICER_BUILD

cmake --build ./SLICER_BUILD --config Debug

Also built TutorialMaker:

cd "path\to\TUTORIALMAKER_BUILD"

cmake -G "Visual Studio 17 2022" -A x64 -DSlicer_DIR:PATH="path\to\Slicer-build" -S ..\TUTORIALMAKER_SOURCE -B .

cmake --build . --config Debug

And ran the tests:

ctest -R py_TutorialMaker -V -C Debug --output-on-failure --debug

Then, i got a more detailed error message:

Ran 2 tests in 6.704s

OK
Switch to module:  ""
Switch to module:  ""
error: [C:/Slicer-debug/SLICER_BUILD/Slicer-build/bin/Debug/SlicerApp-real.exe] exit abnormally - Report the problem.

...

R:/winlibs64ucrt_stage/48568.cmake/cmake-3.29.2/Source/cmCTest.cxx:1030 Errors while running CTest

R:/winlibs64ucrt_stage/48568.cmake/cmake-3.29.2/Source/cmCTest.cxx:2997 Running a test(s) failed returning : 8

c:\Slicer-debug\TUTORIALMAKER_BUILD>

First thing i noticed is that the returning error code is 8, which is odd and doesn't seem to be documented anywhere. Couldn't find anything that could explain that in TutorialMaker and Slicer code.

Second thing i noticed is that Slicer was showing a strange error before running the tests. It doesnt appear to be related to TutorialMaker (it was happening also in other tests), but for the sake of completeness, here it is:

Generic Warning: In vtkOpenGLState.cxx, line 197
Error in cache state for GL_DRAW_FRAMEBUFFER_BINDING


Generic Warning: In vtkOpenGLState.cxx, line 263
at stack loc
 at vtksys::SystemInformationImplementation::GetProgramStack in C:\Slicer-debug\SLICER_BUILD\VTK\Utilities\KWSys\vtksys\SystemInformation.cxx line 3987
 at vtksys::SystemInformation::GetProgramStack in C:\Slicer-debug\SLICER_BUILD\VTK\Utilities\KWSys\vtksys\SystemInformation.cxx line 829
 at vtkOpenGLState::CheckState in C:\Slicer-debug\SLICER_BUILD\VTK\Rendering\OpenGL2\vtkOpenGLState.cxx line 262
 at vtkOpenGLState::SetEnumState in C:\Slicer-debug\SLICER_BUILD\VTK\Rendering\OpenGL2\vtkOpenGLState.cxx line 973
 at vtkOpenGLState::vtkglDisable in C:\Slicer-debug\SLICER_BUILD\VTK\Rendering\OpenGL2\vtkOpenGLState.cxx line 1303
 at vtkOpenGLRenderWindow::GetZbufferData in C:\Slicer-debug\SLICER_BUILD\VTK\Rendering\OpenGL2\vtkOpenGLRenderWindow.cxx line 
2516
 at vtkRenderWindow::GetZbufferDataAtPoint in C:\Slicer-debug\SLICER_BUILD\VTK\Rendering\Core\vtkRenderWindow.h line 535       
 at vtkRenderer::GetZ in C:\Slicer-debug\SLICER_BUILD\VTK\Rendering\Core\vtkRenderer.cxx line 1492
 at vtkWorldPointPicker::Pick in C:\Slicer-debug\SLICER_BUILD\VTK\Rendering\Core\vtkWorldPointPicker.cxx line 36
 at vtkMRMLThreeDViewInteractorStyle::QuickPick in C:\Slicer-debug\SLICER_SOURCE\Libs\MRML\DisplayableManager\vtkMRMLThreeDViewInteractorStyle.cxx line 179
 at vtkMRMLThreeDViewInteractorStyle::DelegateInteractionEventToDisplayableManagers in C:\Slicer-debug\SLICER_SOURCE\Libs\MRML\DisplayableManager\vtkMRMLThreeDViewInteractorStyle.cxx line 128
 at vtkMRMLViewInteractorStyle::DelegateInteractionEventToDisplayableManagers in C:\Slicer-debug\SLICER_SOURCE\Libs\MRML\DisplayableManager\vtkMRMLViewInteractorStyle.cxx line 285
 at vtkMRMLViewInteractorStyle::CustomProcessEvents in C:\Slicer-debug\SLICER_SOURCE\Libs\MRML\DisplayableManager\vtkMRMLViewInteractorStyle.cxx line 458
 at vtkCallbackCommand::Execute in C:\Slicer-debug\SLICER_BUILD\VTK\Common\Core\vtkCallbackCommand.cxx line 30
 at vtkSubjectHelper::InvokeEvent in C:\Slicer-debug\SLICER_BUILD\VTK\Common\Core\vtkObject.cxx line 639
 at vtkObject::InvokeEvent in C:\Slicer-debug\SLICER_BUILD\VTK\Common\Core\vtkObject.cxx line 819
 at vtkObject::InvokeEvent in C:\Slicer-debug\SLICER_BUILD\VTK\Common\Core\vtkObject.h line 223
 at QVTKRenderWindowAdapter::QVTKInternals::resize in C:\Slicer-debug\SLICER_BUILD\VTK\GUISupport\Qt\QVTKRenderWindowAdapter.cxx line 221
 at QVTKRenderWindowAdapter::resize in C:\Slicer-debug\SLICER_BUILD\VTK\GUISupport\Qt\QVTKRenderWindowAdapter.cxx line 550     
 at QVTKOpenGLNativeWidget::updateSize in C:\Slicer-debug\SLICER_BUILD\VTK\GUISupport\Qt\QVTKOpenGLNativeWidget.cxx line 269   
 at QVTKOpenGLNativeWidget::qt_static_metacall in C:\Slicer-debug\SLICER_BUILD\VTK-build\GUISupport\Qt\GUISupportQt_autogen\include_Debug\EWIEGA46WW\moc_QVTKOpenGLNativeWidget.cpp line 77
 at QTextStream::realNumberPrecision
 at QTextStream::realNumberPrecision
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QVTKOpenGLNativeWidget::event in C:\Slicer-debug\SLICER_BUILD\VTK\GUISupport\Qt\QVTKOpenGLNativeWidget.cxx line 321        
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at qSlicerApplication::notify in C:\Slicer-debug\SLICER_SOURCE\Base\QTGUI\qSlicerApplication.cxx line 559
 at QTextStream::realNumberPrecision
 at QTextStream::realNumberPrecision
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at qSlicerApplication::notify in C:\Slicer-debug\SLICER_SOURCE\Base\QTGUI\qSlicerApplication.cxx line 559
 at QTextStream::realNumberPrecision
 at QTextStream::realNumberPrecision
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at qSlicerApplication::notify in C:\Slicer-debug\SLICER_SOURCE\Base\QTGUI\qSlicerApplication.cxx line 559
 at QTextStream::realNumberPrecision
 at QTextStream::realNumberPrecision
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at qSlicerApplication::notify in C:\Slicer-debug\SLICER_SOURCE\Base\QTGUI\qSlicerApplication.cxx line 559
 at QTextStream::realNumberPrecision
 at QTextStream::realNumberPrecision
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at qSlicerApplication::notify in C:\Slicer-debug\SLICER_SOURCE\Base\QTGUI\qSlicerApplication.cxx line 559
 at QTextStream::realNumberPrecision
 at QTextStream::realNumberPrecision
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QTextStream::realNumberPrecision
 at QTextStream::realNumberPrecision
 at QTextStream::realNumberPrecision
 at QTextStream::realNumberPrecision
 at QTextStream::realNumberPrecision
 at QTextStream::realNumberPrecision
 at QTextStream::realNumberPrecision
 at QTextStream::realNumberPrecision
 at QTextStream::realNumberPrecision
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at qSlicerApplication::notify in C:\Slicer-debug\SLICER_SOURCE\Base\QTGUI\qSlicerApplication.cxx line 559
 at QTextStream::realNumberPrecision
 at QTextStream::realNumberPrecision
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QTextStream::realNumberPrecision
 at QTextStream::realNumberPrecision
 at QTextStream::realNumberPrecision
 at QTextStream::realNumberPrecision
 at QTextStream::realNumberPrecision
 at QTextStream::realNumberPrecision
 at QTextStream::realNumberPrecision
 at QTextStream::realNumberPrecision
 at QTextStream::realNumberPrecision
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at QStyleAnimation::frameRate
 at qSlicerApplication::notify in C:\Slicer-debug\SLICER_SOURCE\Base\QTGUI\qSlicerApplication.cxx line 559
 at QTextStream::realNumberPrecision
 at QTextStream::realNumberPrecision
 at QTextStream::realNumberPrecision
 at QTextStream::realNumberPrecision
 at qt_plugin_instance
 at QTextStream::realNumberPrecision
 at qt_plugin_instance
 at QTextStream::realNumberPrecision
 at QTextStream::realNumberPrecision
 at QTextStream::realNumberPrecision
 at QOpenGLFunctions_4_3_Compatibility::glLightModeli
 at QStyleAnimation::frameRate
 at qSlicerCoreApplication::exec in C:\Slicer-debug\SLICER_SOURCE\Base\QTCore\qSlicerCoreApplication.cxx line 1077
 at `anonymous namespace'::SlicerAppMain in C:\Slicer-debug\SLICER_SOURCE\Applications\SlicerApp\Main.cxx line 64
 at main in C:\Slicer-debug\SLICER_SOURCE\Base\QTApp\qSlicerApplicationMainWrapper.cxx line 55
 at invoke_main in D:\a\_work\1\s\src\vctools\crt\vcstartup\src\startup\exe_common.inl line 79
 at __scrt_common_main_seh in D:\a\_work\1\s\src\vctools\crt\vcstartup\src\startup\exe_common.inl line 288
 at __scrt_common_main in D:\a\_work\1\s\src\vctools\crt\vcstartup\src\startup\exe_common.inl line 331
 at mainCRTStartup in D:\a\_work\1\s\src\vctools\crt\vcstartup\src\startup\exe_main.cpp line 17
 at BaseThreadInitThunk
 at RtlUserThreadStart

After trying to remove some modules from tutorialmaker, i found out that the error only happens when the TutorialEditor module is instantiated. Related to that, i found an interesting comment in the TutorialEditor code (TutorialMaker.py):

    def cleanup(self):
        # that will make an exception: AttributeError: 'NoneType' object has no attribute 'exitTutorialEditor'
        # self.logic.exitTutorialEditor()
        """
        Called when the application closes and the module widget is destroyed.
        """
        return

I also tried to run the raw test command with gdb to see if i could get a stack trace, but it didn't help much:

-------------------------------------------
path: ['C:/Slicer-debug/TUTORIALMAKER_BUILD/TutorialMaker', 'C:/Slicer-debug/TUTORIALMAKER_SOURCE/TutorialMaker']
testname: TutorialMaker
-------------------------------------------
runTest (slicer.ScriptedLoadableModule.ScriptedLoadableModuleTest.runTest)
Run a default selection of tests here. ... ok
runTest (TutorialMaker.TutorialMakerTest.runTest)
QWindowsWindow::setGeometry: Unable to set geometry 1920x1080+542+235 (frame: 1936x1119+534+204) on QWidgetWindow/"qSlicerMainWindowWindow" on "\\.\DISPLAY1". Resulting geometry: 1920x1061+542+235 (frame: 1936x1100+534+204) margins: 8, 31, 8, 8 minimum size: 949x396 MINMAXINFO maxSize=0,0 maxpos=0,0 mintrack=965,435 maxtrack=0,0)
Run as few or as many tests as needed here. ... ok

----------------------------------------------------------------------
Ran 2 tests in 3.315s

OK
Switch to module:  ""
Switch to module:  ""
[New Thread 10868.0xc60]
error: [C:/Slicer-debug/SLICER_BUILD/Slicer-build/bin/Debug/SlicerApp-real.exe] exit abnormally - Report the problem.
Reading symbols from C:\Windows\SysWOW64\kernel.appcore.dll...
(No debugging symbols found in C:\Windows\SysWOW64\kernel.appcore.dll)

Thread 1 hit Breakpoint 5.1, 0x763f6a23 in KERNEL32!ExitProcess () from C:\Windows\SysWOW64\kernel32.dll
(gdb) bt
#0  0x763f6a23 in KERNEL32!ExitProcess () from C:\Windows\SysWOW64\kernel32.dll
#1  0x0109605b in ?? ()
#2  0x01096025 in ?? ()
#3  0x0109617a in ?? ()
#4  0x0108fbd7 in ?? ()
#5  0x763efcc9 in KERNEL32!BaseThreadInitThunk () from C:\Windows\SysWOW64\kernel32.dll
#6  0x76fb82ae in ntdll!RtlGetAppContainerNamedObjectPath () from C:\Windows\SysWOW64\ntdll.dll
#7  0x76fb827e in ntdll!RtlGetAppContainerNamedObjectPath () from C:\Windows\SysWOW64\ntdll.dll
#8  0x00000000 in ?? ()
(gdb) bt full
#0  0x763f6a23 in KERNEL32!ExitProcess () from C:\Windows\SysWOW64\kernel32.dll
No symbol table info available.
#1  0x0109605b in ?? ()
No symbol table info available.
#2  0x01096025 in ?? ()
No symbol table info available.
#3  0x0109617a in ?? ()
No symbol table info available.
#4  0x0108fbd7 in ?? ()
No symbol table info available.
#5  0x763efcc9 in KERNEL32!BaseThreadInitThunk () from C:\Windows\SysWOW64\kernel32.dll
No symbol table info available.
#6  0x76fb82ae in ntdll!RtlGetAppContainerNamedObjectPath () from C:\Windows\SysWOW64\ntdll.dll
No symbol table info available.
#7  0x76fb827e in ntdll!RtlGetAppContainerNamedObjectPath () from C:\Windows\SysWOW64\ntdll.dll
No symbol table info available.
#8  0x00000000 in ?? ()
No symbol table info available.
(gdb) info threads
  Id   Target Id           Frame 
* 1    Thread 10868.0x2b74 0x763f6a23 in KERNEL32!ExitProcess () from C:\Windows\SysWOW64\kernel32.dll
  2    Thread 10868.0x1300 0x76fc4f3c in ntdll!ZwWaitForWorkViaWorkerFactory () from C:\Windows\SysWOW64\ntdll.dll
  3    Thread 10868.0x22e8 0x76fc4f3c in ntdll!ZwWaitForWorkViaWorkerFactory () from C:\Windows\SysWOW64\ntdll.dll
  4    Thread 10868.0x2944 0x76fc4f3c in ntdll!ZwWaitForWorkViaWorkerFactory () from C:\Windows\SysWOW64\ntdll.dll
  5    Thread 10868.0xc60  0x76fc4f3c in ntdll!ZwWaitForWorkViaWorkerFactory () from C:\Windows\SysWOW64\ntdll.dll
(gdb) thread apply all bt

Thread 5 (Thread 10868.0xc60):
#0  0x76fc4f3c in ntdll!ZwWaitForWorkViaWorkerFactory () from C:\Windows\SysWOW64\ntdll.dll
#1  0x76f85cd0 in ntdll!TpCallbackIndependent () from C:\Windows\SysWOW64\ntdll.dll
#2  0x763efcc9 in KERNEL32!BaseThreadInitThunk () from C:\Windows\SysWOW64\kernel32.dll
#3  0x76fb82ae in ntdll!RtlGetAppContainerNamedObjectPath () from C:\Windows\SysWOW64\ntdll.dll
#4  0x76fb827e in ntdll!RtlGetAppContainerNamedObjectPath () from C:\Windows\SysWOW64\ntdll.dll
#5  0x00000000 in ?? ()

Thread 4 (Thread 10868.0x2944):
#0  0x76fc4f3c in ntdll!ZwWaitForWorkViaWorkerFactory () from C:\Windows\SysWOW64\ntdll.dll
#1  0x76f85cd0 in ntdll!TpCallbackIndependent () from C:\Windows\SysWOW64\ntdll.dll
#2  0x763efcc9 in KERNEL32!BaseThreadInitThunk () from C:\Windows\SysWOW64\kernel32.dll
#3  0x76fb82ae in ntdll!RtlGetAppContainerNamedObjectPath () from C:\Windows\SysWOW64\ntdll.dll
#4  0x76fb827e in ntdll!RtlGetAppContainerNamedObjectPath () from C:\Windows\SysWOW64\ntdll.dll
#5  0x00000000 in ?? ()

Thread 3 (Thread 10868.0x22e8):
#0  0x76fc4f3c in ntdll!ZwWaitForWorkViaWorkerFactory () from C:\Windows\SysWOW64\ntdll.dll
#1  0x76f85cd0 in ntdll!TpCallbackIndependent () from C:\Windows\SysWOW64\ntdll.dll
#2  0x763efcc9 in KERNEL32!BaseThreadInitThunk () from C:\Windows\SysWOW64\kernel32.dll
#3  0x76fb82ae in ntdll!RtlGetAppContainerNamedObjectPath () from C:\Windows\SysWOW64\ntdll.dll
#4  0x76fb827e in ntdll!RtlGetAppContainerNamedObjectPath () from C:\Windows\SysWOW64\ntdll.dll
#5  0x00000000 in ?? ()

Thread 2 (Thread 10868.0x1300):
#0  0x76fc4f3c in ntdll!ZwWaitForWorkViaWorkerFactory () from C:\Windows\SysWOW64\ntdll.dll
#1  0x76f85cd0 in ntdll!TpCallbackIndependent () from C:\Windows\SysWOW64\ntdll.dll
#2  0x763efcc9 in KERNEL32!BaseThreadInitThunk () from C:\Windows\SysWOW64\kernel32.dll
#3  0x76fb82ae in ntdll!RtlGetAppContainerNamedObjectPath () from C:\Windows\SysWOW64\ntdll.dll
#4  0x76fb827e in ntdll!RtlGetAppContainerNamedObjectPath () from C:\Windows\SysWOW64\ntdll.dll
#5  0x00000000 in ?? ()

--Type <RET> for more, q to quit, c to continue without paging--thread apply all bt full
Thread 1 (Thread 10868.0x2b74):
#0  0x763f6a23 in KERNEL32!ExitProcess () from C:\Windows\SysWOW64\kernel32.dll
#1  0x0109605b in ?? ()
#2  0x01096025 in ?? ()
#3  0x0109617a in ?? ()
#4  0x0108fbd7 in ?? ()
#5  0x763efcc9 in KERNEL32!BaseThreadInitThunk () from C:\Windows\SysWOW64\kernel32.dll
#6  0x76fb82ae in ntdll!RtlGetAppContainerNamedObjectPath () from C:\Windows\SysWOW64\ntdll.dll
#7  0x76fb827e in ntdll!RtlGetAppContainerNamedObjectPath () from C:\Windows\SysWOW64\ntdll.dll
#8  0x00000000 in ?? ()
(gdb) info registers
eax            0x0                 0
ecx            0x1                 1
edx            0x0                 0
ebx            0x2a5000            2772992
esp            0x19fedc            0x19fedc
ebp            0x19fedc            0x19fedc
esi            0x1                 1
edi            0x589140            5804352
eip            0x763f6a23          0x763f6a23 <KERNEL32!ExitProcess+3>
eflags         0x246               [ PF ZF IF ]
cs             0x23                35
ss             0x2b                43
ds             0x2b                43
es             0x2b                43
fs             0x53                83
gs             0x2b                43
(gdb)

Lastly, i tried to play around with some extra debug outputs i added in Slicer's code. Helped map the functions that might be involved in the crash:

qSlicerAbstractModuleWidget::~qSlicerAbstractModuleWidget
qSlicerModulePanel::setModule 
qSlicerModuleSelectorToolBar::actionSelected
qSlicerModulesMenu::actionSelected

Slicer has a bug of showing 2 times the module change:

Switch to module:  ""
Switch to module:  "" 

This bug is also related to the listed functions. I was able to prevent it during testing by adding a check to avoid switching to the same module again in qSlicerModuleSelectorToolBar::actionSelected.
It doesn't solve the crash, but might be related.

[miiranta]

Another update:

Removing the instantiation of TutorialEditor at __init__ from TutorialMakerLogic solves the problem:

    def __init__(self):
        """
        Called when the logic class is instantiated. Can be used for initializing member variables.
        """
        ScriptedLoadableModuleLogic.__init__(self) # noqa: F405
        self.tutorialEditor = TutorialEditor() 

Narrowing down the problem inside TutorialEditor i got that:

• If you define TutorialEditorLogic class like this:

class TutorialEditorLogic():
        pass

...the error is gone.

• But if you define TutorialEditorLogic class like this:

class TutorialEditorLogic():
    def __init__(self, gui=None):
        pass
...

or

class TutorialEditorLogic():
    def StopStartRecording(self):
        pass
...

or any other function, even with just a pass inside...

...the error suddenly reappears.

[lassoan]

Slicer has a bug of showing 2 times the module change:
Switch to module: ""
Switch to module: ""

This log message means that no module is active in the module selector. This is the normal behavior during application shutdown.

I've started the test by running ctest -R py_TutorialMaker -V -C Debug --output-on-failure --debug with a debug-mode-built Slicer and then attached the debugger to SlicerApp-real.exe (menu: Debug -> Attach to process). I got a nice stack trace of the crash:

I replaced the tutorial editor logic with

class TutorialEditorLogic():
        pass

and for me it did not change the test result, which I expected, because I don't think the tutorial editor is needed for running a tutorial.

Since the crash occurred in cleaning up signal handlers, I agree that the issue is may be related to invalid/unusual way of using signals. Maybe the error is that timers are not stopped when a class is cleaned up? The SignalManager class is unusual, too, but I commented out all its uses and the problem was still there.

I think a good approach could be to remove (or comment out) more and more of the code and see when the problem goes away.

[miiranta]

Hi Andras!

Thanks for the stack trace, i didn't know we could do that haha. I'll try to investigate with the new information you provided.

The commenting code approach was used until i got to the TutorialEditorLogic class which had the weird behaviour i described before. If i'm not mistaken, there was a signal related function that recevied an instance of TutorialEditorLogic, so it might be that declaring a "null" TutorialEditorLogic class also affects this function and prevents the error from happening somehow.

When you say "for me it did not change the test result" after replacing the class implementation with pass do you mean that the error continue to happen?
If that's the case, would you mind removing the instantiation of TutorialEditorLogic inside TutorialEditor and testing again? The error should have gone away.

[miiranta]

Also, indeed TutorialEditor is not necessary for testing, we could just remove it. We agreed tho that It's better if we find the exact cause of the problem so we can avoid future headaches.