Some DraftCreation unit tests fail randomly #18679

kpemartin · 2024-12-22T17:31:27Z

Is there an existing issue for this?

I have searched the existing issues

Problem description

When running the full suite of unit tests in the Gui app, some of the DraftCreation tests fail non-deterministically.

Several of these tests, such as the one calling itself "Draft Dimension Angular" can sometimes produce a Windows exception 0xC0000005 (memory access violation). Furthermore, when handling this exception another error occurs in the form of a std::exception with the message "invalid format specifier" which causes a popup message window with the same text and ends the test run.

The actual original exception occurs in View3DInventorPy::getSceneGraph on the line scene->ref() because scene is null.

This only seems to occur if the entire test suite (TestApp.All) is run. It does not matter if this is done from the command line using -r 0 or by using the test workbench.

This particular test even admits Occasionally crashes with no further explanation. Looking at the code history provides no details as to whether this is the "occasional crash" the comment refers to.

It would appear that the crash occurs because code delayed using ToDo.delay is delayed long enough that the document window is already closed (I'm guessing here) so there is no scene any more. The call to ToDo.delay is in Tracker.__init__ in gui_tracker.py.

The full Console Log is attached, but here is a summarized extract:

....log of previous tests...
10:09:26    Temporary document 'DraftCreation'
10:09:26    Test 'Draft Dimension Angular'
10:09:26    Occasionally crashes
10:09:26    center=Vector (0.0, 0.0, 0.0)
10:09:26    angle1=20, angle2=70
10:09:26    dim_line=Vector (3.0, 1.0, 0.0)
10:09:32  Illegal storage access...
10:09:32  Traceback (most recent call last):
  File "D:\Users\KPMartin\Documents\Git\FreeCAD\build\Mod\Draft\draftutils\todo.py", line 138, in doTasks
    f(arg)
  File "D:\Users\KPMartin\Documents\Git\FreeCAD\build\Mod\Draft\draftguitools\gui_trackers.py", line 107, in _insertSwitch
    sg = self.get_scene_graph()
         ^^^^^^^^^^^^^^^^^^^^^^
  File "D:\Users\KPMartin\Documents\Git\FreeCAD\build\Mod\Draft\draftguitools\gui_trackers.py", line 97, in get_scene_graph
    return v.getSceneGraph()
           ^^^^^^^^^^^^^^^^^
RuntimeError: Illegal storage access! Please save your work under a new file name and restart the application!

10:09:32  Traceback (most recent call last):
  File "D:\Users\KPMartin\Documents\Git\FreeCAD\build\Mod\Draft\draftutils\todo.py", line 138, in doTasks
    f(arg)
  File "D:\Users\KPMartin\Documents\Git\FreeCAD\build\Mod\Draft\draftguitools\gui_trackers.py", line 107, in _insertSwitch
    sg = self.get_scene_graph()
         ^^^^^^^^^^^^^^^^^^^^^^
  File "D:\Users\KPMartin\Documents\Git\FreeCAD\build\Mod\Draft\draftguitools\gui_trackers.py", line 97, in get_scene_graph
    return v.getSceneGraph()
           ^^^^^^^^^^^^^^^^^
RuntimeError: Illegal storage access! Please save your work under a new file name and restart the application!

10:09:32  ToDo.doTasks, Unexpected error:
<class 'RuntimeError'>
in <bound method Tracker._insertSwitch of <draftguitools.gui_trackers.gridTracker object at 0x000001C45E806270>>(<pivy.coin.SoSwitch; proxy of <Swig Object of type 'SoSwitch *' at 0x000001C45FB34FC0> >)
...module version information...
10:09:32  Id: 21080: ERROR: SymGetLineFromAddr64, GetLastError: 487 (Address: 00007FFF8D7FEBE5)
10:09:32  Id: 21080: 00007FFF8D7FEBE5 (Coin4): (filename not available): SoBase::ref
...several traceback entries...
10:09:32  Id: 21080: D:\Users\KPMartin\Documents\Git\FreeCAD\src\Gui\Application.cpp (2312): Gui::Application::runApplication
...several more traceback entries...
10:09:32  Id: 21080: 00007FF82125CC91 (ntdll): (filename not available): RtlUserThreadStart
10:09:32  *** Unhandled Exception!
10:09:32     ExpCode: 0xC0000005
10:09:32     ExpFlags: 0
10:09:32  Unhandled std::exception caught in GUIApplication::notify.
The error message is: invalid format specifier
10:09:32  
10:09:32  ------------------------------------------------------------------------------
10:09:32    Temporary document 'DraftCreation'
10:09:32    Test 'Draft Dimension'
10:09:32    Occasionally crashes
10:09:32    a=Vector (0.0, 0.0, 0.0), b=Vector (9.0, 0.0, 0.0)
...module info again...
10:09:32  Id: 21080: G:\FreeCAD\FreeCAD-LibPack-chennes\working\python\Objects\frameobject.c (1498): PyFrame_GetBack
10:09:32  Id: 21080: G:\FreeCAD\FreeCAD-LibPack-chennes\working\python\Objects\frameobject.c (106): frame_getback
10:09:32  Id: 21080: G:\FreeCAD\FreeCAD-LibPack-chennes\working\python\Objects\object.c (1430): _PyObject_GenericGetAttrWithDict
...more traceback lines...
10:09:32  Id: 21080: 00007FF82125CC91 (ntdll): (filename not available): RtlUserThreadStart
10:09:32  *** Unhandled Exception!
10:09:32     ExpCode: 0xC0000005
10:09:32     ExpFlags: 0

Full log: Null scene exception.zip

This log seems to imply that there are two access violations, which would imply that there are two ToDo entries, each of which causes an exception once the message loop runs the delayed code. This double exception might ultimately be the cause of the "invalid format specifier"

Full version info

OS: Windows 10 build 19045
Architecture: x86_64
Version: 1.1.0dev.39675 (Git)
Build type: Release
Branch: Issue16849B
Hash: b20509baff0609145476612fd432ef3e7ccb286b
Python 3.12.4, Qt 6.7.2, Coin 4.0.2, Vtk 9.3.0, OCC 7.8.0
Locale: English/Canada (en_CA)
Stylesheet/Theme/QtStyle: FreeCAD Light.qss/FreeCAD Classic/

Subproject(s) affected?

None

Anything else?

The immediate fix is to change View3DInventorPy::getSceneGraph to return a python None is scene is null.

This does not explain the second "invalid format specifier" error, so perhaps that should be analyzed before fixing View3DInventorPy::getSceneGraph.

Code of Conduct

I agree to follow this project's Code of Conduct

The text was updated successfully, but these errors were encountered:

luzpaz · 2024-12-23T00:38:21Z

cc @Roy-043

Roy-043 · 2025-01-02T18:42:07Z

The issue is indeed that documents can get closed before delayed code that should act on them has had a chance to execute. I suppose this is an example of a 'race condition'. What is interesting is that the referenced code in gui_trackers.py actually checks if there is a valid 3D view. So it appears documents get closed at the exact moment that code runs.

FreeCAD/src/Mod/Draft/draftguitools/gui_trackers.py

Lines 93 to 100 in e977eb4

    
               def get_scene_graph(self): 
        
                   """Returns the current scenegraph or None if this is not a 3D view 
        
                   """ 
        
                   v = Draft.get3DView() 
        
                   if v: 
        
                       return v.getSceneGraph() 
        
                   else: 
        
                       return None

WorkingPlane.py is responsible for (some of) the delayed code. That code triggers the grid (among other things) based on view changes.

FreeCAD/src/Mod/Draft/WorkingPlane.py

Lines 1791 to 1804 in e977eb4

    
           def _view_observer_callback(sub_win): 
        
               if sub_win is None: 
        
                   return 
        
               view = gui_utils.get_3d_view() 
        
               if view is None: 
        
                   return 
        
               if not hasattr(FreeCADGui, "draftToolBar"): 
        
                   return 
        
               tray = FreeCADGui.draftToolBar.tray 
        
               if tray is None: 
        
                   return 
        
               if FreeCADGui.draftToolBar.tray.isVisible() is False: 
        
                   return 
        
               ToDo.delay(_update_gui, None)

The tests that close documents too soon are actually dummy tests (aux.fake_function). There are 5 test files with such tests. 2 have already been commented out in TestDraft.py. If I comment out the other 3 (related to SVG, DXF and DWG) the issue seems to no longer occur.
TestDraft.py.txt (Remove the .txt extension).

In a way that solution avoids the problem rather than solving it. To really solve it I suppose we should add try-except structures whenever we reference a 3D view.

@kpemartin Can please you test with the attached file? Thanks.

OS: Windows 8 build 9600
Architecture: x86_64
Version: 1.1.0dev.39708 (Git) Conda
Build type: Release
Branch: main
Hash: 173ff4da1ef4f075d56c0dc617d1bf00d5f49d4b
Python 3.11.11, Qt 5.15.15, Coin 4.0.3, Vtk 9.3.0, OCC 7.8.1
Locale: C/Default (C) [ OS: Dutch/Netherlands (nl_NL) ]
Stylesheet/Theme/QtStyle: unset/FreeCAD Classic/Qt default
Installed mods:

kpemartin · 2025-01-02T19:28:22Z

I ran the file and it succeeded but the only way I could ever get the failure was to run the complete test suite (-r 0) so I'm not surprised this subset did not fail.

Draft.get3DView verifies that the view it returns has a getSceneGraph method but not whether that method will succeed so it is possible for it to return a value that already has no scene, causing the fault in getSceneGraph.

There is perhaps a larger time window between the ToDo.delay() call and execution of the delayed code where the main window can have an active window with a null scene. I would expect that eventually in the process of closing the window, it (the window) stops being the active window so Draft.get3DView finds nothing at all, but until that happens you're in this time window.

Come to think of it, it is possible that the window being closed by the test that did the delay call has actually closed, popping back to some unrelated previous active window, which may also be closing asynchronously. Asking for the Active window in (arbitrarily) delayed code and expecting to get any particular window just sounds like a Bad Idea because who knows what window will be active at that time.

One way to avoid this is to have the code that does the delay call query the view at that time, and pass it as an argument to the delayed code. But then, perhaps the whole reason for the delay is that this is too early to find the view.

Some Draft test files contain only dummy tests (`aux.fake_function`). Running them will just open a new file and then immediately close it. This can result in issues with code that is called with a delay. See FreeCAD#18679. Disabling these tests by commenting them out avoids this.

kpemartin added Status: Needs confirmation Missing confirmation from other testers Status: Needs triage Missing triage labels Dec 22, 2024

luzpaz added Mod: Draft Related to the Draft Workbench Mod: Test Related to the Test Workbench and removed Status: Needs triage Missing triage labels Dec 23, 2024

Roy-043 added Type: Bug This issue or PR is related to a bug and removed Status: Needs confirmation Missing confirmation from other testers labels Jan 2, 2025

Roy-043 added the Status: Confirmed The issue was confirmed by others label Jan 2, 2025

Roy-043 removed the Mod: Test Related to the Test Workbench label Jan 2, 2025

Roy-043 mentioned this issue Jan 4, 2025

Draft: comment out 3 test files with only dummy tests #18863

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Some DraftCreation unit tests fail randomly #18679

Some DraftCreation unit tests fail randomly #18679

kpemartin commented Dec 22, 2024

luzpaz commented Dec 23, 2024

Roy-043 commented Jan 2, 2025

kpemartin commented Jan 2, 2025

Some DraftCreation unit tests fail randomly #18679

Some DraftCreation unit tests fail randomly #18679

Comments

kpemartin commented Dec 22, 2024

Is there an existing issue for this?

Problem description

Full version info

Subproject(s) affected?

Anything else?

Code of Conduct

luzpaz commented Dec 23, 2024

Roy-043 commented Jan 2, 2025

kpemartin commented Jan 2, 2025