SlicerCustomAppTemplate icon indicating copy to clipboard operation
SlicerCustomAppTemplate copied to clipboard
verified publisher icon KitwareMedical

Python automated tests crash

Open cpinter opened this issue 5 years ago • 14 comments

The scripted module tests crash for custom app, also confirmed to be the case with the template without anything additional. This happens using the latest master, on Windows 10 with Qt 5.10.1.

I cannot debug it with setting the launcher as executable, as it runs the test on a different thread. I'd appreciate any ideas. Thank you!

e:\e\tD\Slicer-build>ctest -C Debug -V -R py_nomainwindow_
UpdateCTestConfiguration  from :E:/e/tD/Slicer-build/DartConfiguration.tcl
Parse Config file:E:/e/tD/Slicer-build/DartConfiguration.tcl
 Add coverage exclude regular expressions.
 Add coverage exclude: /CMakeFiles/CMakeTmp/
 Add coverage exclude: .*/moc_.*
 Add coverage exclude: .*/ui_.*
 Add coverage exclude: .*/qrc_.*
 Add coverage exclude: .*/Testing/.*
 Add coverage exclude: .*Python.cxx
 Add coverage exclude: .*PythonInit.cxx
 Add coverage exclude: .*/DesignerPlugins/.*
 Add coverage exclude: .*/generated_cpp/.*
SetCTestConfiguration:CMakeCommand:C:/Program Files/CMake/bin/cmake.exe
UpdateCTestConfiguration  from :E:/e/tD/Slicer-build/DartConfiguration.tcl
Parse Config file:E:/e/tD/Slicer-build/DartConfiguration.tcl
Test project E:/e/tD/Slicer-build
Constructing a list of tests
Done constructing a list of tests
Updating test list for fixtures
Added 0 tests to meet fixture requirements
Checking test dependency graph...
Checking test dependency graph end
test 292
      Start 292: py_nomainwindow_SubjectHierarchyFoldersTest1

292: Test command: E:\e\tD\Slicer-build\testingTest.exe "--no-splash" "--testing" "--disable-cli-modules" "--no-main-window" "--additional-module-paths" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-loadable-modules/Debug" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-loadable-modules/Release" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-loadable-modules/MinSizeRel" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-loadable-modules/RelWithDebInfo" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-scripted-modules" "--additional-module-paths" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-scripted-modules" "E:/e/tD/Slicer-build/lib/testingTest-4.11/cli-modules" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-loadable-modules" "--python-code" "import slicer.testing; slicer.testing.runUnitTest(['E:/e/tD/Slicer-build/Modules/Loadable/SubjectHierarchy/Testing/Python', 'E:/e/tD/slicersources-src/Modules/Loadable/SubjectHierarchy/Testing/Python'], 'SubjectHierarchyFoldersTest1')"
292: Test timeout computed to be: 1500
292: error: [E:/e/tD/Slicer-build/bin/Debug/testingTestApp-real.exe] exit abnormally - Report the problem.
 1/11 Test #292: py_nomainwindow_SubjectHierarchyFoldersTest1 .................***Failed    2.76 sec
test 372
      Start 372: py_nomainwindow_SegmentationsModuleTest1

372: Test command: E:\e\tD\Slicer-build\testingTest.exe "--no-splash" "--testing" "--disable-cli-modules" "--no-main-window" "--additional-module-paths" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-loadable-modules/Debug" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-loadable-modules/Release" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-loadable-modules/MinSizeRel" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-loadable-modules/RelWithDebInfo" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-scripted-modules" "--additional-module-paths" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-scripted-modules" "E:/e/tD/Slicer-build/lib/testingTest-4.11/cli-modules" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-loadable-modules" "--python-code" "import slicer.testing; slicer.testing.runUnitTest(['E:/e/tD/Slicer-build/Modules/Loadable/Segmentations/Testing/Python', 'E:/e/tD/slicersources-src/Modules/Loadable/Segmentations/Testing/Python'], 'SegmentationsModuleTest1')"
372: Test timeout computed to be: 1500
372: error: [E:/e/tD/Slicer-build/bin/Debug/testingTestApp-real.exe] exit abnormally - Report the problem.
 2/11 Test #372: py_nomainwindow_SegmentationsModuleTest1 .....................***Failed    2.76 sec
test 373
      Start 373: py_nomainwindow_SegmentationsModuleTest2

373: Test command: E:\e\tD\Slicer-build\testingTest.exe "--no-splash" "--testing" "--disable-cli-modules" "--no-main-window" "--additional-module-paths" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-loadable-modules/Debug" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-loadable-modules/Release" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-loadable-modules/MinSizeRel" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-loadable-modules/RelWithDebInfo" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-scripted-modules" "--additional-module-paths" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-scripted-modules" "E:/e/tD/Slicer-build/lib/testingTest-4.11/cli-modules" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-loadable-modules" "--python-code" "import slicer.testing; slicer.testing.runUnitTest(['E:/e/tD/Slicer-build/Modules/Loadable/Segmentations/Testing/Python', 'E:/e/tD/slicersources-src/Modules/Loadable/Segmentations/Testing/Python'], 'SegmentationsModuleTest2')"
373: Test timeout computed to be: 1500
373: error: [E:/e/tD/Slicer-build/bin/Debug/testingTestApp-real.exe] exit abnormally - Report the problem.
 3/11 Test #373: py_nomainwindow_SegmentationsModuleTest2 .....................***Failed    2.82 sec
test 374
      Start 374: py_nomainwindow_SegmentationWidgetsTest1

374: Test command: E:\e\tD\Slicer-build\testingTest.exe "--no-splash" "--testing" "--disable-cli-modules" "--no-main-window" "--additional-module-paths" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-loadable-modules/Debug" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-loadable-modules/Release" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-loadable-modules/MinSizeRel" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-loadable-modules/RelWithDebInfo" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-scripted-modules" "--additional-module-paths" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-scripted-modules" "E:/e/tD/Slicer-build/lib/testingTest-4.11/cli-modules" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-loadable-modules" "--python-code" "import slicer.testing; slicer.testing.runUnitTest(['E:/e/tD/Slicer-build/Modules/Loadable/Segmentations/Testing/Python', 'E:/e/tD/slicersources-src/Modules/Loadable/Segmentations/Testing/Python'], 'SegmentationWidgetsTest1')"
374: Test timeout computed to be: 1500
374: error: [E:/e/tD/Slicer-build/bin/Debug/testingTestApp-real.exe] exit abnormally - Report the problem.
 4/11 Test #374: py_nomainwindow_SegmentationWidgetsTest1 .....................***Failed    2.77 sec
test 417
      Start 417: py_nomainwindow_qSlicerCropVolumeSequenceModuleGenericTest

417: Test command: E:\e\tD\Slicer-build\testingTest.exe "--no-splash" "--testing" "--no-main-window" "--disable-cli-modules" "--additional-module-path" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-scripted-modules" "--additional-module-paths" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-scripted-modules" "E:/e/tD/Slicer-build/lib/testingTest-4.11/cli-modules" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-loadable-modules" "--python-code" "import slicer.testing; slicer.testing.runUnitTest(['E:/e/tD/Slicer-build/Modules/Scripted/CropVolumeSequence', 'E:/e/tD/slicersources-src/Modules/Scripted/CropVolumeSequence'], 'qSlicerCropVolumeSequenceModuleGenericTest')"
417: Test timeout computed to be: 1500
417: error: [E:/e/tD/Slicer-build/bin/Debug/testingTestApp-real.exe] exit abnormally - Report the problem.
 5/11 Test #417: py_nomainwindow_qSlicerCropVolumeSequenceModuleGenericTest ...***Failed    2.76 sec
test 419
      Start 419: py_nomainwindow_qSlicerEditorModuleGenericTest

419: Test command: E:\e\tD\Slicer-build\testingTest.exe "--no-splash" "--testing" "--no-main-window" "--disable-cli-modules" "--additional-module-path" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-scripted-modules" "--additional-module-paths" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-scripted-modules" "E:/e/tD/Slicer-build/lib/testingTest-4.11/cli-modules" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-loadable-modules" "--python-code" "import slicer.testing; slicer.testing.runUnitTest(['E:/e/tD/Slicer-build/Modules/Scripted/Editor', 'E:/e/tD/slicersources-src/Modules/Scripted/Editor'], 'qSlicerEditorModuleGenericTest')"
419: Test timeout computed to be: 1500
419: error: [E:/e/tD/Slicer-build/bin/Debug/testingTestApp-real.exe] exit abnormally - Report the problem.
 6/11 Test #419: py_nomainwindow_qSlicerEditorModuleGenericTest ...............***Failed    2.77 sec
test 422
      Start 422: py_nomainwindow_qSlicerScreenCaptureModuleGenericTest

422: Test command: E:\e\tD\Slicer-build\testingTest.exe "--no-splash" "--testing" "--no-main-window" "--disable-cli-modules" "--additional-module-path" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-scripted-modules" "--additional-module-paths" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-scripted-modules" "E:/e/tD/Slicer-build/lib/testingTest-4.11/cli-modules" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-loadable-modules" "--python-code" "import slicer.testing; slicer.testing.runUnitTest(['E:/e/tD/Slicer-build/Modules/Scripted/ScreenCapture', 'E:/e/tD/slicersources-src/Modules/Scripted/ScreenCapture'], 'qSlicerScreenCaptureModuleGenericTest')"
422: Test timeout computed to be: 1500
422: error: [E:/e/tD/Slicer-build/bin/Debug/testingTestApp-real.exe] exit abnormally - Report the problem.
 7/11 Test #422: py_nomainwindow_qSlicerScreenCaptureModuleGenericTest ........***Failed    2.77 sec
test 425
      Start 425: py_nomainwindow_qSlicerSegmentStatisticsModuleGenericTest

425: Test command: E:\e\tD\Slicer-build\testingTest.exe "--no-splash" "--testing" "--no-main-window" "--disable-cli-modules" "--additional-module-path" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-scripted-modules" "--additional-module-paths" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-scripted-modules" "E:/e/tD/Slicer-build/lib/testingTest-4.11/cli-modules" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-loadable-modules" "--python-code" "import slicer.testing; slicer.testing.runUnitTest(['E:/e/tD/Slicer-build/Modules/Scripted/SegmentStatistics', 'E:/e/tD/slicersources-src/Modules/Scripted/SegmentStatistics'], 'qSlicerSegmentStatisticsModuleGenericTest')"
425: Test timeout computed to be: 1500
425: error: [E:/e/tD/Slicer-build/bin/Debug/testingTestApp-real.exe] exit abnormally - Report the problem.
 8/11 Test #425: py_nomainwindow_qSlicerSegmentStatisticsModuleGenericTest ....***Failed    2.81 sec
test 427
      Start 427: py_nomainwindow_qSlicerSelfTestsModuleGenericTest

427: Test command: E:\e\tD\Slicer-build\testingTest.exe "--no-splash" "--testing" "--no-main-window" "--disable-cli-modules" "--additional-module-path" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-scripted-modules" "--additional-module-paths" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-scripted-modules" "E:/e/tD/Slicer-build/lib/testingTest-4.11/cli-modules" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-loadable-modules" "--python-code" "import slicer.testing; slicer.testing.runUnitTest(['E:/e/tD/Slicer-build/Modules/Scripted/SelfTests', 'E:/e/tD/slicersources-src/Modules/Scripted/SelfTests'], 'qSlicerSelfTestsModuleGenericTest')"
427: Test timeout computed to be: 1500
427: error: [E:/e/tD/Slicer-build/bin/Debug/testingTestApp-real.exe] exit abnormally - Report the problem.
 9/11 Test #427: py_nomainwindow_qSlicerSelfTestsModuleGenericTest ............***Failed    2.85 sec
test 428
      Start 428: py_nomainwindow_qSlicerDICOMModuleGenericTest

428: Test command: E:\e\tD\Slicer-build\testingTest.exe "--no-splash" "--testing" "--no-main-window" "--disable-cli-modules" "--additional-module-path" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-scripted-modules" "--additional-module-paths" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-scripted-modules" "E:/e/tD/Slicer-build/lib/testingTest-4.11/cli-modules" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-loadable-modules" "--python-code" "import slicer.testing; slicer.testing.runUnitTest(['E:/e/tD/Slicer-build/Modules/Scripted/DICOM', 'E:/e/tD/slicersources-src/Modules/Scripted/DICOM'], 'qSlicerDICOMModuleGenericTest')"
428: Test timeout computed to be: 1500
428: error: [E:/e/tD/Slicer-build/bin/Debug/testingTestApp-real.exe] exit abnormally - Report the problem.
10/11 Test #428: py_nomainwindow_qSlicerDICOMModuleGenericTest ................***Failed    2.85 sec
test 429
      Start 429: py_nomainwindow_qSlicerDICOMPatcherModuleGenericTest

429: Test command: E:\e\tD\Slicer-build\testingTest.exe "--no-splash" "--testing" "--no-main-window" "--disable-cli-modules" "--additional-module-path" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-scripted-modules" "--additional-module-paths" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-scripted-modules" "E:/e/tD/Slicer-build/lib/testingTest-4.11/cli-modules" "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-loadable-modules" "--python-code" "import slicer.testing; slicer.testing.runUnitTest(['E:/e/tD/Slicer-build/Modules/Scripted/DICOMPatcher', 'E:/e/tD/slicersources-src/Modules/Scripted/DICOMPatcher'], 'qSlicerDICOMPatcherModuleGenericTest')"
429: Test timeout computed to be: 1500
429: error: [E:/e/tD/Slicer-build/bin/Debug/testingTestApp-real.exe] exit abnormally - Report the problem.
11/11 Test #429: py_nomainwindow_qSlicerDICOMPatcherModuleGenericTest .........***Failed    2.83 sec

0% tests passed, 11 tests failed out of 11

Total Test time (real) =  30.94 sec

The following tests FAILED:
        292 - py_nomainwindow_SubjectHierarchyFoldersTest1 (Failed)
        372 - py_nomainwindow_SegmentationsModuleTest1 (Failed)
        373 - py_nomainwindow_SegmentationsModuleTest2 (Failed)
        374 - py_nomainwindow_SegmentationWidgetsTest1 (Failed)
        417 - py_nomainwindow_qSlicerCropVolumeSequenceModuleGenericTest (Failed)
        419 - py_nomainwindow_qSlicerEditorModuleGenericTest (Failed)
        422 - py_nomainwindow_qSlicerScreenCaptureModuleGenericTest (Failed)
        425 - py_nomainwindow_qSlicerSegmentStatisticsModuleGenericTest (Failed)
        427 - py_nomainwindow_qSlicerSelfTestsModuleGenericTest (Failed)
        428 - py_nomainwindow_qSlicerDICOMModuleGenericTest (Failed)
        429 - py_nomainwindow_qSlicerDICOMPatcherModuleGenericTest (Failed)
Errors while running CTest

cpinter avatar May 04 '20 12:05 cpinter

Does anyone have an idea about this?

cpinter avatar Jun 04 '20 10:06 cpinter

as it runs the test on a different thread. I'd appreciate any ideas. Thank you!

Since the executable testingTestApp-real.exe is crashing, I suggest you start visual studio using testingTest.exe --VisualStudioProject, you should then be able to debug testingTestApp-real.

See https://www.slicer.org/wiki/Documentation/Nightly/Developers/Tutorials/Debug_Instructions#Using_Visual_Studio

jcfr avatar Jun 04 '20 16:06 jcfr

Thanks, @jcfr , I have been debugging Slicer for a decade now, the problem is not this.

The question is how do I debug the test in the exact same environment as it is run by ctest. And I think it's not through testingTestApp-real. Although I can try running the test from within Slicer and see if it crashes.

cpinter avatar Jun 04 '20 16:06 cpinter

I figured :)

Does the program crash if you run it directly from the command line ?

If yes, running it in visual studio may help.

jcfr avatar Jun 04 '20 16:06 jcfr

Yes it crashes when run from the command line. I tried to run it that way from VS and that's where the different process became a problem. I'll try running the test python command (slicer.testing.runUnitTest(...)) from a running Slicer through the debugger, maybe it crashes that way.

cpinter avatar Jun 04 '20 17:06 cpinter

Considering the following command:

E:\e\tD\Slicer-build\testingTest.exe ^
  --no-splash ^
  --testing ^
  --no-main-window ^
  --disable-cli-modules ^
  --additional-module-path  "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-scripted-modules" ^
  --additional-module-paths ^
     "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-scripted-modules" ^
     "E:/e/tD/Slicer-build/lib/testingTest-4.11/cli-modules" ^
     "E:/e/tD/Slicer-build/lib/testingTest-4.11/qt-loadable-modules" ^
  --python-code ^
    "import slicer.testing; slicer.testing.runUnitTest(['E:/e/tD/Slicer-build/Modules/Scripted/DICOMPatcher', 'E:/e/tD/slicersources-src/Modules/Scripted/DICOMPatcher'], 'qSlicerDICOMPatcherModuleGenericTest')"

From within Visual Studio, you should be able to associate all arguments with the testingTestApp-real project and start the debugger.

Indeed, I don't the execution of the slicer.testing.runUnitTest (implemented here) is starting any thread or process.

jcfr avatar Jun 04 '20 17:06 jcfr

Sorry for the late answer! I tried the command you suggested but it is identical with what I tried last, and the debugger returns with no call stack, but without the debugger there is clearly a crash.

Unless we get a call stack for this crash we can't fix this, meaning slicer custom apps cannot be tested the usual way.

If I run the test python code from within the main window's python interactor (after removing no-main-window and testing and the python-code arguments from the startup command), then the tests pass alright.

cpinter avatar Jul 28 '20 15:07 cpinter

@cpinter or @jcfr Were you all able to resolve this? I think I'm running into this now with my slicer custom app.

PS C:\Program Files\MyName 2.0.0-2022-04-25> ./MyName.exe --testing
error: [C:/Program Files/MyName 2.0.0-2022-04-25/bin/MyNameApp-real.exe] exit abnormally - Report the problem.

It does not have an issue with a regular Slicer build

PS C:\Users\JamesButler\AppData\Local\NA-MIC\Slicer 4.13.0-2022-04-23> ./Slicer.exe --testing
PS C:\Users\JamesButler\AppData\Local\NA-MIC\Slicer 4.13.0-2022-04-23>

jamesobutler avatar Apr 25 '22 22:04 jamesobutler

@jamesobutler I could not find a way to attach a debugger to the process where it crashed, and didn't have any additional ideas since then. I ended up running tests from an app started normally using a button in the settings panel, and this was not critical after that. It would be still great if we could fix this, because without it custom apps can't really have a working dashboard.

Linking the recent discourse topic here as well: https://discourse.slicer.org/t/slicer-custom-app-crashing-with-testing-arg/23209/2

cpinter avatar May 02 '22 09:05 cpinter

I was trying to debug this on linux with a debug build of my custom app using:

gdb GeoSlicer
set follow-fork-mode child
r --testing

Segfault backtrace:

#0  0x00007ffff3b011a2 in QSettings::value(QString const&, QVariant const&) const ()
   from /home/fernando/Downloads/GeoSlicer-1.6.0-2022-05-11-linux-amd64_debug/GeoSlicer-1.6.0-2022-05-11-linux-amd64/bin/../lib/GeoSlicer-4.11/libQt5Core.so.5
#1  0x00007ffff5628b94 in qSlicerCoreApplicationPrivate::init (this=0xbbf4a0)
    at /root/volume/geoslicerbase/builddebug/slicersources-src/Base/QTCore/qSlicerCoreApplication.cxx:306
#2  0x00007ffff71b1db7 in qSlicerApplicationPrivate::init (this=0xbbf4a0)
    at /root/volume/geoslicerbase/builddebug/slicersources-src/Base/QTGUI/qSlicerApplication.cxx:215
## my comment (the above line is this->Superclass::init();)
#3  0x00007ffff71b2f38 in qSlicerApplication::qSlicerApplication (this=0x7fffffffb410, _argc=@0x7fffffffb3cc: 2, _argv=0x7fffffffb588)
    at /root/volume/geoslicerbase/builddebug/slicersources-src/Base/QTGUI/qSlicerApplication.cxx:374
#4  0x0000000000408a6b in (anonymous namespace)::SlicerAppMain (argc=2, argv=0x7fffffffb588)
    at /root/volume/geoslicerbase/Applications/GeoSlicerApp/Main.cxx:38
#5  0x0000000000408d87 in main (argc=2, argv=0x7fffffffb588)
    at /root/volume/geoslicerbase/builddebug/slicersources-src/Base/QTApp/qSlicerApplicationMainWrapper.cxx:72

Not very informative specially because my custom app may have changed some of those sources but it seems that a command line argument is not being built properly.

fbordignon avatar May 11 '22 20:05 fbordignon

Thanks for the additional debugging help @fbordignon! Much appreciated 🙏🏻

jamesobutler avatar May 11 '22 20:05 jamesobutler

My custom app is based on version 4.11.20210226 if you need more info I can share those cxx sources.

fbordignon avatar May 11 '22 20:05 fbordignon

It probably has been failing in the same way through various versions of Slicer (master as of May 4th 2020, version 4.11.20210226, and recent master at least as of Late-April 2022).

jamesobutler avatar May 11 '22 20:05 jamesobutler