Merge pull request #287 from AVSLab/feature/286-sysmodel-logger

Feature/286 sysmodel logger

docs/source/Learn/bskPrinciples.rst

@@ -20,3 +20,4 @@ by writing a python script.
    bskPrinciples/bskPrinciples-8
    bskPrinciples/bskPrinciples-9
    bskPrinciples/bskPrinciples-10
+   bskPrinciples/bskPrinciples-11

docs/source/Learn/bskPrinciples/bskPrinciples-11.rst

@@ -0,0 +1,31 @@
+
+
+.. _bskPrinciples-11:
+
+.. warning:: 
+
+    This section refers to a deprecated way of logging variables. Refer to previous documentation pages for the updated way.
+
+Deprecated: Setting and Recording Module Variables
+==================================================
+
+The deprecated :ref:`SimulationBaseClass` method to record a module variable is::
+
+    scSim.AddVariableForLogging( variableString, recordingTime, indexStart==0, indexStop==0)
+
+Here ``variableString`` must be composed of the module tag string, a period and the variable name.
+The examples above illustrate how to apply this method for a C or C++ module variable.
+
+The ``recordingTime`` variable is the minimum time that must pass, in nano-seconds again, before the
+module variable is recorded.
+
+The optional integer arguments ``indexStart`` and ``indexStop`` are defaulted to zero, resulting in a
+single value being recorded.  As this example is also recording a 3-dimensional array ``dumVector``,
+it is recorded by setting the start and end index to 0 and 2 respectively.
+
+After executing the script, the recorded variables are retrieved in general using
+the :ref:`SimulationBaseClass` method::
+
+    scSim.GetLogVariableData(variableString)
+
+Here ``variableString`` is again composed of the ``ModelTag`` and variable name as before.  Note that the returned array has a first column that represents the time where the variable is recorded in nano-seconds.  Executing the script you should thus see the following output:

docs/source/Learn/bskPrinciples/bskPrinciples-6.rst

@@ -1,7 +1,3 @@
-.. raw:: html
-
-    <iframe width="560" height="315" src="https://www.youtube.com/embed/XuaSmG4wYlk" frameborder="0" allow="accelerometer; autoplay; clipboard-write; encrypted-media; gyroscope; picture-in-picture" allowfullscreen></iframe>
-
 
 .. _bskPrinciples-6:
 
@@ -13,7 +9,7 @@ Setting and Recording Module Variables
 
     The python code shown below can be downloaded :download:`here </../../docs/source/codeSamples/bsk-6.py>`.
 
-Sometimes it is convenient to record a Basilisk module variable, not just the input or output message.  This can be done via a python command as shown below.  However, note that such module variable recording will slow down the simulation as this is done in the python layer.
+Sometimes it is convenient to record a Basilisk module variable, not just the input or output message.  This can be done via a python command as shown below.  However, note that such module variable recording will slow down the simulation as this is done in the python layer.  
 
 The simulation setup is shown in the figure below.  Both a C and C++ module are created and added to the single task.  However, no messages are connected here.  Rather, this sample code illustrates how to record module internal variables.  The variables are either public C++ class variables, or they are variables with the C module configuration structure.  Both :ref:`cModuleTemplate` and :ref:`cppModuleTemplate` have the exact same public variables for easy comparison.
 
@@ -27,21 +23,23 @@ The sample code is shown below.  The C and C++ modules are set up as before.  Th
    :linenos:
    :lines: 18-
 
-The :ref:`SimulationBaseClass` method to record a module variable is::
+Logging a variable from a module is similar to recording one from a message::
 
-    scSim.AddVariableForLogging( variableString, recordingTime, indexStart==0, indexStop==0)
+    moduleLogger = module.logger(variableName, recordingTime)
 
-Here ``variableString`` must be composed of the module tag string, a period and the variable name.  The examples above illustrate how to apply this method for a C or C++ module variable. 
+The ``variableName`` must be either a string or a list of strings. This establishes what module variables to log.
 
-The ``recordingTime`` variable is the minimum time that must pass, in nano-seconds again, before the module variable is recorded.
+The optional ``recordingTime`` variable is the minimum time that must pass, in nano-seconds again,
+before the module variable is recorded.  If this variable is not provided, then the logging occurs
+at the module update period.
 
-The optional integer arguments ``indexStart`` and ``indexStop`` are defaulted to zero, resulting in a single value being recorded.  As this example is also recording a 3-dimensional array ``dumVector``, it is recorded by setting the start and end index to 0 and 2 respectively.
+After executing the script, the recorded variables are retrieved using ``moduleLogger.variableName`` 
+where ``variableName`` is the the name of the module variable you seek to access. 
 
-After executing the script, the recorded variables are retrieved in general using the :ref:`SimulationBaseClass` method::
+To access the array of time values where the module variables were recorded use ``moduleLogger.times()``. 
+Note that these times are given in nanoseconds.
 
-    scSim.GetLogVariableData(variableString)
-
-Here ``variableString`` is again composed of the ``ModelTag`` and variable name as before.  Note that the returned array has a first column that represents the time where the variable is recorded in nano-seconds.  Executing the script you should thus see the following output:
+Executing the script you should thus see the following output:
 
 .. code-block::
 
@@ -52,17 +50,29 @@ Here ``variableString`` is again composed of the ``ModelTag`` and variable name
     BSK_INFORMATION: C++ Module ID 2 ran Update at 0.000000s
     BSK_INFORMATION: C Module ID 1 ran Update at 1.000000s
     BSK_INFORMATION: C++ Module ID 2 ran Update at 1.000000s
+    Times:  [         0 1000000000]
     mod1.dummy:
-    [[0.e+00 1.e+00]
-     [1.e+09 2.e+00]]
-    mod1.dumVector:
-    [[0.e+00 1.e+00 2.e+00 3.e+00]
-     [1.e+09 1.e+00 2.e+00 3.e+00]]
+    [1. 2.]
     mod2.dummy:
-    [[0.e+00 1.e+00]
-     [1.e+09 2.e+00]]
+    [1. 2.]
     mod2.dumVector:
-    [[0.e+00 1.e+00 2.e+00 3.e+00]
-     [1.e+09 1.e+00 2.e+00 3.e+00]]
+    [[1. 2. 3.]
+    [1. 2. 3.]]
 
 Note that both the C and C++ module variables are correctly being recorded.
+
+Clearing the Data Log
+---------------------
+Similarly to message recorders, module loggers continuously add data to their internal data vectors. 
+If you start and stop the simulation, pull the data, resume the simulation and so on, 
+this data recording process is cumulative. If you stop the simulation and want to clear the data log 
+so that only new data is recorded, you can clear the logger using the ``.clear()`` method::
+
+    moduleLogger.clear()
+
+Advanced Data Logging
+---------------------
+The syntax ``module.logger(variableName)`` generates a simple logger for one or more module variables.
+However, loggers can retrieve data from many other sources, and do arbitrary operations on this data
+before it is stored. This is done using the class ``Basilisk.utilities.pythonVariableLogger``.
+See :ref:`scenarioFuelSlosh` for an example.

docs/source/Learn/makingModules/cppModules/cppModules-4.rst

@@ -19,7 +19,7 @@ The basic swig interface file looks like this:
     from Basilisk.architecture.swig_common_model import *
     %}
 
-    %include "sys_model.h"
+    %include "sys_model.i"
     %include "swig_conly_data.i"
 
     %include "someModule.h"

docs/source/Support/bskReleaseNotes.rst

@@ -43,15 +43,22 @@ Version |release|
 - Corrected an error with :ref:`magnetometer` where the RNG seed was passed to the Gauss-Markov noise model within the
   constructor and could therefore not be modified after creating the object. Furthermore, the noise model is now only
   used if all three components of the standard deviation parameter are initialized to a positive value.
-- Removed fswAuto and associated documenation, as the tool was outdated.
+- Removed fswAuto and associated documentation, as the tool was outdated.
 - Changed how C modules are wrapped as C++ classes. This makes handling C modules the same as C++ modules,
   removing the need for "Config" and "Wrap" objects. Updated all scenarios and test files for this new syntax.
   To convert prior script to use the new syntax, see :ref:`bskPrinciples-2` for the simple new
   syntaxt to add C-modules.
-- Modified :ref:`mrpFeedback` to enable the use of a modified control law, and added the integral control torque
+- Modified :ref:`mrpFeedback` to enable the use of a modified control law, and added the integral control torque 
   feedback output message.
 - Resolved a crash, induced by uninitialized memory, in the Camera module. The crash was first seen on Ubuntu 22 with
   gcc 9.5
+- Implemented new syntax for variable logging. See :ref:`bskPrinciples-6`.
+
+.. warning::
+
+    SWIG files (``.i``) for modules should include ``%include "sys_model.i"`` instead of ``%include "sys_model.h"``
+    to take advantage of the new module variable logging feature.
+
 
 Version 2.2.0 (June 28, 2023)
 -----------------------------

docs/source/codeSamples/bsk-6.py

@@ -51,11 +51,11 @@ def run():
     mod2.dummy = 1
     mod2.dumVector = [1., 2., 3.]
 
-    # request these module variables to be recorded
-    scSim.AddVariableForLogging(mod1.ModelTag + ".dummy", macros.sec2nano(1.))
-    scSim.AddVariableForLogging(mod1.ModelTag + ".dumVector", macros.sec2nano(1.), 0, 2)
-    scSim.AddVariableForLogging(mod2.ModelTag + ".dummy", macros.sec2nano(1.))
-    scSim.AddVariableForLogging(mod2.ModelTag + ".dumVector", macros.sec2nano(1.), 0, 2)
+    # request these module variables to be recorded    
+    mod1Logger = mod1.logger("dummy", macros.sec2nano(1.))
+    scSim.AddModelToTask("dynamicsTask", mod1Logger)
+    mod2WrapLogger = mod2.logger(["dummy", "dumVector"], macros.sec2nano(1.))
+    scSim.AddModelToTask("dynamicsTask", mod2WrapLogger)
 
     #  initialize Simulation:
     scSim.InitializeSimulation()
@@ -64,17 +64,16 @@ def run():
     scSim.ConfigureStopTime(macros.sec2nano(1.0))
     scSim.ExecuteSimulation()
 
+    # Print when were the variables logged (the same for every logged variable)
+    print("Times: ", mod1Logger.times())
+
+    # Print values logged
     print("mod1.dummy:")
-    print(scSim.GetLogVariableData(mod1.ModelTag + ".dummy"))
-    print("mod1.dumVector:")
-    print(scSim.GetLogVariableData(mod1.ModelTag + ".dumVector"))
+    print(mod1Logger.dummy)
     print("mod2.dummy:")
-    print(scSim.GetLogVariableData(mod2.ModelTag + ".dummy"))
+    print(mod2WrapLogger.dummy)
     print("mod2.dumVector:")
-    print(scSim.GetLogVariableData(mod2.ModelTag + ".dumVector"))
-
-    return
-
+    print(mod2WrapLogger.dumVector)
 
 if __name__ == "__main__":
     run()

examples/OpNavScenarios/scenariosOpNav/scenario_OpNavHeading.py

@@ -143,10 +143,10 @@ def log_outputs(self):
             self.rwLogs.append(DynModel.rwStateEffector.rwOutMsgs[item].recorder(samplingTime))
             self.masterSim.AddModelToTask(DynModel.taskName, self.rwLogs[item])
 
-        self.masterSim.AddVariableForLogging('headingUKF.bVec_B', samplingTime, 0, 2)
-
+        self.headingBVecLog = FswModel.headingUKF.logger("bVec_B")
         self.filtRec = FswModel.headingUKF.filtDataOutMsg.recorder(samplingTime)
         self.opNavFiltRec = FswModel.headingUKF.opnavDataOutMsg.recorder(samplingTime)
+        self.masterSim.AddModelToTask(DynModel.taskName, self.headingBVecLog)
         self.masterSim.AddModelToTask(DynModel.taskName, self.filtRec)
         self.masterSim.AddModelToTask(DynModel.taskName, self.opNavFiltRec)
 
@@ -167,7 +167,7 @@ def pull_outputs(self, showPlots):
         circleRadii = unitTestSupport.addTimeColumn(self.circlesRec.times(), self.circlesRec.circlesRadii)
         validCircle = unitTestSupport.addTimeColumn(self.circlesRec.times(), self.circlesRec.valid)
 
-        frame = self.masterSim.GetLogVariableData('headingUKF.bVec_B')
+        frame = unitTestSupport.addTimeColumn(self.headingBVecLog.times(), self.headingBVecLog.bVec_B) 
 
         numRW = 4
         dataRW = []

examples/scenarioCSSFilters.py

@@ -483,6 +483,7 @@ def setupCSS(CSS):
     # Setup filter
     #
     numStates = 6
+    bVecLogger = None
     if FilterType == 'EKF':
         module = sunlineEKF.sunlineEKF()
         module.ModelTag = "SunlineEKF"
@@ -518,7 +519,8 @@ def setupCSS(CSS):
 
         # Add test module to runtime call list
         scSim.AddModelToTask(simTaskName, module)
-        scSim.AddVariableForLogging('SunlineSEKF.bVec_B', simulationTimeStep, 0, 2)
+        bVecLogger = module.logger('bVec_B', simulationTimeStep)
+        scSim.AddModelToTask(simTaskName, bVecLogger)
 
     if FilterType == 'SuKF':
         numStates = 6
@@ -528,7 +530,8 @@ def setupCSS(CSS):
 
         # Add test module to runtime call list
         scSim.AddModelToTask(simTaskName, module)
-        scSim.AddVariableForLogging('SunlineSuKF.bVec_B', simulationTimeStep, 0, 2)
+        bVecLogger = module.logger('bVec_B', simulationTimeStep)
+        scSim.AddModelToTask(simTaskName, bVecLogger)
 
     module.cssDataInMsg.subscribeTo(cssConstelation.constellationOutMsg)
     module.cssConfigInMsg.subscribeTo(cssConstMsg)
@@ -570,13 +573,15 @@ def addTimeColumn(time, data):
     covarLog = addTimeColumn(timeAxis, filtLog.covar[:, range(numStates*numStates)])
     obsLog = addTimeColumn(timeAxis, filtLog.numObs)
 
+    # Get bVec_B through the variable logger
+    bVecLog = None if bVecLogger is None else addTimeColumn(timeAxis, bVecLogger.bVec_B)
+
     dcmLog = np.zeros([len(stateLog[:,0]),3,3])
     omegaExp = np.zeros([len(stateLog[:,0]),3])
     if FilterType == 'SEKF':
         dcm = sunlineSEKF.new_doubleArray(3 * 3)
         for j in range(9):
             sunlineSEKF.doubleArray_setitem(dcm, j, 0)
-        bVecLog = scSim.GetLogVariableData('SunlineSEKF.bVec_B')
         for i in range(len(stateLog[:,0])):
             sunlineSEKF.sunlineSEKFComputeDCM_BS(stateLog[i,1:4].tolist(), bVecLog[i, 1:4].tolist(), dcm)
             dcmOut = []
@@ -588,7 +593,6 @@ def addTimeColumn(time, data):
         dcm = sunlineSuKF.new_doubleArray(3 * 3)
         for j in range(9):
             sunlineSuKF.doubleArray_setitem(dcm, j, 0)
-        bVecLog = scSim.GetLogVariableData('SunlineSuKF.bVec_B')
         for i in range(len(stateLog[:,0])):
             sunlineSuKF.sunlineSuKFComputeDCM_BS(stateLog[i,1:4].tolist(), bVecLog[i, 1:4].tolist(), dcm)
             dcmOut = []

examples/scenarioDragDeorbit.py

@@ -250,9 +250,11 @@ def run(show_plots, initialAlt=250, deorbitAlt=100, model="exponential"):
     # Setup data logging before the simulation is initialized
     dataRec = scObject.scStateOutMsg.recorder(samplingTime)
     dataAtmoLog = atmo.envOutMsgs[0].recorder(samplingTime)
+    forceLog = dragEffector.logger("forceExternal_B", samplingTime)
+
     scSim.AddModelToTask(simTaskName, dataRec)
     scSim.AddModelToTask(simTaskName, dataAtmoLog)
-    scSim.AddVariableForLogging('DragEff.forceExternal_B', samplingTime, StartIndex=0, StopIndex=2)
+    scSim.AddModelToTask(simTaskName, forceLog)
 
     # Event to terminate the simulation
     scSim.createNewEvent("Deorbited", simulationTimeStep, True,
@@ -282,7 +284,7 @@ def run(show_plots, initialAlt=250, deorbitAlt=100, model="exponential"):
     # retrieve the logged data
     posData = dataRec.r_BN_N
     velData = dataRec.v_BN_N
-    dragForce = scSim.GetLogVariableData('DragEff.forceExternal_B')
+    dragForce = forceLog.forceExternal_B
     denseData = dataAtmoLog.neutralDensity
 
     figureList = plotOrbits(dataRec.times(), posData, velData, dragForce, denseData, oe, mu, planet, model)
@@ -348,7 +350,7 @@ def register_fig(i):
 
     # draw drag as a function of time
     fig, ax = register_fig(4)
-    plt.semilogy(timeAxis * macros.NANO2HOUR, np.linalg.norm(dragForce[:, 1:], 2, 1))
+    plt.semilogy(timeAxis * macros.NANO2HOUR, np.linalg.norm(dragForce, 2, 1))
     plt.xlabel('$t$ [hr]')
     plt.ylabel('$|F_drag|$ [N]')
 

examples/scenarioDragRendezvous.py

@@ -255,10 +255,6 @@ def drag_simulator(altOffset, trueAnomOffset, densMultiplier, ctrlType='lqr', us
     scSim.AddModelToTask(dynTaskName, chiefNav,800)
     scSim.AddModelToTask(dynTaskName, depNav,801)
     # scSim.AddModelToTask(dynTaskName, gravFactory.spiceObject, 999)
-    scSim.AddVariableForLogging(chiefDrag.ModelTag + ".forceExternal_B",
-                                      dynTimeStep, 0, 2, 'double')
-    scSim.AddVariableForLogging(depDrag.ModelTag + ".forceExternal_B",
-                                      dynTimeStep, 0, 2, 'double')
 
     ##  FSW setup
     #   Chief S/C
@@ -306,12 +302,14 @@ def drag_simulator(altOffset, trueAnomOffset, densMultiplier, ctrlType='lqr', us
     numDataPoints = 21384
     samplingTime = simulationTime // (numDataPoints - 1)
 
-    #   Set up recorders
+    #   Set up recorders and loggers
     chiefStateRec = chiefSc.scStateOutMsg.recorder()
     depStateRec = depSc.scStateOutMsg.recorder()
     hillStateRec = hillStateNavObj.hillStateOutMsg.recorder()
     depAttRec = depAttRef.attRefOutMsg.recorder()
     chiefAttRec = chiefAttRef.attRefOutMsg.recorder()
+    chiefDragForceLog = chiefDrag.logger("forceExternal_B")
+    depDragForceLog = depDrag.logger("forceExternal_B")
     atmoRecs = []
     for msg in atmosphere.envOutMsgs:
         atmoRec = msg.recorder()
@@ -322,8 +320,11 @@ def drag_simulator(altOffset, trueAnomOffset, densMultiplier, ctrlType='lqr', us
     scSim.AddModelToTask(dynTaskName, hillStateRec, 702)
     scSim.AddModelToTask(dynTaskName, depAttRec, 703)
     scSim.AddModelToTask(dynTaskName, chiefAttRec, 704)
+    scSim.AddModelToTask(dynTaskName, chiefDragForceLog, 705)
+    scSim.AddModelToTask(dynTaskName, depDragForceLog, 706)
+
     for ind,rec in enumerate(atmoRecs):
-        scSim.AddModelToTask(dynTaskName, rec, 705+ind)
+        scSim.AddModelToTask(dynTaskName, rec, 707+ind)
 
     # if this scenario is to interface with the BSK Viz, uncomment the following lines
     # to save the BSK data to a file, uncomment the saveFile line below
@@ -345,8 +346,8 @@ def drag_simulator(altOffset, trueAnomOffset, densMultiplier, ctrlType='lqr', us
     print(f"Sim complete in {execTime} seconds, pulling data...")
     # ----- pull ----- #
     results_dict = {}
-    results_dict['chiefDrag_B'] = scSim.GetLogVariableData(chiefDrag.ModelTag + ".forceExternal_B")
-    results_dict['depDrag_B'] = scSim.GetLogVariableData(depDrag.ModelTag + ".forceExternal_B")
+    results_dict['chiefDrag_B'] = chiefDragForceLog.forceExternal_B
+    results_dict['depDrag_B'] = depDragForceLog.forceExternal_B
     results_dict['dynTimeData'] = chiefStateRec.times()
     results_dict['fswTimeData'] = depAttRec.times()
     results_dict['wiggum.r_BN_N'] = chiefStateRec.r_BN_N 
@@ -453,27 +454,27 @@ def run(show_plots, altOffset, trueAnomOffset, densMultiplier, ctrlType='lqr', u
 
     #   Debug plots
     plt.figure()
-    plt.plot(timeData[1:], depDrag[1:,1]-chiefDrag[1:,1],label="delta a_1")
-    plt.plot(timeData[1:], depDrag[1:,2]-chiefDrag[1:,2],label="delta a_2")
-    plt.plot(timeData[1:], depDrag[1:,3]-chiefDrag[1:,3],label="delta a_3")
+    plt.plot(timeData[1:], depDrag[1:,0]-chiefDrag[1:,0],label="delta a_1")
+    plt.plot(timeData[1:], depDrag[1:,1]-chiefDrag[1:,1],label="delta a_2")
+    plt.plot(timeData[1:], depDrag[1:,2]-chiefDrag[1:,2],label="delta a_3")
     plt.grid()
     plt.legend()
     plt.xlabel('Time')   
     plt.ylabel('Relative acceleration due to drag, body frame (m/s)')
 
     plt.figure()
-    plt.plot(timeData[1:], chiefDrag[1:,1],label="chief a_1")
-    plt.plot(timeData[1:], chiefDrag[1:,2],label="chief a_2")
-    plt.plot(timeData[1:], chiefDrag[1:,3],label="chief a_3")
+    plt.plot(timeData[1:], chiefDrag[1:,0],label="chief a_1")
+    plt.plot(timeData[1:], chiefDrag[1:,1],label="chief a_2")
+    plt.plot(timeData[1:], chiefDrag[1:,2],label="chief a_3")
     plt.grid()
     plt.legend()
     plt.xlabel('Time')   
     plt.ylabel('Relative acceleration due to drag, body frame (m/s)')
 
     plt.figure()
-    plt.plot(timeData[1:], depDrag[1:,1],label="dep a_1")
-    plt.plot(timeData[1:], depDrag[1:,2],label="dep a_2")
-    plt.plot(timeData[1:], depDrag[1:,3],label="dep a_3")
+    plt.plot(timeData[1:], depDrag[1:,0],label="dep a_1")
+    plt.plot(timeData[1:], depDrag[1:,1],label="dep a_2")
+    plt.plot(timeData[1:], depDrag[1:,2],label="dep a_3")
     plt.grid()
     plt.legend()
     plt.xlabel('Time')