KitwareMedical / SlicerCustomAppTemplate

Template to be used as a starting point for creating a custom 3D Slicer application
Apache License 2.0
51 stars 23 forks source link

Python automated tests crash #23

Open cpinter opened 4 years ago

cpinter commented 4 years ago

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 commented 4 years ago

Does anyone have an idea about this?

jcfr commented 4 years ago

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

cpinter commented 4 years ago

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.

jcfr commented 4 years ago

I figured :)

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

If yes, running it in visual studio may help.

cpinter commented 4 years ago

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.

jcfr commented 4 years ago

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.

cpinter commented 4 years ago

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.

jamesobutler commented 2 years ago

@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>
cpinter commented 2 years ago

@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

fbordignon commented 2 years ago

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.

jamesobutler commented 2 years ago

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

fbordignon commented 2 years ago

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

jamesobutler commented 2 years ago

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).