C Message Recorders and PythonVariableLogger causes mysterious debugger behavior

[sassy-asjp]

Describe the bug

Usage of a C message .recorder(timeDiff) and PythonVariableLogger cause mysterious debugger behavior:

• next over usage in the Pdb will result in skipping to the next breakpoint, not over to the next line as expected.
• step into the usage in the Pdb will result in infinite recursion
• VSCode Python debugger will not hit any breakpoints set after usage.

To reproduce

This script reproduces the issues

from Basilisk.architecture import messaging
from Basilisk.fswAlgorithms import tamComm
from Basilisk.utilities import pythonVariableLogger

# The commented out lines all cause mysterious behavior,
# if uncommented, VSCode debugger will not hit a breakpoint set at the print
# usage of the Pdb around those lines will also exhibit odd behavior

test = tamComm.tamComm() # C module with C messages
#test.tamOutMsg.recorder(10) # CAUSES WEIRDNESS
msg = messaging.SCStatesMsg_C() # Using a C message directly
#rec = msg.recorder(10) # CAUSES WEIRDNESS
#pythonVariableLogger.PythonVariableLogger({'test': lambda CurrentSimNanos: test.RNGSeed}) # CAUSES WEIRDNESS
msgCpp = messaging.SCStatesMsg()
recCpp = msgCpp.recorder(10) # This causes NO weird behavior
print('YAY!')

Expected behavior The debugger should work as expected, e.g., even with the lines uncommented, the VSCode debugger will hit a breakpoint placed on print.

Screenshots N/A

Desktop (please complete the following information):

• OS: macOS
• Version 2.3.25
• Python version 3.11

Additional context

It seems to be a weird interaction between SWIG, the debugger, and __getattr__. The infinite loop the Pdb gets trapped in is within __getattr__ as it constantly gets called trying to find a non-existent attribute. In the C message case, it is looking for this and in the PythonVariableLogger case it is looking for _variables.

When I modify PythonVariableLogger to not use __getattr__, the weirdness goes away. I can submit my change for this, however removing __getattr__ for the C message recorder case looks a lot less straightforward.

If you run the offending line within the Pdb console, it will run fine. It is only broken when it's in the script the Pdb is being used to debug.

Potential fix for PythonVariableLogger:

diff --git a/src/utilities/pythonVariableLogger.py b/src/utilities/pythonVariableLogger.py
index 8d78f9588..69492e2c0 100644
--- a/src/utilities/pythonVariableLogger.py
+++ b/src/utilities/pythonVariableLogger.py
@@ -55,6 +55,8 @@ class PythonVariableLogger(sysModel.SysModel):
         """Called to clear the internal data storages"""
         self._times = []
         self._variables = {name: [] for name in self.logging_functions}
+        for name in self.logging_functions:
+            setattr(self, name, property(lambda: np.array(self._variables[name])))

     def times(self):
         """Retrieve the times when the data was logged"""
@@ -80,9 +82,3 @@ class PythonVariableLogger(sysModel.SysModel):

             self._next_update_time += self.min_log_period
         return super().UpdateState(CurrentSimNanos)
-    
-    def __getattr__(self, __name: str) -> Any:
-        if __name in self._variables:
-            return np.array(self._variables[__name])
-        raise AttributeError(f"Logger is not logging '{__name}'. "
-                             f"Must be one of: {', '.join(self._variables)}")

[sassy-asjp]

Ah, I think is the same issue as #249

[sassy-asjp]

I wonder if the fix for the C message recorder, instead of refactoring out the __getattr__ usage in the Python side, we could force the creation of the recorder object into the C/C++ side, similar to how C++ message recorder works, which might fix the issue.

It would probably require C++ usage in src/architecture/messaging/msgAutoSource/cMsgCInterfacePy.i.in, which I guess sounds fine?

[schaubh]

@juan-g-bonilla , I think yo helped create this code. Any thoughts on this issue and potential solution?

[juan-g-bonilla]

This seems like a VSCode Python Debugger bug. We should try to make a minimal reproducible example without Basilisk to try and find exactly what’s triggering this. Then, if we confirm this is a VSCode Python Debugger bug, we should post an issue on their GitHub and ask for a fix. In the mean time, I’m not opposed to a quick fix on our side, but I’d rather fix/find the core issue if possible.

Regarding the proposed fix, it seems fine to me. I’d put the code that sets the proprieties in __init__ instead of clear. Also, shame we lose the custom error message, but not the end of the world.

[sassy-asjp]

It does affect the native Python Pdb debugger as well. I think it's a SWIG bug with the "proper" fix probably inside SWIG, though I don't really understand SWIG well enough to theorize about what could be going on.

I'll investigate a workaround for the C message recorder when I have time and submit it with the Python variable logger fix.

[sassy-asjp]

I submitted a merge request.

@juan-g-bonilla As noted on the merge request, the code to set the properties has to be put in clear as it needs _variables which won't be set until clear