2023-05-11T16:29:39.618Z,1683822579.618 [Supervisor](DEBUG): Initializing supervisor.
2023-05-11T16:29:39.623Z,1683822579.623 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2023-05-11T16:29:39.624Z,1683822579.624 [SyncHandler](INFO): Protected caller Thread ID is 991
2023-05-11T16:29:39.624Z,1683822579.624 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2023-05-11T16:29:39.626Z,1683822579.626 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2023-05-11T16:29:39.626Z,1683822579.626 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 992
2023-05-11T16:29:39.630Z,1683822579.630 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2023-05-11T16:29:39.648Z,1683822579.648 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2023-05-11T16:29:39.649Z,1683822579.649 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2023-05-11T16:29:39.649Z,1683822579.649 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 993
2023-05-11T16:29:39.653Z,1683822579.653 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2023-05-11T16:29:39.654Z,1683822579.654 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2023-05-11T16:29:39.655Z,1683822579.655 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 994
2023-05-11T16:29:39.657Z,1683822579.657 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2023-05-11T16:29:39.658Z,1683822579.658 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2023-05-11T16:29:39.658Z,1683822579.658 [logger ThreadHandler](INFO): Protected caller Thread ID is 995
2023-05-11T16:29:39.662Z,1683822579.662 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2023-05-11T16:29:39.662Z,1683822579.662 [Supervisor](INFO): Looking for Config files in directory: Config/
2023-05-11T16:29:39.664Z,1683822579.664 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2023-05-11T16:29:39.763Z,1683822579.763 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2023-05-11T16:29:39.764Z,1683822579.764 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2023-05-11T16:29:40.576Z,1683822580.576 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2023-05-11T16:29:40.577Z,1683822580.577 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2023-05-11T16:29:40.857Z,1683822580.857 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2023-05-11T16:29:40.857Z,1683822580.857 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2023-05-11T16:29:40.937Z,1683822580.937 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2023-05-11T16:29:41.073Z,1683822581.073 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2023-05-11T16:29:41.073Z,1683822581.073 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2023-05-11T16:29:41.155Z,1683822581.155 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2023-05-11T16:29:41.265Z,1683822581.265 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2023-05-11T16:29:41.266Z,1683822581.266 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2023-05-11T16:29:41.671Z,1683822581.671 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2023-05-11T16:29:41.671Z,1683822581.671 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2023-05-11T16:29:42.184Z,1683822582.184 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2023-05-11T16:29:42.185Z,1683822582.185 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2023-05-11T16:29:42.415Z,1683822582.415 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2023-05-11T16:29:42.416Z,1683822582.416 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2023-05-11T16:29:42.612Z,1683822582.612 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2023-05-11T16:29:42.613Z,1683822582.613 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2023-05-11T16:29:43.144Z,1683822583.144 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2023-05-11T16:29:43.145Z,1683822583.145 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2023-05-11T16:29:43.453Z,1683822583.453 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2023-05-11T16:29:43.454Z,1683822583.454 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2023-05-11T16:29:43.677Z,1683822583.677 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2023-05-11T16:29:43.677Z,1683822583.677 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2023-05-11T16:29:44.059Z,1683822584.059 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2023-05-11T16:29:44.060Z,1683822584.060 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2023-05-11T16:29:44.412Z,1683822584.412 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2023-05-11T16:29:44.414Z,1683822584.414 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/
2023-05-11T16:29:44.415Z,1683822584.415 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg
2023-05-11T16:29:44.501Z,1683822584.501 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg
2023-05-11T16:29:44.664Z,1683822584.664 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg
2023-05-11T16:29:44.768Z,1683822584.768 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg
2023-05-11T16:29:44.854Z,1683822584.854 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg
2023-05-11T16:29:44.950Z,1683822584.950 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg
2023-05-11T16:29:45.138Z,1683822585.138 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg
2023-05-11T16:29:45.410Z,1683822585.410 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2023-05-11T16:29:45.411Z,1683822585.411 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg
2023-05-11T16:29:45.506Z,1683822585.506 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg
2023-05-11T16:29:45.644Z,1683822585.644 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg
2023-05-11T16:29:45.935Z,1683822585.935 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg
2023-05-11T16:29:46.294Z,1683822586.294 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/root/
2023-05-11T16:29:46.294Z,1683822586.294 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2023-05-11T16:29:46.664Z,1683822586.664 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2023-05-11T16:29:46.877Z,1683822586.877 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2023-05-11T16:29:46.878Z,1683822586.878 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2023-05-11T16:29:46.984Z,1683822586.984 [VerticalControl](DEBUG): Construct VerticalControl.
2023-05-11T16:29:47.046Z,1683822587.046 [VerticalControl] Loaded
2023-05-11T16:29:47.046Z,1683822587.046 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2023-05-11T16:29:47.049Z,1683822587.049 [HorizontalControl](DEBUG): Construct HorizontalControl.
2023-05-11T16:29:47.092Z,1683822587.092 [HorizontalControl] Loaded
2023-05-11T16:29:47.092Z,1683822587.092 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2023-05-11T16:29:47.095Z,1683822587.095 [SpeedControl](DEBUG): Construct SpeedControl.
2023-05-11T16:29:47.098Z,1683822587.098 [SpeedControl] Loaded
2023-05-11T16:29:47.098Z,1683822587.098 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2023-05-11T16:29:47.101Z,1683822587.101 [LoopControl](DEBUG): Construct LoopControl.
2023-05-11T16:29:47.101Z,1683822587.101 [LoopControl] Loaded
2023-05-11T16:29:47.102Z,1683822587.102 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2023-05-11T16:29:47.102Z,1683822587.102 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2023-05-11T16:29:47.102Z,1683822587.102 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2023-05-11T16:29:47.154Z,1683822587.154 [DepthRateCalculator] Loaded
2023-05-11T16:29:47.154Z,1683822587.154 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2023-05-11T16:29:47.159Z,1683822587.159 [PitchRateCalculator] Loaded
2023-05-11T16:29:47.159Z,1683822587.159 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2023-05-11T16:29:47.169Z,1683822587.169 [SpeedCalculator] Loaded
2023-05-11T16:29:47.170Z,1683822587.170 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2023-05-11T16:29:47.174Z,1683822587.174 [YawRateCalculator] Loaded
2023-05-11T16:29:47.174Z,1683822587.174 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2023-05-11T16:29:47.193Z,1683822587.193 [ElevatorOffsetCalculator] Loaded
2023-05-11T16:29:47.193Z,1683822587.193 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2023-05-11T16:29:47.194Z,1683822587.194 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2023-05-11T16:29:47.194Z,1683822587.194 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2023-05-11T16:29:47.222Z,1683822587.222 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2023-05-11T16:29:47.223Z,1683822587.223 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2023-05-11T16:29:47.297Z,1683822587.297 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2023-05-11T16:29:47.297Z,1683822587.297 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2023-05-11T16:29:47.624Z,1683822587.624 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2023-05-11T16:29:47.625Z,1683822587.625 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2023-05-11T16:29:47.780Z,1683822587.780 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2023-05-11T16:29:47.781Z,1683822587.781 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2023-05-11T16:29:48.262Z,1683822588.262 [AHRS_M2] Loaded
2023-05-11T16:29:48.263Z,1683822588.263 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2023-05-11T16:29:48.298Z,1683822588.298 [BackseatComponent] Loaded
2023-05-11T16:29:48.298Z,1683822588.298 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2023-05-11T16:29:48.300Z,1683822588.300 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 409984E0
2023-05-11T16:29:48.300Z,1683822588.300 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 1077
2023-05-11T16:29:48.303Z,1683822588.303 [LcmUniversalReporter] Loaded
2023-05-11T16:29:48.303Z,1683822588.303 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2023-05-11T16:29:49.136Z,1683822589.136 [BPC1] Loaded
2023-05-11T16:29:49.137Z,1683822589.137 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2023-05-11T16:29:49.222Z,1683822589.222 [DATMMP] Loaded
2023-05-11T16:29:49.222Z,1683822589.222 [ComponentRegistry](DEBUG): Component "DATMMP" handled in its own thread.
2023-05-11T16:29:49.223Z,1683822589.223 [DATMMP ThreadHandler](DEBUG): Created PCaller Thread at 409C94E0
2023-05-11T16:29:49.224Z,1683822589.224 [DATMMP ThreadHandler](INFO): Protected caller Thread ID is 1078
2023-05-11T16:29:49.294Z,1683822589.294 [DataOverHttps] Loaded
2023-05-11T16:29:49.294Z,1683822589.294 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2023-05-11T16:29:49.295Z,1683822589.295 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409F94E0
2023-05-11T16:29:49.296Z,1683822589.296 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1079
2023-05-11T16:29:49.317Z,1683822589.317 [Depth_Keller] Loaded
2023-05-11T16:29:49.317Z,1683822589.317 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2023-05-11T16:29:49.382Z,1683822589.382 [NAL9602] Loaded
2023-05-11T16:29:49.382Z,1683822589.382 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2023-05-11T16:29:49.413Z,1683822589.413 [Onboard] Loaded
2023-05-11T16:29:49.413Z,1683822589.413 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2023-05-11T16:29:49.414Z,1683822589.414 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40A294E0
2023-05-11T16:29:49.415Z,1683822589.415 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 1080
2023-05-11T16:29:49.427Z,1683822589.427 [Power24vConverter] Loaded
2023-05-11T16:29:49.428Z,1683822589.428 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2023-05-11T16:29:49.441Z,1683822589.441 [Radio_Surface] Loaded
2023-05-11T16:29:49.441Z,1683822589.441 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2023-05-11T16:29:49.442Z,1683822589.442 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40A594E0
2023-05-11T16:29:49.442Z,1683822589.442 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1081
2023-05-11T16:29:49.490Z,1683822589.490 [RDI_Pathfinder] Loaded
2023-05-11T16:29:49.490Z,1683822589.490 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2023-05-11T16:29:49.491Z,1683822589.491 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2023-05-11T16:29:49.492Z,1683822589.492 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2023-05-11T16:29:49.606Z,1683822589.606 [DeadReckonUsingMultipleVelocitySources] Loaded
2023-05-11T16:29:49.606Z,1683822589.606 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2023-05-11T16:29:49.620Z,1683822589.620 [NavChart] Loaded
2023-05-11T16:29:49.620Z,1683822589.620 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2023-05-11T16:29:49.626Z,1683822589.626 [UniversalFixResidualReporter] Loaded
2023-05-11T16:29:49.626Z,1683822589.626 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2023-05-11T16:29:49.627Z,1683822589.627 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2023-05-11T16:29:49.627Z,1683822589.627 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2023-05-11T16:29:49.777Z,1683822589.777 [SBIT](DEBUG): Construct Startup Built In Test.
2023-05-11T16:29:49.786Z,1683822589.786 [SBIT] Loaded
2023-05-11T16:29:49.787Z,1683822589.787 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2023-05-11T16:29:49.790Z,1683822589.790 [IBIT](DEBUG): Construct Initiated Built In Test.
2023-05-11T16:29:49.803Z,1683822589.803 [IBIT] Loaded
2023-05-11T16:29:49.803Z,1683822589.803 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2023-05-11T16:29:49.809Z,1683822589.809 [CBIT](DEBUG): Construct Continuous Built In Test.
2023-05-11T16:29:49.917Z,1683822589.917 [CBIT] Loaded
2023-05-11T16:29:49.917Z,1683822589.917 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2023-05-11T16:29:49.918Z,1683822589.918 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2023-05-11T16:29:49.918Z,1683822589.918 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2023-05-11T16:29:50.058Z,1683822590.058 [BuoyancyServo] Loaded
2023-05-11T16:29:50.058Z,1683822590.058 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2023-05-11T16:29:50.080Z,1683822590.080 [ElevatorServo] Loaded
2023-05-11T16:29:50.080Z,1683822590.080 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2023-05-11T16:29:50.100Z,1683822590.100 [MassServo] Loaded
2023-05-11T16:29:50.100Z,1683822590.100 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2023-05-11T16:29:50.119Z,1683822590.119 [RudderServo] Loaded
2023-05-11T16:29:50.120Z,1683822590.120 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2023-05-11T16:29:50.137Z,1683822590.137 [ThrusterServo] Loaded
2023-05-11T16:29:50.138Z,1683822590.138 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2023-05-11T16:29:50.138Z,1683822590.138 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2023-05-11T16:29:50.139Z,1683822590.139 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2023-05-11T16:29:50.149Z,1683822590.149 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2023-05-11T16:29:50.150Z,1683822590.150 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2023-05-11T16:29:50.328Z,1683822590.328 [CTD_Seabird] Loaded
2023-05-11T16:29:50.329Z,1683822590.329 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2023-05-11T16:29:50.330Z,1683822590.330 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40BA14E0
2023-05-11T16:29:50.330Z,1683822590.330 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1082
2023-05-11T16:29:50.351Z,1683822590.351 [PAR_Licor] Loaded
2023-05-11T16:29:50.351Z,1683822590.351 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2023-05-11T16:29:50.384Z,1683822590.384 [WetLabsBB2FL] Loaded
2023-05-11T16:29:50.384Z,1683822590.384 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2023-05-11T16:29:50.385Z,1683822590.385 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40BD14E0
2023-05-11T16:29:50.385Z,1683822590.385 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1083
2023-05-11T16:29:50.406Z,1683822590.406 [WetLabsUBAT] Loaded
2023-05-11T16:29:50.406Z,1683822590.406 [ComponentRegistry](DEBUG): Component "WetLabsUBAT" handled in its own thread.
2023-05-11T16:29:50.407Z,1683822590.407 [WetLabsUBAT ThreadHandler](DEBUG): Created PCaller Thread at 40C014E0
2023-05-11T16:29:50.407Z,1683822590.407 [WetLabsUBAT ThreadHandler](INFO): Protected caller Thread ID is 1084
2023-05-11T16:29:50.408Z,1683822590.408 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2023-05-11T16:29:50.414Z,1683822590.414 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2023-05-11T16:29:50.417Z,1683822590.417 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2023-05-11T16:29:50.428Z,1683822590.428 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2023-05-11T16:29:50.429Z,1683822590.429 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C314E0
2023-05-11T16:29:50.430Z,1683822590.430 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1085
2023-05-11T16:29:50.434Z,1683822590.434 [Supervisor](INFO): Main Thread ID is 830
2023-05-11T16:29:50.434Z,1683822590.434 [Supervisor](DEBUG): Running supervisor.
2023-05-11T16:29:50.435Z,1683822590.435 [CommandExec ThreadHandler](INFO): Handler Thread ID is 1086
2023-05-11T16:29:50.435Z,1683822590.435 [CommandExec](INFO): Initializing the command executive.
2023-05-11T16:29:50.437Z,1683822590.437 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1087
2023-05-11T16:29:50.439Z,1683822590.439 [controlThread ThreadHandler](INFO): Handler Thread ID is 1088
2023-05-11T16:29:50.440Z,1683822590.440 [controlThread](DEBUG): Initializing ControlThread
2023-05-11T16:29:50.440Z,1683822590.440 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2023-05-11T16:29:50.442Z,1683822590.442 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2023-05-11T16:29:50.443Z,1683822590.443 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2023-05-11T16:29:50.443Z,1683822590.443 [LoopControl](DEBUG): Initialize LoopControlComponent.
2023-05-11T16:29:50.444Z,1683822590.444 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2023-05-11T16:29:50.445Z,1683822590.445 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2023-05-11T16:29:50.445Z,1683822590.445 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2023-05-11T16:29:50.445Z,1683822590.445 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2023-05-11T16:29:50.446Z,1683822590.446 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2023-05-11T16:29:50.449Z,1683822590.449 [NavChart](DEBUG): Initialize NavChart Navigation.
2023-05-11T16:29:50.450Z,1683822590.450 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2023-05-11T16:29:50.450Z,1683822590.450 [SBIT](INFO): Initialize SBIT Component.
2023-05-11T16:29:50.450Z,1683822590.450 [SBIT](IMPORTANT): git: 2023-04-26-68-gd8052d973
2023-05-11T16:29:50.451Z,1683822590.451 [SBIT](INFO): git hash: d8052d9734beefc1bd50265fa9cca972428f086c
2023-05-11T16:29:50.451Z,1683822590.451 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2023-05-11T16:29:50.452Z,1683822590.452 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2023-05-11T16:29:50.453Z,1683822590.453 [SBIT](INFO): Beginning SBIT in 51.000000 seconds.
2023-05-11T16:29:50.454Z,1683822590.454 [IBIT](INFO): Initialize IBIT Component.
2023-05-11T16:29:50.455Z,1683822590.455 [CBIT](DEBUG): Initialize CBIT Component.
2023-05-11T16:29:50.456Z,1683822590.456 [logger ThreadHandler](INFO): Handler Thread ID is 1089
2023-05-11T16:29:50.468Z,1683822590.468 [CBIT](DEBUG): Initialized mux pins.
2023-05-11T16:29:50.468Z,1683822590.468 [CBIT](DEBUG): Initializing the watchdog timer.
2023-05-11T16:29:50.476Z,1683822590.476 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 1090
2023-05-11T16:29:50.488Z,1683822590.488 [DATMMP ThreadHandler](INFO): Handler Thread ID is 1091
2023-05-11T16:29:50.489Z,1683822590.489 [DATMMP](INFO): Start
2023-05-11T16:29:50.489Z,1683822590.489 [DATMMP](INFO): Powering up
2023-05-11T16:29:50.489Z,1683822590.489 [DATMMP](DEBUG): Initializing DATMMP.
2023-05-11T16:29:50.492Z,1683822590.492 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2023-05-11T16:29:50.492Z,1683822590.492 [CBIT](DEBUG): Initializing heartbeat.
2023-05-11T16:29:50.494Z,1683822590.494 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1093
2023-05-11T16:29:50.495Z,1683822590.495 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2023-05-11T16:29:50.504Z,1683822590.504 [Onboard ThreadHandler](INFO): Handler Thread ID is 1094
2023-05-11T16:29:50.522Z,1683822590.522 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1095
2023-05-11T16:29:50.540Z,1683822590.540 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1096
2023-05-11T16:29:50.541Z,1683822590.541 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2023-05-11T16:29:50.545Z,1683822590.545 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1098
2023-05-11T16:29:50.548Z,1683822590.548 [WetLabsBB2FL](INFO): Powering up
2023-05-11T16:29:50.549Z,1683822590.549 [WetLabsUBAT ThreadHandler](INFO): Handler Thread ID is 1100
2023-05-11T16:29:50.552Z,1683822590.552 [WetLabsUBAT](INFO): Powering up
2023-05-11T16:29:50.553Z,1683822590.553 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1102
2023-05-11T16:29:50.557Z,1683822590.557 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2023-05-11T16:29:50.557Z,1683822590.557 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2023-05-11T16:29:50.557Z,1683822590.557 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2023-05-11T16:29:50.557Z,1683822590.557 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2023-05-11T16:29:50.557Z,1683822590.557 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2023-05-11T16:29:50.558Z,1683822590.558 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2023-05-11T16:29:50.558Z,1683822590.558 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2023-05-11T16:29:50.558Z,1683822590.558 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2023-05-11T16:29:50.564Z,1683822590.564 [CBIT](DEBUG): Deactivating GF circuits.
2023-05-11T16:29:50.564Z,1683822590.564 [CBIT](DEBUG): Deactivating emergency mode.
2023-05-11T16:29:50.604Z,1683822590.604 [CBIT](DEBUG): Backplane powered.
2023-05-11T16:29:50.609Z,1683822590.609 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2023-05-11T16:29:50.675Z,1683822590.675 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2023-05-11T16:29:50.709Z,1683822590.709 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2023-05-11T16:29:50.710Z,1683822590.710 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2023-05-11T16:29:50.740Z,1683822590.740 [DATMMP](INFO): Starting
2023-05-11T16:29:50.804Z,1683822590.804 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2023-05-11T16:29:50.805Z,1683822590.805 [Default:A.Wait](DEBUG): Construct Wait.
2023-05-11T16:29:50.808Z,1683822590.808 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-05-11T16:29:50.846Z,1683822590.846 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2023-05-11T16:29:50.849Z,1683822590.849 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2023-05-11T16:29:50.882Z,1683822590.882 [Default:E.Execute](DEBUG): Construct Execute.
2023-05-11T16:29:50.894Z,1683822590.894 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

    <DefineArg Name="ElapsedSinceDefaultStarted"><Units:minute/><Value>0</Value></DefineArg>

    <Guidance:Wait>
        <Description>
            Wait a moment to see if the scheduler starts a new mission before
            starting to actually run Default.
        </Description>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Units:second/><Value>13</Value></Setting>
    </Guidance:Wait>

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P4H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn on</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>5</Value></Setting>
        </Guidance:Wait>

        <Assign><Sequence/><Arg Name="ElapsedSinceDefaultStarted"/><Elapsed><Universal:mission_started/></Elapsed></Assign>

        <Syslog Severity="Important">Default mission has been running for <Arg Name="ElapsedSinceDefaultStarted"/><Units:minute/></Syslog>

    </Aggregate>

    <Syslog Severity="Important">Restarting logs and Default mission.</Syslog>

    <Guidance:Execute>
        <Sequence/>
        <Setting><Guidance:Execute.command/><String>restart logs</String></Setting>
    </Guidance:Execute>

</Mission>


2023-05-11T16:29:50.898Z,1683822590.898 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,NAL9602,Power24vConverter,RDI_Pathfinder,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2023-05-11T16:29:50.921Z,1683822590.921 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-05-11T16:29:50.928Z,1683822590.928 [Radio_Surface](INFO): Powering up
2023-05-11T16:29:50.989Z,1683822590.989 [Depth_Keller](ERROR): Pressure or depth reading out of range: -1.000394 decibar, -0.993016 m
2023-05-11T16:29:50.990Z,1683822590.990 [Power24vConverter](INFO): Powering up.
2023-05-11T16:29:50.991Z,1683822590.991 [RDI_Pathfinder](IMPORTANT): Expecting PD13 message format
2023-05-11T16:29:50.992Z,1683822590.992 [DATMMP](INFO): Starting
2023-05-11T16:29:51.080Z,1683822591.080 [DepthRateCalculator](ERROR): Depth measurement is not active
2023-05-11T16:29:51.100Z,1683822591.100 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2023-05-11T16:29:51.108Z,1683822591.108 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2023-05-11T16:29:51.109Z,1683822591.109 [ElevatorServo](DEBUG): Initializing EZServoServo.
2023-05-11T16:29:51.116Z,1683822591.116 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2023-05-11T16:29:51.117Z,1683822591.117 [MassServo](DEBUG): Initializing EZServoServo.
2023-05-11T16:29:51.124Z,1683822591.124 [MassServo](DEBUG): Initializing MassServo.
2023-05-11T16:29:51.125Z,1683822591.125 [RudderServo](DEBUG): Initializing EZServoServo.
2023-05-11T16:29:51.132Z,1683822591.132 [RudderServo](DEBUG): Initializing RudderServo.
2023-05-11T16:29:51.133Z,1683822591.133 [ThrusterServo](DEBUG): Initializing EZServoServo.
2023-05-11T16:29:51.144Z,1683822591.144 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2023-05-11T16:29:51.244Z,1683822591.244 [DATMMP](INFO): Starting
2023-05-11T16:29:51.497Z,1683822591.497 [DATMMP](INFO): Starting
2023-05-11T16:29:51.748Z,1683822591.748 [DATMMP](INFO): Starting
2023-05-11T16:29:51.000Z,1683822592.000 [DATMMP](INFO): Starting
2023-05-11T16:29:52.252Z,1683822592.252 [DATMMP](INFO): Starting
2023-05-11T16:29:52.504Z,1683822592.504 [DATMMP](INFO): Starting
2023-05-11T16:29:52.756Z,1683822592.756 [DATMMP](INFO): Starting
2023-05-11T16:29:53.008Z,1683822593.008 [DATMMP](INFO): Starting
2023-05-11T16:29:53.160Z,1683822593.160 [WetLabsBB2FL](INFO): Powering down
2023-05-11T16:29:53.260Z,1683822593.260 [DATMMP](INFO): Starting
2023-05-11T16:29:53.512Z,1683822593.512 [DATMMP](INFO): Starting
2023-05-11T16:29:53.764Z,1683822593.764 [DATMMP](INFO): Starting
2023-05-11T16:29:54.016Z,1683822594.016 [DATMMP](INFO): Starting
2023-05-11T16:29:54.269Z,1683822594.269 [DATMMP](INFO): Starting
2023-05-11T16:29:54.520Z,1683822594.520 [DATMMP](INFO): Starting
2023-05-11T16:29:54.772Z,1683822594.772 [DATMMP](INFO): Starting
2023-05-11T16:29:55.024Z,1683822595.024 [DATMMP](INFO): Starting
2023-05-11T16:29:55.276Z,1683822595.276 [DATMMP](INFO): Starting
2023-05-11T16:29:55.528Z,1683822595.528 [DATMMP](INFO): Starting
2023-05-11T16:29:55.780Z,1683822595.780 [DATMMP](INFO): Starting
2023-05-11T16:29:56.032Z,1683822596.032 [DATMMP](INFO): Starting
2023-05-11T16:29:56.284Z,1683822596.284 [DATMMP](INFO): Starting
2023-05-11T16:29:56.536Z,1683822596.536 [DATMMP](INFO): Starting
2023-05-11T16:29:56.788Z,1683822596.788 [DATMMP](INFO): Starting
2023-05-11T16:29:57.040Z,1683822597.040 [DATMMP](INFO): Starting
2023-05-11T16:29:57.292Z,1683822597.292 [DATMMP](INFO): Starting
2023-05-11T16:29:57.544Z,1683822597.544 [DATMMP](INFO): Starting
2023-05-11T16:29:57.572Z,1683822597.572 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2023-05-11T16:29:57.796Z,1683822597.796 [DATMMP](INFO): Starting
2023-05-11T16:29:58.048Z,1683822598.048 [DATMMP](INFO): Starting
2023-05-11T16:29:58.300Z,1683822598.300 [DATMMP](INFO): Starting
2023-05-11T16:29:58.552Z,1683822598.552 [DATMMP](INFO): Starting
2023-05-11T16:29:58.804Z,1683822598.804 [DATMMP](INFO): Starting
2023-05-11T16:29:59.056Z,1683822599.056 [DATMMP](INFO): Starting
2023-05-11T16:29:59.308Z,1683822599.308 [DATMMP](INFO): Starting
2023-05-11T16:29:59.560Z,1683822599.560 [DATMMP](INFO): Starting
2023-05-11T16:29:59.813Z,1683822599.813 [DATMMP](INFO): Starting
2023-05-11T16:29:59.818Z,1683822599.818 [WetLabsUBAT](INFO): Powering down
2023-05-11T16:30:00.064Z,1683822600.064 [DATMMP](INFO): Starting
2023-05-11T16:30:00.316Z,1683822600.316 [DATMMP](INFO): Starting
2023-05-11T16:30:00.568Z,1683822600.568 [DATMMP](INFO): Starting
2023-05-11T16:30:00.820Z,1683822600.820 [DATMMP](INFO): Starting
2023-05-11T16:30:01.072Z,1683822601.072 [DATMMP](INFO): Starting
2023-05-11T16:30:01.324Z,1683822601.324 [DATMMP](INFO): Starting
2023-05-11T16:30:01.576Z,1683822601.576 [DATMMP](INFO): Starting
2023-05-11T16:30:01.828Z,1683822601.828 [DATMMP](INFO): Starting
2023-05-11T16:30:02.080Z,1683822602.080 [DATMMP](INFO): Starting
2023-05-11T16:30:02.332Z,1683822602.332 [DATMMP](INFO): Starting
2023-05-11T16:30:02.584Z,1683822602.584 [DATMMP](INFO): Starting
2023-05-11T16:30:02.584Z,1683822602.584 [DATMMP](INFO): DAT read: 

2023-05-11T16:30:02.585Z,1683822602.585 [DATMMP](INFO): DAT read: Teledyne Benthos DAT-900 Series

2023-05-11T16:30:02.836Z,1683822602.836 [DATMMP](INFO): Starting
2023-05-11T16:30:03.089Z,1683822603.089 [DATMMP](INFO): Starting
2023-05-11T16:30:03.340Z,1683822603.340 [DATMMP](INFO): Starting
2023-05-11T16:30:03.592Z,1683822603.592 [DATMMP](INFO): Starting
2023-05-11T16:30:03.844Z,1683822603.844 [DATMMP](INFO): Starting
2023-05-11T16:30:04.096Z,1683822604.096 [DATMMP](INFO): Starting
2023-05-11T16:30:04.348Z,1683822604.348 [DATMMP](INFO): Starting
2023-05-11T16:30:04.349Z,1683822604.349 [DATMMP](INFO): DAT read: MF Frequency Band

2023-05-11T16:30:04.350Z,1683822604.350 [DATMMP](INFO): DAT read: Directional Acoustic Transponder version 8.15.0

2023-05-11T16:30:04.351Z,1683822604.351 [DATMMP](INFO): DAT read: Apr 11 2000 16:29:58 

2023-05-11T16:30:04.600Z,1683822604.600 [DATMMP](INFO): Starting
2023-05-11T16:30:04.852Z,1683822604.852 [DATMMP](INFO): Starting
2023-05-11T16:30:05.104Z,1683822605.104 [DATMMP](INFO): Starting
2023-05-11T16:30:05.356Z,1683822605.356 [DATMMP](INFO): Starting
2023-05-11T16:30:05.357Z,1683822605.357 [DATMMP](INFO): DAT read: Features enabled [Bearing]

2023-05-11T16:30:05.358Z,1683822605.358 [DATMMP](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2023-05-11T16:30:05.358Z,1683822605.358 [DATMMP](INFO): commRate: 800
2023-05-11T16:30:05.608Z,1683822605.608 [DATMMP](INFO): Starting
2023-05-11T16:30:05.860Z,1683822605.860 [DATMMP](INFO): Starting
2023-05-11T16:30:06.112Z,1683822606.112 [DATMMP](INFO): Starting
2023-05-11T16:30:06.364Z,1683822606.364 [DATMMP](INFO): Starting
2023-05-11T16:30:06.616Z,1683822606.616 [DATMMP](INFO): Starting
2023-05-11T16:30:06.868Z,1683822606.868 [DATMMP](INFO): Starting
2023-05-11T16:30:07.120Z,1683822607.120 [DATMMP](INFO): Starting
2023-05-11T16:30:07.372Z,1683822607.372 [DATMMP](INFO): Starting
2023-05-11T16:30:07.424Z,1683822607.424 [DATMMP](INFO): entering command mode
2023-05-11T16:30:07.624Z,1683822607.624 [DATMMP](INFO): Starting
2023-05-11T16:30:07.624Z,1683822607.624 [DATMMP](INFO): DAT read: 

2023-05-11T16:30:07.625Z,1683822607.625 [DATMMP](INFO): DAT read: user:1>

2023-05-11T16:30:07.625Z,1683822607.625 [DATMMP](DEBUG): read user prompt 1: user:1>

2023-05-11T16:30:07.625Z,1683822607.625 [DATMMP](INFO): entering MMP mode
2023-05-11T16:30:07.876Z,1683822607.876 [DATMMP](INFO): Starting
2023-05-11T16:30:07.877Z,1683822607.877 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:30:07.878Z,1683822607.878 [DATMMP](INFO): status rx: 	 x1
2023-05-11T16:30:07.879Z,1683822607.879 [DATMMP](INFO): MMP status: 1: started
2023-05-11T16:30:07.879Z,1683822607.879 [DATMMP](INFO): Received message type: status
2023-05-11T16:30:07.879Z,1683822607.879 [DATMMP](INFO): Handled
2023-05-11T16:30:08.128Z,1683822608.128 [DATMMP](INFO): Starting
2023-05-11T16:30:08.129Z,1683822608.129 [DATMMP](INFO): Sent Tx Power Config 8
2023-05-11T16:30:08.130Z,1683822608.130 [DATMMP](INFO): Setting local address: 10
2023-05-11T16:30:08.131Z,1683822608.131 [DATMMP](INFO): Setting time to: 16:30:8 And date to:5/11/2023
2023-05-11T16:30:08.380Z,1683822608.380 [DATMMP](INFO): Starting
2023-05-11T16:30:08.380Z,1683822608.380 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:30:08.381Z,1683822608.381 [DATMMP](INFO): mdmpower rx: 	 x8	 x0	 x5	 x0
2023-05-11T16:30:08.382Z,1683822608.382 [DATMMP](INFO): Received message type: mdmpower
2023-05-11T16:30:08.382Z,1683822608.382 [DATMMP](INFO): Handled
2023-05-11T16:30:08.632Z,1683822608.632 [DATMMP](INFO): Starting
2023-05-11T16:30:08.632Z,1683822608.632 [DATMMP](INFO): GSXN notify for xid: 10
2023-05-11T16:30:08.633Z,1683822608.633 [DATMMP](INFO): sreg_txpower rx: 	 x8
2023-05-11T16:30:08.633Z,1683822608.633 [DATMMP](INFO): Received message type: sreg_txpower
2023-05-11T16:30:08.633Z,1683822608.633 [DATMMP](INFO): Match for : sreg_txpower
2023-05-11T16:30:08.633Z,1683822608.633 [DATMMP](INFO): ACK
2023-05-11T16:30:08.884Z,1683822608.884 [DATMMP](INFO): Starting
2023-05-11T16:30:08.884Z,1683822608.884 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:30:08.885Z,1683822608.885 [DATMMP](INFO): mdmlocal rx: 	 xA	 x0	 x0	 x0
2023-05-11T16:30:08.885Z,1683822608.885 [DATMMP](INFO): Received message type: mdmlocal
2023-05-11T16:30:08.886Z,1683822608.886 [DATMMP](INFO): Handled
2023-05-11T16:30:09.136Z,1683822609.136 [DATMMP](INFO): Starting
2023-05-11T16:30:09.136Z,1683822609.136 [DATMMP](INFO): GSXN notify for xid: 11
2023-05-11T16:30:09.137Z,1683822609.137 [DATMMP](INFO): sreg_locaddr rx: 	 xA
2023-05-11T16:30:09.137Z,1683822609.137 [DATMMP](INFO): Received message type: sreg_locaddr
2023-05-11T16:30:09.137Z,1683822609.137 [DATMMP](INFO): Match for : sreg_locaddr
2023-05-11T16:30:09.137Z,1683822609.137 [DATMMP](INFO): ACK
2023-05-11T16:30:09.388Z,1683822609.388 [DATMMP](INFO): Starting
2023-05-11T16:30:09.389Z,1683822609.389 [DATMMP](INFO): GSXN notify for xid: 12
2023-05-11T16:30:09.390Z,1683822609.390 [DATMMP](INFO): timedate rx: 	 x0	 x10	 x1E	 x8	 x4	 xB	 x7B	 x0
2023-05-11T16:30:09.390Z,1683822609.390 [DATMMP](INFO): Received message type: timedate
2023-05-11T16:30:09.390Z,1683822609.390 [DATMMP](INFO): Match for : timedate
2023-05-11T16:30:09.390Z,1683822609.390 [DATMMP](INFO): ACK
2023-05-11T16:30:09.640Z,1683822609.640 [DATMMP](INFO): Starting
2023-05-11T16:30:09.640Z,1683822609.640 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:30:09.641Z,1683822609.641 [DATMMP](INFO): sys_verb rx: 	 x0	 x0	 x0	 x0
2023-05-11T16:30:09.642Z,1683822609.642 [DATMMP](INFO): Received message type: sys_verb
2023-05-11T16:30:09.642Z,1683822609.642 [DATMMP](INFO): Handled
2023-05-11T16:30:09.892Z,1683822609.892 [DATMMP](INFO): Starting
2023-05-11T16:30:09.892Z,1683822609.892 [DATMMP](INFO): GSXN notify for xid: 13
2023-05-11T16:30:09.893Z,1683822609.893 [DATMMP](INFO): sreg_verbosity rx: 	 x0
2023-05-11T16:30:09.893Z,1683822609.893 [DATMMP](INFO): Received message type: sreg_verbosity
2023-05-11T16:30:09.893Z,1683822609.893 [DATMMP](INFO): Match for : sreg_verbosity
2023-05-11T16:30:09.893Z,1683822609.893 [DATMMP](INFO): ACK
2023-05-11T16:30:10.144Z,1683822610.144 [DATMMP](INFO): Starting
2023-05-11T16:30:10.144Z,1683822610.144 [DATMMP](INFO): GSXN notify for xid: 14
2023-05-11T16:30:10.145Z,1683822610.145 [DATMMP](INFO): version rx: 	 x2	 x5
2023-05-11T16:30:10.146Z,1683822610.146 [DATMMP](INFO): DatMMPVersion: 2.5
2023-05-11T16:30:10.146Z,1683822610.146 [DATMMP](INFO): Received message type: version
2023-05-11T16:30:10.146Z,1683822610.146 [DATMMP](INFO): Match for : version
2023-05-11T16:30:10.146Z,1683822610.146 [DATMMP](INFO): ACK
2023-05-11T16:30:10.146Z,1683822610.146 [DATMMP](INFO): in MMP mode: config complete going to runnable
2023-05-11T16:30:19.621Z,1683822619.621 [NAL9602](INFO): Powering up NAL9602
2023-05-11T16:30:24.510Z,1683822624.510 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:30:24.518Z,1683822624.518 [DATMMP](INFO): timesync rx: 	 x0	 x1	 x1	 x0
2023-05-11T16:30:24.518Z,1683822624.518 [DATMMP](INFO): Received message type: timesync
2023-05-11T16:30:24.518Z,1683822624.518 [DATMMP](INFO): Handled
2023-05-11T16:30:30.577Z,1683822630.577 [NAL9602](INFO): NAL9602 initialized
2023-05-11T16:30:34.336Z,1683822634.336 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:30:34.337Z,1683822634.337 [DATMMP](INFO): timesync rx: 	 x1	 x0	 x1	 x0
2023-05-11T16:30:34.337Z,1683822634.337 [DATMMP](INFO): Received message type: timesync
2023-05-11T16:30:34.338Z,1683822634.338 [DATMMP](INFO): Handled
2023-05-11T16:30:42.251Z,1683822642.251 [SBIT](IMPORTANT): Beginning Startup BIT
2023-05-11T16:30:42.284Z,1683822642.284 [CBIT](IMPORTANT): Beginning ground fault scan
2023-05-11T16:30:51.988Z,1683822651.988 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:30:51.989Z,1683822651.989 [DATMMP](INFO): doppler rx: 	 x0
2023-05-11T16:30:51.989Z,1683822651.989 [DATMMP](INFO): Received message type: doppler
2023-05-11T16:30:51.990Z,1683822651.990 [DATMMP](INFO): Handled
2023-05-11T16:30:52.240Z,1683822652.240 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:30:52.241Z,1683822652.241 [DATMMP](INFO): timestamp rx: 	 x1	 x10	 x1E	 x32	 x117F
2023-05-11T16:30:52.242Z,1683822652.242 [DATMMP](INFO): Rx dataTimestamp_ set to:1683822693.776192
2023-05-11T16:30:52.243Z,1683822652.243 [DATMMP](INFO): Rx ping set to:1683822652.241390
2023-05-11T16:30:52.243Z,1683822652.243 [DATMMP](INFO): Received message type: timestamp
2023-05-11T16:30:52.243Z,1683822652.243 [DATMMP](INFO): Handled
2023-05-11T16:30:52.495Z,1683822652.495 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:30:52.499Z,1683822652.499 [DATMMP](INFO): remote_header rx: 	 xF	 x4	 x5	 x22	 x0	 xA	 x5	 x0
2023-05-11T16:30:52.500Z,1683822652.500 [DATMMP](INFO): DATA Src=5, Dst=10
2023-05-11T16:30:52.501Z,1683822652.501 [DATMMP](INFO): Received message type: remote_header
2023-05-11T16:30:52.501Z,1683822652.501 [DATMMP](INFO): Handled
2023-05-11T16:30:52.996Z,1683822652.996 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:30:52.997Z,1683822652.997 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-11T16:30:52.997Z,1683822652.997 [DATMMP](INFO): Received message type: nav_stat
2023-05-11T16:30:52.997Z,1683822652.997 [DATMMP](INFO): Handled
2023-05-11T16:30:53.213Z,1683822653.213 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.000822
CHAN A1 (24V): 0.000086
CHAN A2 (12V): -0.007373
CHAN A3 (5V): -0.002227
CHAN B0 (3.3V): 0.000081
CHAN B1 (3.15aV): -0.000189
CHAN B2 (3.15bV): 0.000545
CHAN B3 (GND): 0.001827
OPEN: 0.005065
Full Scale: +/- 1 mA
2023-05-11T16:30:53.249Z,1683822653.249 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:30:53.250Z,1683822653.250 [DATMMP](INFO): directional_debug rx: 	 x1A6	 x10A	 x20	 x1D9	 x3290	 x4091	 x6832	 x55C3
2023-05-11T16:30:53.251Z,1683822653.251 [DATMMP](INFO): Received message type: directional_debug
2023-05-11T16:30:53.251Z,1683822653.251 [DATMMP](INFO): Handled
2023-05-11T16:30:53.500Z,1683822653.500 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:30:53.502Z,1683822653.502 [DATMMP](INFO): directional rx: 	 x1CA	 xF7	 x436	 xFEF6	 xAED	 xFEF4	 x0	 x6B8	 x3	 x1	 x27B5966	 x-43569E0
2023-05-11T16:30:53.504Z,1683822653.504 [DATMMP](INFO): Received message type: directional
2023-05-11T16:30:53.504Z,1683822653.504 [DATMMP](INFO): Handled
2023-05-11T16:30:53.752Z,1683822653.752 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:30:53.754Z,1683822653.754 [DATMMP](INFO): acstats rx: 	 x5	 x5	 x0	 x2B5	 x23	 x81	 xAB	 xB8	 xD	 xFFFF	 xA7	 x20	 xC	 x0
2023-05-11T16:30:53.754Z,1683822653.754 [DATMMP](INFO): Received message type: acstats
2023-05-11T16:30:53.754Z,1683822653.754 [DATMMP](INFO): Handled
2023-05-11T16:30:54.004Z,1683822654.004 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:30:54.005Z,1683822654.005 [DATMMP](INFO): data_rx rx: 	 x5	 x0	 x0	 x22
2023-05-11T16:30:54.006Z,1683822654.006 [DATMMP](INFO): Check CRC
2023-05-11T16:30:54.006Z,1683822654.006 [DATMMP](INFO): data rx parseDataResponse 34
2023-05-11T16:30:54.006Z,1683822654.006 [DATMMP](INFO): Got DATA: len 34
2023-05-11T16:30:54.006Z,1683822654.006 [DATMMP](INFO): Received command: set _.pressure 0.745180 atmosphere
2023-05-11T16:30:54.007Z,1683822654.007 [DATMMP](INFO): #Outgoing data=1
2023-05-11T16:30:54.007Z,1683822654.007 [DATMMP](INFO): Sending ack
2023-05-11T16:30:54.007Z,1683822654.007 [DATMMP](INFO): Received message type: data_rx
2023-05-11T16:30:54.007Z,1683822654.007 [DATMMP](INFO): Handled
2023-05-11T16:30:55.116Z,1683822655.116 [CommandExec](IMPORTANT): got command set _.pressure 0.745180 atmosphere
2023-05-11T16:31:02.828Z,1683822662.828 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:02.829Z,1683822662.829 [DATMMP](INFO): doppler rx: 	 x0
2023-05-11T16:31:02.829Z,1683822662.829 [DATMMP](INFO): Received message type: doppler
2023-05-11T16:31:02.829Z,1683822662.829 [DATMMP](INFO): Handled
2023-05-11T16:31:03.081Z,1683822663.081 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:03.082Z,1683822663.082 [DATMMP](INFO): timestamp rx: 	 x1	 x10	 x1F	 x1	 x9AF
2023-05-11T16:31:03.082Z,1683822663.082 [DATMMP](INFO): Rx dataTimestamp_ set to:1683822685.219136
2023-05-11T16:31:03.082Z,1683822663.082 [DATMMP](INFO): Rx ping set to:1683822663.081673
2023-05-11T16:31:03.083Z,1683822663.083 [DATMMP](INFO): Received message type: timestamp
2023-05-11T16:31:03.083Z,1683822663.083 [DATMMP](INFO): Handled
2023-05-11T16:31:03.333Z,1683822663.333 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:03.334Z,1683822663.334 [DATMMP](INFO): remote_header rx: 	 xF	 x4	 x5	 x22	 x0	 xA	 x5	 x0
2023-05-11T16:31:03.334Z,1683822663.334 [DATMMP](INFO): DATA Src=5, Dst=10
2023-05-11T16:31:03.334Z,1683822663.334 [DATMMP](INFO): Received message type: remote_header
2023-05-11T16:31:03.334Z,1683822663.334 [DATMMP](INFO): Handled
2023-05-11T16:31:03.837Z,1683822663.837 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:03.838Z,1683822663.838 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-11T16:31:03.838Z,1683822663.838 [DATMMP](INFO): Received message type: nav_stat
2023-05-11T16:31:03.838Z,1683822663.838 [DATMMP](INFO): Handled
2023-05-11T16:31:04.088Z,1683822664.088 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:04.090Z,1683822664.090 [DATMMP](INFO): directional_debug rx: 	 x1A1	 x102	 x20	 x1C4	 x3230	 x3FF1	 x67D2	 x72C3
2023-05-11T16:31:04.091Z,1683822664.091 [DATMMP](INFO): Received message type: directional_debug
2023-05-11T16:31:04.091Z,1683822664.091 [DATMMP](INFO): Handled
2023-05-11T16:31:04.340Z,1683822664.340 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:04.342Z,1683822664.342 [DATMMP](INFO): directional rx: 	 x1C5	 xF0	 x43B	 xFEFE	 xAF1	 xFEFD	 x0	 x6B8	 x3	 x0	 x27B5966	 x-43569E0
2023-05-11T16:31:04.344Z,1683822664.344 [DATMMP](INFO): Received message type: directional
2023-05-11T16:31:04.344Z,1683822664.344 [DATMMP](INFO): Handled
2023-05-11T16:31:04.592Z,1683822664.592 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:04.594Z,1683822664.594 [DATMMP](INFO): acstats rx: 	 x5	 x5	 x0	 x29E	 x22	 x7E	 xB2	 xBA	 xD	 xFFFF	 xA6	 x24	 xC	 x0
2023-05-11T16:31:04.594Z,1683822664.594 [DATMMP](INFO): Received message type: acstats
2023-05-11T16:31:04.594Z,1683822664.594 [DATMMP](INFO): Handled
2023-05-11T16:31:04.844Z,1683822664.844 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:04.845Z,1683822664.845 [DATMMP](INFO): data_rx rx: 	 x5	 x0	 x0	 x22
2023-05-11T16:31:04.845Z,1683822664.845 [DATMMP](INFO): Check CRC
2023-05-11T16:31:04.845Z,1683822664.845 [DATMMP](INFO): data rx parseDataResponse 34
2023-05-11T16:31:04.846Z,1683822664.846 [DATMMP](INFO): Got DATA: len 34
2023-05-11T16:31:04.846Z,1683822664.846 [DATMMP](INFO): Received command: set _.pressure 0.745180 atmosphere
2023-05-11T16:31:04.846Z,1683822664.846 [DATMMP](INFO): #Outgoing data=2
2023-05-11T16:31:04.846Z,1683822664.846 [DATMMP](INFO): Sending ack
2023-05-11T16:31:04.847Z,1683822664.847 [DATMMP](INFO): Received message type: data_rx
2023-05-11T16:31:04.847Z,1683822664.847 [DATMMP](INFO): Handled
2023-05-11T16:31:05.800Z,1683822665.800 [CommandExec](IMPORTANT): got command set _.pressure 0.745180 atmosphere
2023-05-11T16:31:13.668Z,1683822673.668 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:13.669Z,1683822673.669 [DATMMP](INFO): doppler rx: 	 x0
2023-05-11T16:31:13.669Z,1683822673.669 [DATMMP](INFO): Received message type: doppler
2023-05-11T16:31:13.669Z,1683822673.669 [DATMMP](INFO): Handled
2023-05-11T16:31:13.920Z,1683822673.920 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:13.921Z,1683822673.921 [DATMMP](INFO): timestamp rx: 	 x1	 x10	 x1F	 xC	 x3D1
2023-05-11T16:31:13.922Z,1683822673.922 [DATMMP](INFO): Rx dataTimestamp_ set to:1683822681.567296
2023-05-11T16:31:13.922Z,1683822673.922 [DATMMP](INFO): Rx ping set to:1683822673.921393
2023-05-11T16:31:13.922Z,1683822673.922 [DATMMP](INFO): Received message type: timestamp
2023-05-11T16:31:13.922Z,1683822673.922 [DATMMP](INFO): Handled
2023-05-11T16:31:14.172Z,1683822674.172 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:14.174Z,1683822674.174 [DATMMP](INFO): remote_header rx: 	 xF	 x4	 x5	 x22	 x0	 xA	 x5	 x0
2023-05-11T16:31:14.174Z,1683822674.174 [DATMMP](INFO): DATA Src=5, Dst=10
2023-05-11T16:31:14.174Z,1683822674.174 [DATMMP](INFO): Received message type: remote_header
2023-05-11T16:31:14.174Z,1683822674.174 [DATMMP](INFO): Handled
2023-05-11T16:31:14.676Z,1683822674.676 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:14.677Z,1683822674.677 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-11T16:31:14.677Z,1683822674.677 [DATMMP](INFO): Received message type: nav_stat
2023-05-11T16:31:14.677Z,1683822674.677 [DATMMP](INFO): Handled
2023-05-11T16:31:14.928Z,1683822674.928 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:14.930Z,1683822674.930 [DATMMP](INFO): directional_debug rx: 	 x199	 xF9	 x20	 x1BB	 x31F0	 x3FF1	 x6782	 x71F3
2023-05-11T16:31:14.931Z,1683822674.931 [DATMMP](INFO): Received message type: directional_debug
2023-05-11T16:31:14.931Z,1683822674.931 [DATMMP](INFO): Handled
2023-05-11T16:31:15.180Z,1683822675.180 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:15.182Z,1683822675.182 [DATMMP](INFO): directional rx: 	 x1BE	 xE9	 x443	 xFF07	 xAF7	 xFF06	 x0	 x6B5	 x3	 x1	 x27B5966	 x-43569E0
2023-05-11T16:31:15.185Z,1683822675.185 [DATMMP](INFO): Received message type: directional
2023-05-11T16:31:15.185Z,1683822675.185 [DATMMP](INFO): Handled
2023-05-11T16:31:15.432Z,1683822675.432 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:15.434Z,1683822675.434 [DATMMP](INFO): acstats rx: 	 x5	 x5	 x0	 x2D0	 x23	 x7F	 xB2	 xB2	 xD	 xFFFF	 xA6	 x21	 xC	 x0
2023-05-11T16:31:15.434Z,1683822675.434 [DATMMP](INFO): Received message type: acstats
2023-05-11T16:31:15.434Z,1683822675.434 [DATMMP](INFO): Handled
2023-05-11T16:31:15.684Z,1683822675.684 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:15.685Z,1683822675.685 [DATMMP](INFO): data_rx rx: 	 x5	 x0	 x0	 x22
2023-05-11T16:31:15.685Z,1683822675.685 [DATMMP](INFO): Check CRC
2023-05-11T16:31:15.685Z,1683822675.685 [DATMMP](INFO): data rx parseDataResponse 34
2023-05-11T16:31:15.686Z,1683822675.686 [DATMMP](INFO): Got DATA: len 34
2023-05-11T16:31:15.686Z,1683822675.686 [DATMMP](INFO): Received command: set _.pressure 0.745180 atmosphere
2023-05-11T16:31:15.686Z,1683822675.686 [DATMMP](INFO): #Outgoing data=3
2023-05-11T16:31:15.686Z,1683822675.686 [DATMMP](INFO): Sending ack
2023-05-11T16:31:15.687Z,1683822675.687 [DATMMP](INFO): Received message type: data_rx
2023-05-11T16:31:15.687Z,1683822675.687 [DATMMP](INFO): Handled
2023-05-11T16:31:16.550Z,1683822676.550 [CommandExec](IMPORTANT): got command set _.pressure 0.745180 atmosphere
2023-05-11T16:31:24.514Z,1683822684.514 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:24.516Z,1683822684.516 [DATMMP](INFO): doppler rx: 	 x0
2023-05-11T16:31:24.517Z,1683822684.517 [DATMMP](INFO): Received message type: doppler
2023-05-11T16:31:24.517Z,1683822684.517 [DATMMP](INFO): Handled
2023-05-11T16:31:24.764Z,1683822684.764 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:24.765Z,1683822684.765 [DATMMP](INFO): timestamp rx: 	 x1	 x10	 x1F	 x16	 x2505
2023-05-11T16:31:24.766Z,1683822684.766 [DATMMP](INFO): Rx dataTimestamp_ set to:1683822710.575488
2023-05-11T16:31:24.766Z,1683822684.766 [DATMMP](INFO): Rx ping set to:1683822684.765302
2023-05-11T16:31:24.767Z,1683822684.767 [DATMMP](INFO): Received message type: timestamp
2023-05-11T16:31:24.767Z,1683822684.767 [DATMMP](INFO): Handled
2023-05-11T16:31:25.016Z,1683822685.016 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:25.018Z,1683822685.018 [DATMMP](INFO): remote_header rx: 	 xF	 x4	 x5	 x22	 x0	 xA	 x5	 x0
2023-05-11T16:31:25.018Z,1683822685.018 [DATMMP](INFO): DATA Src=5, Dst=10
2023-05-11T16:31:25.018Z,1683822685.018 [DATMMP](INFO): Received message type: remote_header
2023-05-11T16:31:25.018Z,1683822685.018 [DATMMP](INFO): Handled
2023-05-11T16:31:25.521Z,1683822685.521 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:25.522Z,1683822685.522 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-11T16:31:25.522Z,1683822685.522 [DATMMP](INFO): Received message type: nav_stat
2023-05-11T16:31:25.522Z,1683822685.522 [DATMMP](INFO): Handled
2023-05-11T16:31:25.772Z,1683822685.772 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:25.774Z,1683822685.774 [DATMMP](INFO): directional_debug rx: 	 x1A5	 x104	 x20	 x1C4	 x31D0	 x4031	 x67B2	 x7313
2023-05-11T16:31:25.775Z,1683822685.775 [DATMMP](INFO): Received message type: directional_debug
2023-05-11T16:31:25.775Z,1683822685.775 [DATMMP](INFO): Handled
2023-05-11T16:31:26.024Z,1683822686.024 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:26.026Z,1683822686.026 [DATMMP](INFO): directional rx: 	 x1CA	 xF1	 x437	 xFEFC	 xAEA	 xFEFA	 x0	 x6B5	 x3	 x1	 x27B5966	 x-43569E0
2023-05-11T16:31:26.028Z,1683822686.028 [DATMMP](INFO): Received message type: directional
2023-05-11T16:31:26.028Z,1683822686.028 [DATMMP](INFO): Handled
2023-05-11T16:31:26.276Z,1683822686.276 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:26.281Z,1683822686.281 [DATMMP](INFO): acstats rx: 	 x5	 x5	 x0	 x2D0	 x23	 x80	 xB9	 xC0	 xD	 xFFFF	 xA9	 x22	 xC	 x0
2023-05-11T16:31:26.281Z,1683822686.281 [DATMMP](INFO): Received message type: acstats
2023-05-11T16:31:26.282Z,1683822686.282 [DATMMP](INFO): Handled
2023-05-11T16:31:26.531Z,1683822686.531 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:26.534Z,1683822686.534 [DATMMP](INFO): data_rx rx: 	 x5	 x0	 x0	 x22
2023-05-11T16:31:26.534Z,1683822686.534 [DATMMP](INFO): Check CRC
2023-05-11T16:31:26.535Z,1683822686.535 [DATMMP](INFO): data rx parseDataResponse 34
2023-05-11T16:31:26.536Z,1683822686.536 [DATMMP](INFO): Got DATA: len 34
2023-05-11T16:31:26.537Z,1683822686.537 [DATMMP](INFO): Received command: set _.pressure 0.745180 atmosphere
2023-05-11T16:31:26.538Z,1683822686.538 [DATMMP](INFO): #Outgoing data=4
2023-05-11T16:31:26.538Z,1683822686.538 [DATMMP](INFO): Sending ack
2023-05-11T16:31:26.539Z,1683822686.539 [DATMMP](INFO): Received message type: data_rx
2023-05-11T16:31:26.539Z,1683822686.539 [DATMMP](INFO): Handled
2023-05-11T16:31:27.466Z,1683822687.466 [CommandExec](IMPORTANT): got command set _.pressure 0.745180 atmosphere
2023-05-11T16:31:35.860Z,1683822695.860 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:35.861Z,1683822695.861 [DATMMP](INFO): doppler rx: 	 x0
2023-05-11T16:31:35.861Z,1683822695.861 [DATMMP](INFO): Received message type: doppler
2023-05-11T16:31:35.861Z,1683822695.861 [DATMMP](INFO): Handled
2023-05-11T16:31:36.004Z,1683822696.004 [SBIT](IMPORTANT): SBIT PASSED
2023-05-11T16:31:36.004Z,1683822696.004 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-05-11T16:31:36.005Z,1683822696.005 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count;

2023-05-11T16:31:36.005Z,1683822696.005 [SBIT](IMPORTANT): CBIT.gf24Offset=143 microampere;

2023-05-11T16:31:36.005Z,1683822696.005 [SBIT](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2023-05-11T16:31:36.005Z,1683822696.005 [SBIT](IMPORTANT): Express linearApproximation WetLabsUBAT.flow_rate 0.300000 liter_per_second;

2023-05-11T16:31:36.005Z,1683822696.005 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=279.582187 cubic_centimeter;

2023-05-11T16:31:36.005Z,1683822696.005 [SBIT](IMPORTANT): VerticalControl.massDefault=7.892016 millimeter;

2023-05-11T16:31:36.006Z,1683822696.006 [SBIT](IMPORTANT): WetLabsUBAT.loadAtStartup=1 bool;

2023-05-11T16:31:36.113Z,1683822696.113 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:36.114Z,1683822696.114 [DATMMP](INFO): timestamp rx: 	 x1	 x10	 x1F	 x22	 xBA1
2023-05-11T16:31:36.114Z,1683822696.114 [DATMMP](INFO): Rx dataTimestamp_ set to:1683822723.075776
2023-05-11T16:31:36.114Z,1683822696.114 [DATMMP](INFO): Rx ping set to:1683822696.113595
2023-05-11T16:31:36.115Z,1683822696.115 [DATMMP](INFO): Received message type: timestamp
2023-05-11T16:31:36.115Z,1683822696.115 [DATMMP](INFO): Handled
2023-05-11T16:31:36.364Z,1683822696.364 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:36.365Z,1683822696.365 [DATMMP](INFO): remote_header rx: 	 xF	 x4	 x5	 x23	 x0	 xA	 x5	 x0
2023-05-11T16:31:36.366Z,1683822696.366 [DATMMP](INFO): DATA Src=5, Dst=10
2023-05-11T16:31:36.366Z,1683822696.366 [DATMMP](INFO): Received message type: remote_header
2023-05-11T16:31:36.366Z,1683822696.366 [DATMMP](INFO): Handled
2023-05-11T16:31:36.421Z,1683822696.421 [MissionManager](IMPORTANT): Started mission Startup
2023-05-11T16:31:36.422Z,1683822696.422 [Startup] Running Loop=1
2023-05-11T16:31:36.422Z,1683822696.422 [Startup](DEBUG): Aggregate::initialize Startup
2023-05-11T16:31:36.422Z,1683822696.422 [Startup:A.GoToSurface] Running Loop=1
2023-05-11T16:31:36.422Z,1683822696.422 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-05-11T16:31:36.422Z,1683822696.422 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-05-11T16:31:36.423Z,1683822696.423 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-05-11T16:31:36.423Z,1683822696.423 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-05-11T16:31:36.428Z,1683822696.428 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-05-11T16:31:36.428Z,1683822696.428 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-05-11T16:31:36.429Z,1683822696.429 [Startup:StartupSatComms] Running Loop=1
2023-05-11T16:31:36.430Z,1683822696.430 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2023-05-11T16:31:36.430Z,1683822696.430 [Startup:StartupSatComms:A] Running Loop=1
2023-05-11T16:31:36.809Z,1683822696.809 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2023-05-11T16:31:36.868Z,1683822696.868 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:36.869Z,1683822696.869 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-11T16:31:36.869Z,1683822696.869 [DATMMP](INFO): Received message type: nav_stat
2023-05-11T16:31:36.870Z,1683822696.870 [DATMMP](INFO): Handled
2023-05-11T16:31:37.120Z,1683822697.120 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:37.122Z,1683822697.122 [DATMMP](INFO): directional_debug rx: 	 x19C	 xF7	 x20	 x1C6	 x31B0	 x3FF1	 x67C2	 x71B3
2023-05-11T16:31:37.123Z,1683822697.123 [DATMMP](INFO): Received message type: directional_debug
2023-05-11T16:31:37.123Z,1683822697.123 [DATMMP](INFO): Handled
2023-05-11T16:31:37.373Z,1683822697.373 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:37.374Z,1683822697.374 [DATMMP](INFO): directional rx: 	 x1C1	 xE8	 x440	 xFF09	 xAF4	 xFF08	 x0	 x6B5	 x3	 x0	 x27B5966	 x-43569E0
2023-05-11T16:31:37.376Z,1683822697.376 [DATMMP](INFO): Received message type: directional
2023-05-11T16:31:37.376Z,1683822697.376 [DATMMP](INFO): Handled
2023-05-11T16:31:37.624Z,1683822697.624 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:37.626Z,1683822697.626 [DATMMP](INFO): acstats rx: 	 x5	 x5	 x0	 x2D0	 x22	 x7D	 xBD	 xBD	 xD	 xFFFF	 xA9	 x21	 xC	 x0
2023-05-11T16:31:37.626Z,1683822697.626 [DATMMP](INFO): Received message type: acstats
2023-05-11T16:31:37.627Z,1683822697.627 [DATMMP](INFO): Handled
2023-05-11T16:31:37.876Z,1683822697.876 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:37.877Z,1683822697.877 [DATMMP](INFO): data_rx rx: 	 x5	 x0	 x0	 x23
2023-05-11T16:31:37.877Z,1683822697.877 [DATMMP](INFO): Check CRC
2023-05-11T16:31:37.878Z,1683822697.878 [DATMMP](INFO): data rx parseDataResponse 35
2023-05-11T16:31:37.878Z,1683822697.878 [DATMMP](INFO): Got DATA: len 35
2023-05-11T16:31:37.878Z,1683822697.878 [DATMMP](INFO): Received command: set _.temperature 24.259546 celsius
2023-05-11T16:31:37.878Z,1683822697.878 [DATMMP](INFO): #Outgoing data=5
2023-05-11T16:31:37.878Z,1683822697.878 [DATMMP](INFO): Sending ack
2023-05-11T16:31:37.879Z,1683822697.879 [DATMMP](INFO): Received message type: data_rx
2023-05-11T16:31:37.879Z,1683822697.879 [DATMMP](INFO): Handled
2023-05-11T16:31:39.041Z,1683822699.041 [CommandExec](IMPORTANT): got command set _.temperature 24.259546 celsius
2023-05-11T16:31:46.705Z,1683822706.705 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:46.705Z,1683822706.705 [DATMMP](INFO): doppler rx: 	 x0
2023-05-11T16:31:46.705Z,1683822706.705 [DATMMP](INFO): Received message type: doppler
2023-05-11T16:31:46.706Z,1683822706.706 [DATMMP](INFO): Handled
2023-05-11T16:31:46.956Z,1683822706.956 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:46.957Z,1683822706.957 [DATMMP](INFO): timestamp rx: 	 x1	 x10	 x1F	 x2D	 x5C3
2023-05-11T16:31:46.958Z,1683822706.958 [DATMMP](INFO): Rx dataTimestamp_ set to:1683822719.423936
2023-05-11T16:31:46.958Z,1683822706.958 [DATMMP](INFO): Rx ping set to:1683822706.957565
2023-05-11T16:31:46.959Z,1683822706.959 [DATMMP](INFO): Received message type: timestamp
2023-05-11T16:31:46.959Z,1683822706.959 [DATMMP](INFO): Handled
2023-05-11T16:31:47.210Z,1683822707.210 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:47.211Z,1683822707.211 [DATMMP](INFO): remote_header rx: 	 xF	 x4	 x5	 x23	 x0	 xA	 x5	 x0
2023-05-11T16:31:47.211Z,1683822707.211 [DATMMP](INFO): DATA Src=5, Dst=10
2023-05-11T16:31:47.211Z,1683822707.211 [DATMMP](INFO): Received message type: remote_header
2023-05-11T16:31:47.212Z,1683822707.212 [DATMMP](INFO): Handled
2023-05-11T16:31:47.712Z,1683822707.712 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:47.713Z,1683822707.713 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-11T16:31:47.713Z,1683822707.713 [DATMMP](INFO): Received message type: nav_stat
2023-05-11T16:31:47.714Z,1683822707.714 [DATMMP](INFO): Handled
2023-05-11T16:31:47.964Z,1683822707.964 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:47.966Z,1683822707.966 [DATMMP](INFO): directional_debug rx: 	 x196	 xF2	 x1F	 x1C0	 x31E0	 x3FF1	 x6772	 x7273
2023-05-11T16:31:47.967Z,1683822707.967 [DATMMP](INFO): Received message type: directional_debug
2023-05-11T16:31:47.967Z,1683822707.967 [DATMMP](INFO): Handled
2023-05-11T16:31:48.216Z,1683822708.216 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:48.218Z,1683822708.218 [DATMMP](INFO): directional rx: 	 x1BB	 xE4	 x446	 xFF0E	 xAFC	 xFF0D	 x0	 x6B7	 x2	 x1	 x27B5966	 x-43569E0
2023-05-11T16:31:48.220Z,1683822708.220 [DATMMP](INFO): Received message type: directional
2023-05-11T16:31:48.220Z,1683822708.220 [DATMMP](INFO): Handled
2023-05-11T16:31:48.468Z,1683822708.468 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:48.470Z,1683822708.470 [DATMMP](INFO): acstats rx: 	 x5	 x5	 x0	 x2D0	 x23	 x7E	 xC6	 xC9	 xD	 xFFFF	 xAA	 x23	 xC	 x0
2023-05-11T16:31:48.470Z,1683822708.470 [DATMMP](INFO): Received message type: acstats
2023-05-11T16:31:48.471Z,1683822708.471 [DATMMP](INFO): Handled
2023-05-11T16:31:48.720Z,1683822708.720 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:48.721Z,1683822708.721 [DATMMP](INFO): data_rx rx: 	 x5	 x0	 x0	 x23
2023-05-11T16:31:48.721Z,1683822708.721 [DATMMP](INFO): Check CRC
2023-05-11T16:31:48.722Z,1683822708.722 [DATMMP](INFO): data rx parseDataResponse 35
2023-05-11T16:31:48.722Z,1683822708.722 [DATMMP](INFO): Got DATA: len 35
2023-05-11T16:31:48.722Z,1683822708.722 [DATMMP](INFO): Received command: set _.temperature 24.259546 celsius
2023-05-11T16:31:48.722Z,1683822708.722 [DATMMP](INFO): #Outgoing data=6
2023-05-11T16:31:48.722Z,1683822708.722 [DATMMP](INFO): Sending ack
2023-05-11T16:31:48.723Z,1683822708.723 [DATMMP](INFO): Received message type: data_rx
2023-05-11T16:31:48.723Z,1683822708.723 [DATMMP](INFO): Handled
2023-05-11T16:31:50.263Z,1683822710.263 [CommandExec](IMPORTANT): got command set _.temperature 24.259546 celsius
2023-05-11T16:31:57.540Z,1683822717.540 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:57.541Z,1683822717.541 [DATMMP](INFO): doppler rx: 	 x1
2023-05-11T16:31:57.541Z,1683822717.541 [DATMMP](INFO): Received message type: doppler
2023-05-11T16:31:57.542Z,1683822717.542 [DATMMP](INFO): Handled
2023-05-11T16:31:57.793Z,1683822717.793 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:57.794Z,1683822717.794 [DATMMP](INFO): timestamp rx: 	 x1	 x10	 x1F	 x37	 x26F7
2023-05-11T16:31:57.794Z,1683822717.794 [DATMMP](INFO): Rx dataTimestamp_ set to:1683822748.432128
2023-05-11T16:31:57.794Z,1683822717.794 [DATMMP](INFO): Rx ping set to:1683822717.793591
2023-05-11T16:31:57.795Z,1683822717.795 [DATMMP](INFO): Received message type: timestamp
2023-05-11T16:31:57.795Z,1683822717.795 [DATMMP](INFO): Handled
2023-05-11T16:31:58.045Z,1683822718.045 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:58.046Z,1683822718.046 [DATMMP](INFO): remote_header rx: 	 xF	 x4	 x5	 x23	 x0	 xA	 x5	 x0
2023-05-11T16:31:58.047Z,1683822718.047 [DATMMP](INFO): DATA Src=5, Dst=10
2023-05-11T16:31:58.047Z,1683822718.047 [DATMMP](INFO): Received message type: remote_header
2023-05-11T16:31:58.047Z,1683822718.047 [DATMMP](INFO): Handled
2023-05-11T16:31:58.549Z,1683822718.549 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:58.551Z,1683822718.551 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-11T16:31:58.552Z,1683822718.552 [DATMMP](INFO): Received message type: nav_stat
2023-05-11T16:31:58.552Z,1683822718.552 [DATMMP](INFO): Handled
2023-05-11T16:31:58.615Z,1683822718.615 [CommandExec](IMPORTANT): got command maintain sensor NAL9602.latitude_fix 36.8 degree
2023-05-11T16:31:58.644Z,1683822718.644 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.latitude_fix" handled in the control thread.
2023-05-11T16:31:58.644Z,1683822718.644 [CommandExec](IMPORTANT): got command maintain sensor NAL9602.longitude_fix -121.9 degree
2023-05-11T16:31:58.648Z,1683822718.648 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.longitude_fix" handled in the control thread.
2023-05-11T16:31:58.649Z,1683822718.649 [CommandExec](IMPORTANT): got command maintain sensor Depth_Keller.depth 0.8 meter
2023-05-11T16:31:58.652Z,1683822718.652 [ComponentRegistry](DEBUG): SyncComponent "Maintain_Depth_Keller.depth" handled in the control thread.
2023-05-11T16:31:58.652Z,1683822718.652 [CommandExec](IMPORTANT): got command report touch DATMMP.acoustic_contact_range
2023-05-11T16:31:58.655Z,1683822718.655 [CommandExec](IMPORTANT): got command report touch acoustic_contact_range
2023-05-11T16:31:58.762Z,1683822718.762 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,NAL9602,Power24vConverter,RDI_Pathfinder,PAR_Licor,Depth_Keller,PAR_Licor,Maintain_NAL9602.latitude_fix,Maintain_NAL9602.longitude_fix,Maintain_Depth_Keller.depth,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2023-05-11T16:31:58.800Z,1683822718.800 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:58.802Z,1683822718.802 [DATMMP](INFO): directional_debug rx: 	 x1AC	 x107	 x1F	 x1CA	 x31B0	 x3F91	 x6792	 x7983
2023-05-11T16:31:58.803Z,1683822718.803 [DATMMP](INFO): Received message type: directional_debug
2023-05-11T16:31:58.803Z,1683822718.803 [DATMMP](INFO): Handled
2023-05-11T16:31:59.054Z,1683822719.054 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:59.056Z,1683822719.056 [DATMMP](INFO): directional rx: 	 x1D1	 xF4	 x430	 xFEF9	 xAE8	 xFEF8	 x0	 x6B9	 x3	 x1	 x27B5966	 x-43569E0
2023-05-11T16:31:59.058Z,1683822719.058 [DATMMP](INFO): Received message type: directional
2023-05-11T16:31:59.058Z,1683822719.058 [DATMMP](INFO): Handled
2023-05-11T16:31:59.119Z,1683822719.119 [Startup:StartupSatComms:A] Stopped
2023-05-11T16:31:59.119Z,1683822719.119 [Startup:StartupSatComms:B] Running Loop=1
2023-05-11T16:31:59.304Z,1683822719.304 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:59.306Z,1683822719.306 [DATMMP](INFO): acstats rx: 	 x5	 x5	 x1	 x1CB	 x22	 x7F	 xAE	 xAC	 xD	 xFFFF	 xA8	 x1D	 xC	 x0
2023-05-11T16:31:59.306Z,1683822719.306 [DATMMP](INFO): Received message type: acstats
2023-05-11T16:31:59.306Z,1683822719.306 [DATMMP](INFO): Handled
2023-05-11T16:31:59.307Z,1683822719.307 [DATMMP](INFO): *** SENDING_FILL_BUFFER ***
2023-05-11T16:31:59.309Z,1683822719.309 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA
2023-05-11T16:31:59.473Z,1683822719.473 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-05-11T16:31:59.473Z,1683822719.473 [Startup:StartupSatComms:B] Stopped
2023-05-11T16:31:59.473Z,1683822719.473 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2023-05-11T16:31:59.473Z,1683822719.473 [Startup:StartupSatComms] Stopped
2023-05-11T16:31:59.473Z,1683822719.473 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2023-05-11T16:31:59.474Z,1683822719.474 [Startup](INFO): Completed Startup
2023-05-11T16:31:59.474Z,1683822719.474 [MissionManager](INFO): Startup is completed.
2023-05-11T16:31:59.474Z,1683822719.474 [MissionManager](INFO): Uninitializing Mission Startup
2023-05-11T16:31:59.474Z,1683822719.474 [Startup] Stopped
2023-05-11T16:31:59.474Z,1683822719.474 [Startup](DEBUG): Aggregate::uninitialize Startup
2023-05-11T16:31:59.474Z,1683822719.474 [Startup:A.GoToSurface] Stopped
2023-05-11T16:31:59.474Z,1683822719.474 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-05-11T16:31:59.564Z,1683822719.564 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:31:59.565Z,1683822719.565 [DATMMP](INFO): data_rx rx: 	 x5	 x0	 x0	 x23
2023-05-11T16:31:59.565Z,1683822719.565 [DATMMP](INFO): Check CRC
2023-05-11T16:31:59.566Z,1683822719.566 [DATMMP](INFO): data rx parseDataResponse 35
2023-05-11T16:31:59.566Z,1683822719.566 [DATMMP](INFO): Got DATA: len 35
2023-05-11T16:31:59.566Z,1683822719.566 [DATMMP](INFO): Received command: set _.temperature 24.259546 celsius
2023-05-11T16:31:59.566Z,1683822719.566 [DATMMP](INFO): #Outgoing data=6
2023-05-11T16:31:59.567Z,1683822719.567 [DATMMP](INFO): Sending ack
2023-05-11T16:31:59.567Z,1683822719.567 [DATMMP](INFO): Received message type: data_rx
2023-05-11T16:31:59.567Z,1683822719.567 [DATMMP](INFO): Handled
2023-05-11T16:31:59.567Z,1683822719.567 [DATMMP](INFO): *** SENDING_NAV_DATA ***
2023-05-11T16:31:59.816Z,1683822719.816 [DATMMP](INFO): GSXN notify for xid: 15
2023-05-11T16:31:59.817Z,1683822719.817 [DATMMP](INFO): depth rx: 	 x1	 x1	 x4	 x0
2023-05-11T16:31:59.817Z,1683822719.817 [DATMMP](INFO): Received message type: depth
2023-05-11T16:31:59.818Z,1683822719.818 [DATMMP](INFO): Match for : depth
2023-05-11T16:31:59.818Z,1683822719.818 [DATMMP](INFO): ACK
2023-05-11T16:31:59.818Z,1683822719.818 [DATMMP](INFO): *** SENDING_NAV_DATA ***
2023-05-11T16:31:59.992Z,1683822719.992 [MissionManager](IMPORTANT): Started mission Default
2023-05-11T16:31:59.992Z,1683822719.992 [Default] Running Loop=1
2023-05-11T16:31:59.992Z,1683822719.992 [Default](DEBUG): Aggregate::initialize Default
2023-05-11T16:31:59.992Z,1683822719.992 [Default:B.GoToSurface] Running Loop=1
2023-05-11T16:31:59.993Z,1683822719.993 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-05-11T16:31:59.993Z,1683822719.993 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-05-11T16:31:59.993Z,1683822719.993 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-05-11T16:31:59.993Z,1683822719.993 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-05-11T16:31:59.994Z,1683822719.994 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-05-11T16:31:59.994Z,1683822719.994 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-05-11T16:31:59.994Z,1683822719.994 [Default:A.Wait] Running Loop=1
2023-05-11T16:31:59.994Z,1683822719.994 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-05-11T16:32:00.068Z,1683822720.068 [DATMMP](INFO): GSXN notify for xid: 16
2023-05-11T16:32:00.069Z,1683822720.069 [DATMMP](INFO): lat rx: 	 x2318600	 x6	 x1	 x0
2023-05-11T16:32:00.070Z,1683822720.070 [DATMMP](INFO): Received message type: lat
2023-05-11T16:32:00.070Z,1683822720.070 [DATMMP](INFO): Match for : lat
2023-05-11T16:32:00.070Z,1683822720.070 [DATMMP](INFO): ACK
2023-05-11T16:32:00.070Z,1683822720.070 [DATMMP](INFO): *** SENDING_NAV_DATA ***
2023-05-11T16:32:00.320Z,1683822720.320 [DATMMP](INFO): GSXN notify for xid: 17
2023-05-11T16:32:00.404Z,1683822720.404 [DATMMP](INFO): lon rx: 	 x0	 x6	 x1	 x0
2023-05-11T16:32:00.404Z,1683822720.404 [DATMMP](INFO): Received message type: lon
2023-05-11T16:32:00.405Z,1683822720.405 [DATMMP](INFO): Match for : lon
2023-05-11T16:32:00.405Z,1683822720.405 [DATMMP](INFO): ACK
2023-05-11T16:32:00.405Z,1683822720.405 [DATMMP](INFO): *** SENDING_NAV_DATA ***
2023-05-11T16:32:00.405Z,1683822720.405 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT
2023-05-11T16:32:00.572Z,1683822720.572 [DATMMP](INFO): *** SENDING_TRANSMIT ***
2023-05-11T16:32:00.573Z,1683822720.573 [DATMMP](INFO): Tx to 5 len 4 xid 18
2023-05-11T16:32:00.573Z,1683822720.573 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-11T16:32:00.573Z,1683822720.573 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-11T16:32:00.824Z,1683822720.824 [DATMMP](INFO): GSXN notify for xid: 18
2023-05-11T16:32:00.825Z,1683822720.825 [DATMMP](INFO): cmd_result rx: 	 x1	 x7	 x0	 x1
2023-05-11T16:32:00.825Z,1683822720.825 [DATMMP](DEBUG): In rxCmdResult, sent ack so set commsState_ = SENDING_VERIFIED
2023-05-11T16:32:00.826Z,1683822720.826 [DATMMP](DEBUG): Command complete send
2023-05-11T16:32:00.826Z,1683822720.826 [DATMMP](ERROR): 1:COMPLETE
2023-05-11T16:32:00.826Z,1683822720.826 [DATMMP](INFO): Received message type: cmd_result
2023-05-11T16:32:00.826Z,1683822720.826 [DATMMP](INFO): Handled
2023-05-11T16:32:00.826Z,1683822720.826 [DATMMP](INFO): *** SENDING_VERIFIED ***
2023-05-11T16:32:00.827Z,1683822720.827 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2023-05-11T16:32:01.076Z,1683822721.076 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:01.077Z,1683822721.077 [DATMMP](INFO): timestamp rx: 	 x0	 x10	 x1F	 x3B	 x1A34
2023-05-11T16:32:01.078Z,1683822721.078 [DATMMP](INFO): Received message type: timestamp
2023-05-11T16:32:01.078Z,1683822721.078 [DATMMP](INFO): Handled
2023-05-11T16:32:01.287Z,1683822721.287 [CommandExec](IMPORTANT): got command set _.temperature 24.259546 celsius
2023-05-11T16:32:01.328Z,1683822721.328 [DATMMP](INFO): *** SENDING_FILL_BUFFER ***
2023-05-11T16:32:01.328Z,1683822721.328 [DATMMP](ERROR): Waiting for previous to be ack'd
2023-05-11T16:32:01.329Z,1683822721.329 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA
2023-05-11T16:32:01.580Z,1683822721.580 [DATMMP](INFO): *** SENDING_NAV_DATA ***
2023-05-11T16:32:01.580Z,1683822721.580 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT
2023-05-11T16:32:01.832Z,1683822721.832 [DATMMP](INFO): *** SENDING_TRANSMIT ***
2023-05-11T16:32:01.832Z,1683822721.832 [DATMMP](INFO): Tx to 5 len 4 xid 19
2023-05-11T16:32:01.833Z,1683822721.833 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-11T16:32:01.833Z,1683822721.833 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-11T16:32:02.084Z,1683822722.084 [DATMMP](INFO): GSXN notify for xid: 19
2023-05-11T16:32:02.085Z,1683822722.085 [DATMMP](INFO): cmd_result rx: 	 x1	 x7	 x0	 x1
2023-05-11T16:32:02.085Z,1683822722.085 [DATMMP](DEBUG): In rxCmdResult, sent ack so set commsState_ = SENDING_VERIFIED
2023-05-11T16:32:02.086Z,1683822722.086 [DATMMP](DEBUG): Command complete send
2023-05-11T16:32:02.086Z,1683822722.086 [DATMMP](ERROR): 1:COMPLETE
2023-05-11T16:32:02.086Z,1683822722.086 [DATMMP](INFO): Received message type: cmd_result
2023-05-11T16:32:02.086Z,1683822722.086 [DATMMP](INFO): Handled
2023-05-11T16:32:02.086Z,1683822722.086 [DATMMP](INFO): *** SENDING_VERIFIED ***
2023-05-11T16:32:02.086Z,1683822722.086 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2023-05-11T16:32:02.336Z,1683822722.336 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:02.337Z,1683822722.337 [DATMMP](INFO): timestamp rx: 	 x0	 x10	 x20	 x0	 x23F7
2023-05-11T16:32:02.338Z,1683822722.338 [DATMMP](INFO): Received message type: timestamp
2023-05-11T16:32:02.338Z,1683822722.338 [DATMMP](INFO): Handled
2023-05-11T16:32:02.338Z,1683822722.338 [DATMMP](INFO): *** SENDING_FILL_BUFFER ***
2023-05-11T16:32:02.338Z,1683822722.338 [DATMMP](ERROR): Waiting for previous to be ack'd
2023-05-11T16:32:02.338Z,1683822722.338 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA
2023-05-11T16:32:02.588Z,1683822722.588 [DATMMP](INFO): *** SENDING_NAV_DATA ***
2023-05-11T16:32:02.588Z,1683822722.588 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT
2023-05-11T16:32:02.840Z,1683822722.840 [DATMMP](INFO): *** SENDING_TRANSMIT ***
2023-05-11T16:32:02.841Z,1683822722.841 [DATMMP](INFO): Tx to 5 len 4 xid 20
2023-05-11T16:32:02.841Z,1683822722.841 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-11T16:32:02.841Z,1683822722.841 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-11T16:32:03.093Z,1683822723.093 [DATMMP](INFO): GSXN notify for xid: 20
2023-05-11T16:32:03.094Z,1683822723.094 [DATMMP](INFO): cmd_result rx: 	 x1	 x7	 x0	 x1
2023-05-11T16:32:03.094Z,1683822723.094 [DATMMP](DEBUG): In rxCmdResult, sent ack so set commsState_ = SENDING_VERIFIED
2023-05-11T16:32:03.094Z,1683822723.094 [DATMMP](DEBUG): Command complete send
2023-05-11T16:32:03.094Z,1683822723.094 [DATMMP](ERROR): 1:COMPLETE
2023-05-11T16:32:03.094Z,1683822723.094 [DATMMP](INFO): Received message type: cmd_result
2023-05-11T16:32:03.094Z,1683822723.094 [DATMMP](INFO): Handled
2023-05-11T16:32:03.344Z,1683822723.344 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:03.345Z,1683822723.345 [DATMMP](INFO): timestamp rx: 	 x0	 x10	 x20	 x1	 x23F7
2023-05-11T16:32:03.345Z,1683822723.345 [DATMMP](INFO): Received message type: timestamp
2023-05-11T16:32:03.346Z,1683822723.346 [DATMMP](INFO): Handled
2023-05-11T16:32:03.346Z,1683822723.346 [DATMMP](INFO): *** SENDING_VERIFIED ***
2023-05-11T16:32:03.346Z,1683822723.346 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2023-05-11T16:32:03.596Z,1683822723.596 [DATMMP](INFO): *** SENDING_FILL_BUFFER ***
2023-05-11T16:32:03.596Z,1683822723.596 [DATMMP](ERROR): Waiting for previous to be ack'd
2023-05-11T16:32:03.597Z,1683822723.597 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA
2023-05-11T16:32:03.848Z,1683822723.848 [DATMMP](INFO): *** SENDING_NAV_DATA ***
2023-05-11T16:32:03.848Z,1683822723.848 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT
2023-05-11T16:32:04.100Z,1683822724.100 [DATMMP](INFO): *** SENDING_TRANSMIT ***
2023-05-11T16:32:04.101Z,1683822724.101 [DATMMP](INFO): Tx to 5 len 4 xid 21
2023-05-11T16:32:04.101Z,1683822724.101 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-11T16:32:04.101Z,1683822724.101 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-11T16:32:04.352Z,1683822724.352 [DATMMP](INFO): GSXN notify for xid: 21
2023-05-11T16:32:04.353Z,1683822724.353 [DATMMP](INFO): cmd_result rx: 	 x1	 x7	 x0	 x1
2023-05-11T16:32:04.353Z,1683822724.353 [DATMMP](DEBUG): In rxCmdResult, sent ack so set commsState_ = SENDING_VERIFIED
2023-05-11T16:32:04.353Z,1683822724.353 [DATMMP](DEBUG): Command complete send
2023-05-11T16:32:04.354Z,1683822724.354 [DATMMP](ERROR): 1:COMPLETE
2023-05-11T16:32:04.354Z,1683822724.354 [DATMMP](INFO): Received message type: cmd_result
2023-05-11T16:32:04.354Z,1683822724.354 [DATMMP](INFO): Handled
2023-05-11T16:32:04.354Z,1683822724.354 [DATMMP](INFO): *** SENDING_VERIFIED ***
2023-05-11T16:32:04.354Z,1683822724.354 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2023-05-11T16:32:04.604Z,1683822724.604 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:04.605Z,1683822724.605 [DATMMP](INFO): timestamp rx: 	 x0	 x10	 x20	 x3	 x6AA
2023-05-11T16:32:04.605Z,1683822724.605 [DATMMP](INFO): Received message type: timestamp
2023-05-11T16:32:04.606Z,1683822724.606 [DATMMP](INFO): Handled
2023-05-11T16:32:04.606Z,1683822724.606 [DATMMP](INFO): *** SENDING_FILL_BUFFER ***
2023-05-11T16:32:04.606Z,1683822724.606 [DATMMP](ERROR): Waiting for previous to be ack'd
2023-05-11T16:32:04.606Z,1683822724.606 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA
2023-05-11T16:32:04.856Z,1683822724.856 [DATMMP](INFO): *** SENDING_NAV_DATA ***
2023-05-11T16:32:04.856Z,1683822724.856 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT
2023-05-11T16:32:05.108Z,1683822725.108 [DATMMP](INFO): *** SENDING_TRANSMIT ***
2023-05-11T16:32:05.109Z,1683822725.109 [DATMMP](INFO): Tx to 5 len 4 xid 22
2023-05-11T16:32:05.109Z,1683822725.109 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-11T16:32:05.109Z,1683822725.109 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-11T16:32:05.360Z,1683822725.360 [DATMMP](INFO): GSXN notify for xid: 22
2023-05-11T16:32:05.361Z,1683822725.361 [DATMMP](INFO): cmd_result rx: 	 x1	 x7	 x0	 x1
2023-05-11T16:32:05.361Z,1683822725.361 [DATMMP](DEBUG): In rxCmdResult, sent ack so set commsState_ = SENDING_VERIFIED
2023-05-11T16:32:05.361Z,1683822725.361 [DATMMP](DEBUG): Command complete send
2023-05-11T16:32:05.362Z,1683822725.362 [DATMMP](ERROR): 1:COMPLETE
2023-05-11T16:32:05.362Z,1683822725.362 [DATMMP](INFO): Received message type: cmd_result
2023-05-11T16:32:05.362Z,1683822725.362 [DATMMP](INFO): Handled
2023-05-11T16:32:05.362Z,1683822725.362 [DATMMP](INFO): *** SENDING_VERIFIED ***
2023-05-11T16:32:05.362Z,1683822725.362 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2023-05-11T16:32:05.612Z,1683822725.612 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:05.613Z,1683822725.613 [DATMMP](INFO): timestamp rx: 	 x0	 x10	 x20	 x4	 x6AA
2023-05-11T16:32:05.614Z,1683822725.614 [DATMMP](INFO): Received message type: timestamp
2023-05-11T16:32:05.614Z,1683822725.614 [DATMMP](INFO): Handled
2023-05-11T16:32:05.614Z,1683822725.614 [DATMMP](INFO): *** SENDING_FILL_BUFFER ***
2023-05-11T16:32:05.614Z,1683822725.614 [DATMMP](ERROR): Waiting for previous to be ack'd
2023-05-11T16:32:05.614Z,1683822725.614 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA
2023-05-11T16:32:05.864Z,1683822725.864 [DATMMP](INFO): *** SENDING_NAV_DATA ***
2023-05-11T16:32:05.864Z,1683822725.864 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT
2023-05-11T16:32:06.116Z,1683822726.116 [DATMMP](INFO): *** SENDING_TRANSMIT ***
2023-05-11T16:32:06.117Z,1683822726.117 [DATMMP](INFO): Tx to 5 len 4 xid 23
2023-05-11T16:32:06.117Z,1683822726.117 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-11T16:32:06.117Z,1683822726.117 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-11T16:32:06.368Z,1683822726.368 [DATMMP](INFO): GSXN notify for xid: 23
2023-05-11T16:32:06.369Z,1683822726.369 [DATMMP](INFO): cmd_result rx: 	 x1	 x7	 x0	 x1
2023-05-11T16:32:06.369Z,1683822726.369 [DATMMP](DEBUG): In rxCmdResult, sent ack so set commsState_ = SENDING_VERIFIED
2023-05-11T16:32:06.370Z,1683822726.370 [DATMMP](DEBUG): Command complete send
2023-05-11T16:32:06.370Z,1683822726.370 [DATMMP](ERROR): 1:COMPLETE
2023-05-11T16:32:06.370Z,1683822726.370 [DATMMP](INFO): Received message type: cmd_result
2023-05-11T16:32:06.370Z,1683822726.370 [DATMMP](INFO): Handled
2023-05-11T16:32:06.370Z,1683822726.370 [DATMMP](INFO): *** SENDING_VERIFIED ***
2023-05-11T16:32:06.370Z,1683822726.370 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2023-05-11T16:32:06.620Z,1683822726.620 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:06.621Z,1683822726.621 [DATMMP](INFO): timestamp rx: 	 x0	 x10	 x20	 x5	 x6AA
2023-05-11T16:32:06.621Z,1683822726.621 [DATMMP](INFO): Received message type: timestamp
2023-05-11T16:32:06.622Z,1683822726.622 [DATMMP](INFO): Handled
2023-05-11T16:32:06.622Z,1683822726.622 [DATMMP](INFO): *** SENDING_FILL_BUFFER ***
2023-05-11T16:32:06.622Z,1683822726.622 [DATMMP](ERROR): Waiting for previous to be ack'd
2023-05-11T16:32:06.622Z,1683822726.622 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA
2023-05-11T16:32:06.872Z,1683822726.872 [DATMMP](INFO): *** SENDING_NAV_DATA ***
2023-05-11T16:32:06.872Z,1683822726.872 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT
2023-05-11T16:32:07.124Z,1683822727.124 [DATMMP](INFO): *** SENDING_TRANSMIT ***
2023-05-11T16:32:07.125Z,1683822727.125 [DATMMP](INFO): Tx to 5 len 4 xid 24
2023-05-11T16:32:07.125Z,1683822727.125 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-11T16:32:07.125Z,1683822727.125 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-11T16:32:07.376Z,1683822727.376 [DATMMP](INFO): GSXN notify for xid: 24
2023-05-11T16:32:07.377Z,1683822727.377 [DATMMP](INFO): cmd_result rx: 	 x1	 x7	 x0	 x1
2023-05-11T16:32:07.377Z,1683822727.377 [DATMMP](DEBUG): In rxCmdResult, sent ack so set commsState_ = SENDING_VERIFIED
2023-05-11T16:32:07.377Z,1683822727.377 [DATMMP](DEBUG): Command complete send
2023-05-11T16:32:07.378Z,1683822727.378 [DATMMP](ERROR): 1:COMPLETE
2023-05-11T16:32:07.378Z,1683822727.378 [DATMMP](INFO): Received message type: cmd_result
2023-05-11T16:32:07.378Z,1683822727.378 [DATMMP](INFO): Handled
2023-05-11T16:32:07.378Z,1683822727.378 [DATMMP](INFO): *** SENDING_VERIFIED ***
2023-05-11T16:32:07.378Z,1683822727.378 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2023-05-11T16:32:07.628Z,1683822727.628 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:07.629Z,1683822727.629 [DATMMP](INFO): timestamp rx: 	 x0	 x10	 x20	 x6	 x89E
2023-05-11T16:32:07.629Z,1683822727.629 [DATMMP](INFO): Received message type: timestamp
2023-05-11T16:32:07.630Z,1683822727.630 [DATMMP](INFO): Handled
2023-05-11T16:32:13.221Z,1683822733.221 [Default:A.Wait](INFO): Done Waiting.
2023-05-11T16:32:13.221Z,1683822733.221 [Default:A.Wait] Stopped
2023-05-11T16:32:13.221Z,1683822733.221 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-05-11T16:32:13.617Z,1683822733.617 [Default:CheckIn] Running Loop=1
2023-05-11T16:32:13.617Z,1683822733.617 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-11T16:32:13.617Z,1683822733.617 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-11T16:32:14.028Z,1683822734.028 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-05-11T16:32:16.201Z,1683822736.201 [CommandExec](IMPORTANT): got command get depth
2023-05-11T16:32:16.201Z,1683822736.201 [CommandExec](IMPORTANT): depth 0.800000 m
2023-05-11T16:32:19.162Z,1683822739.162 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004997
2023-05-11T16:32:19.736Z,1683822739.736 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:19.737Z,1683822739.737 [DATMMP](INFO): doppler rx: 	 x0
2023-05-11T16:32:19.737Z,1683822739.737 [DATMMP](INFO): Received message type: doppler
2023-05-11T16:32:19.737Z,1683822739.737 [DATMMP](INFO): Handled
2023-05-11T16:32:19.988Z,1683822739.988 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:19.989Z,1683822739.989 [DATMMP](INFO): timestamp rx: 	 x1	 x10	 x20	 x12	 x7B5
2023-05-11T16:32:19.990Z,1683822739.990 [DATMMP](INFO): Rx dataTimestamp_ set to:1683822757.280576
2023-05-11T16:32:19.990Z,1683822739.990 [DATMMP](INFO): Rx ping set to:1683822739.989228
2023-05-11T16:32:19.990Z,1683822739.990 [DATMMP](INFO): Received message type: timestamp
2023-05-11T16:32:19.990Z,1683822739.990 [DATMMP](INFO): Handled
2023-05-11T16:32:20.242Z,1683822740.242 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:20.257Z,1683822740.257 [DATMMP](INFO): remote_header rx: 	 xF	 x4	 x5	 x20	 x0	 xA	 x5	 x0
2023-05-11T16:32:20.257Z,1683822740.257 [DATMMP](INFO): DATA Src=5, Dst=10
2023-05-11T16:32:20.257Z,1683822740.257 [DATMMP](INFO): Received message type: remote_header
2023-05-11T16:32:20.257Z,1683822740.257 [DATMMP](INFO): Handled
2023-05-11T16:32:20.744Z,1683822740.744 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:20.745Z,1683822740.745 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-11T16:32:20.745Z,1683822740.745 [DATMMP](INFO): Received message type: nav_stat
2023-05-11T16:32:20.745Z,1683822740.745 [DATMMP](INFO): Handled
2023-05-11T16:32:20.996Z,1683822740.996 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:20.998Z,1683822740.998 [DATMMP](INFO): directional_debug rx: 	 x192	 xF3	 x20	 x1E0	 x31D0	 x3A31	 x6772	 x4863
2023-05-11T16:32:20.999Z,1683822740.999 [DATMMP](INFO): Received message type: directional_debug
2023-05-11T16:32:20.999Z,1683822740.999 [DATMMP](INFO): Handled
2023-05-11T16:32:21.248Z,1683822741.248 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:21.250Z,1683822741.250 [DATMMP](INFO): directional rx: 	 x1B6	 xE5	 x44A	 xFF0D	 xAFE	 xFF0C	 x0	 x6B6	 x3	 x0	 x2318600	 x0
2023-05-11T16:32:21.276Z,1683822741.276 [DATMMP](INFO): Received message type: directional
2023-05-11T16:32:21.276Z,1683822741.276 [DATMMP](INFO): Handled
2023-05-11T16:32:21.500Z,1683822741.500 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:21.502Z,1683822741.502 [DATMMP](INFO): acstats rx: 	 x5	 x5	 x0	 x2D0	 x23	 x82	 xB3	 xAE	 xD	 xFFFF	 xAB	 x21	 xC	 x0
2023-05-11T16:32:21.502Z,1683822741.502 [DATMMP](INFO): Received message type: acstats
2023-05-11T16:32:21.502Z,1683822741.502 [DATMMP](INFO): Handled
2023-05-11T16:32:21.752Z,1683822741.752 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:21.753Z,1683822741.753 [DATMMP](INFO): data_rx rx: 	 x5	 x0	 x0	 x20
2023-05-11T16:32:21.753Z,1683822741.753 [DATMMP](INFO): Check CRC
2023-05-11T16:32:21.754Z,1683822741.754 [DATMMP](INFO): data rx parseDataResponse 32
2023-05-11T16:32:21.754Z,1683822741.754 [DATMMP](INFO): Got DATA: len 32
2023-05-11T16:32:21.754Z,1683822741.754 [DATMMP](INFO): Received command: set _.humidity 12.916615 percent
2023-05-11T16:32:21.754Z,1683822741.754 [DATMMP](INFO): #Outgoing data=1
2023-05-11T16:32:21.754Z,1683822741.754 [DATMMP](INFO): Sending ack
2023-05-11T16:32:21.755Z,1683822741.755 [DATMMP](INFO): Received message type: data_rx
2023-05-11T16:32:21.755Z,1683822741.755 [DATMMP](INFO): Handled
2023-05-11T16:32:21.755Z,1683822741.755 [DATMMP](INFO): *** SENDING_FILL_BUFFER ***
2023-05-11T16:32:21.755Z,1683822741.755 [DATMMP](ERROR): Waiting for previous to be ack'd
2023-05-11T16:32:21.756Z,1683822741.756 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA
2023-05-11T16:32:22.004Z,1683822742.004 [DATMMP](INFO): *** SENDING_NAV_DATA ***
2023-05-11T16:32:22.004Z,1683822742.004 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT
2023-05-11T16:32:22.256Z,1683822742.256 [DATMMP](INFO): *** SENDING_TRANSMIT ***
2023-05-11T16:32:22.257Z,1683822742.257 [DATMMP](INFO): Tx to 5 len 4 xid 25
2023-05-11T16:32:22.257Z,1683822742.257 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-11T16:32:22.257Z,1683822742.257 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-11T16:32:22.510Z,1683822742.510 [DATMMP](INFO): GSXN notify for xid: 25
2023-05-11T16:32:22.513Z,1683822742.513 [DATMMP](INFO): cmd_result rx: 	 x1	 x7	 x0	 x1
2023-05-11T16:32:22.513Z,1683822742.513 [DATMMP](DEBUG): In rxCmdResult, sent ack so set commsState_ = SENDING_VERIFIED
2023-05-11T16:32:22.513Z,1683822742.513 [DATMMP](DEBUG): Command complete send
2023-05-11T16:32:22.514Z,1683822742.514 [DATMMP](ERROR): 1:COMPLETE
2023-05-11T16:32:22.514Z,1683822742.514 [DATMMP](INFO): Received message type: cmd_result
2023-05-11T16:32:22.515Z,1683822742.515 [DATMMP](INFO): Handled
2023-05-11T16:32:22.515Z,1683822742.515 [DATMMP](INFO): *** SENDING_VERIFIED ***
2023-05-11T16:32:22.516Z,1683822742.516 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2023-05-11T16:32:22.760Z,1683822742.760 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:22.761Z,1683822742.761 [DATMMP](INFO): timestamp rx: 	 x0	 x10	 x20	 x15	 xC95
2023-05-11T16:32:22.762Z,1683822742.762 [DATMMP](INFO): Received message type: timestamp
2023-05-11T16:32:22.762Z,1683822742.762 [DATMMP](INFO): Handled
2023-05-11T16:32:23.098Z,1683822743.098 [CommandExec](IMPORTANT): got command set _.humidity 12.916615 percent
2023-05-11T16:32:30.572Z,1683822750.572 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:30.573Z,1683822750.573 [DATMMP](INFO): doppler rx: 	 x0
2023-05-11T16:32:30.573Z,1683822750.573 [DATMMP](INFO): Received message type: doppler
2023-05-11T16:32:30.573Z,1683822750.573 [DATMMP](INFO): Handled
2023-05-11T16:32:30.824Z,1683822750.824 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:30.825Z,1683822750.825 [DATMMP](INFO): timestamp rx: 	 x1	 x10	 x20	 x1C	 x2702
2023-05-11T16:32:30.826Z,1683822750.826 [DATMMP](INFO): Rx dataTimestamp_ set to:1683822781.544768
2023-05-11T16:32:30.826Z,1683822750.826 [DATMMP](INFO): Rx ping set to:1683822750.825357
2023-05-11T16:32:30.826Z,1683822750.826 [DATMMP](INFO): Received message type: timestamp
2023-05-11T16:32:30.826Z,1683822750.826 [DATMMP](INFO): Handled
2023-05-11T16:32:31.076Z,1683822751.076 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:31.078Z,1683822751.078 [DATMMP](INFO): remote_header rx: 	 xF	 x4	 x5	 x20	 x0	 xA	 x5	 x0
2023-05-11T16:32:31.078Z,1683822751.078 [DATMMP](INFO): DATA Src=5, Dst=10
2023-05-11T16:32:31.078Z,1683822751.078 [DATMMP](INFO): Received message type: remote_header
2023-05-11T16:32:31.078Z,1683822751.078 [DATMMP](INFO): Handled
2023-05-11T16:32:31.580Z,1683822751.580 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:31.581Z,1683822751.581 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-11T16:32:31.581Z,1683822751.581 [DATMMP](INFO): Received message type: nav_stat
2023-05-11T16:32:31.581Z,1683822751.581 [DATMMP](INFO): Handled
2023-05-11T16:32:31.832Z,1683822751.832 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:31.834Z,1683822751.834 [DATMMP](INFO): directional_debug rx: 	 x194	 x101	 x20	 x1E7	 x31F0	 x4891	 x7632	 x6DF3
2023-05-11T16:32:31.835Z,1683822751.835 [DATMMP](INFO): Received message type: directional_debug
2023-05-11T16:32:31.835Z,1683822751.835 [DATMMP](INFO): Handled
2023-05-11T16:32:32.084Z,1683822752.084 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:32.086Z,1683822752.086 [DATMMP](INFO): directional rx: 	 x1B8	 xF0	 x448	 xFEFF	 xAFE	 xFEFF	 x0	 x6B8	 x2	 x0	 x2318600	 x0
2023-05-11T16:32:32.088Z,1683822752.088 [DATMMP](INFO): Received message type: directional
2023-05-11T16:32:32.088Z,1683822752.088 [DATMMP](INFO): Handled
2023-05-11T16:32:32.336Z,1683822752.336 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:32.338Z,1683822752.338 [DATMMP](INFO): acstats rx: 	 x5	 x5	 x0	 x2D0	 x22	 x7E	 xC8	 xBD	 xD	 xFFFF	 xAB	 x23	 xC	 x0
2023-05-11T16:32:32.338Z,1683822752.338 [DATMMP](INFO): Received message type: acstats
2023-05-11T16:32:32.338Z,1683822752.338 [DATMMP](INFO): Handled
2023-05-11T16:32:32.346Z,1683822752.346 [CommandExec](IMPORTANT): got command set NAL9602.time_fix 1683822743 second
2023-05-11T16:32:32.588Z,1683822752.588 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:32.589Z,1683822752.589 [DATMMP](INFO): data_rx rx: 	 x5	 x0	 x0	 x20
2023-05-11T16:32:32.589Z,1683822752.589 [DATMMP](INFO): Check CRC
2023-05-11T16:32:32.589Z,1683822752.589 [DATMMP](INFO): data rx parseDataResponse 32
2023-05-11T16:32:32.590Z,1683822752.590 [DATMMP](INFO): Got DATA: len 32
2023-05-11T16:32:32.590Z,1683822752.590 [DATMMP](INFO): Received command: set _.humidity 12.916615 percent
2023-05-11T16:32:32.590Z,1683822752.590 [DATMMP](INFO): #Outgoing data=1
2023-05-11T16:32:32.590Z,1683822752.590 [DATMMP](INFO): Sending ack
2023-05-11T16:32:32.590Z,1683822752.590 [DATMMP](INFO): Received message type: data_rx
2023-05-11T16:32:32.591Z,1683822752.591 [DATMMP](INFO): Handled
2023-05-11T16:32:32.682Z,1683822752.682 [Default:CheckIn:Read_GPS] Stopped
2023-05-11T16:32:32.682Z,1683822752.682 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-11T16:32:32.840Z,1683822752.840 [DATMMP](INFO): *** SENDING_FILL_BUFFER ***
2023-05-11T16:32:32.841Z,1683822752.841 [DATMMP](ERROR): Waiting for previous to be ack'd
2023-05-11T16:32:32.841Z,1683822752.841 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA
2023-05-11T16:32:33.033Z,1683822753.033 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-05-11T16:32:33.033Z,1683822753.033 [Default:CheckIn:Read_Iridium] Stopped
2023-05-11T16:32:33.033Z,1683822753.033 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-11T16:32:33.033Z,1683822753.033 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-11T16:32:33.092Z,1683822753.092 [DATMMP](INFO): *** SENDING_NAV_DATA ***
2023-05-11T16:32:33.092Z,1683822753.092 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT
2023-05-11T16:32:33.344Z,1683822753.344 [DATMMP](INFO): *** SENDING_TRANSMIT ***
2023-05-11T16:32:33.345Z,1683822753.345 [DATMMP](INFO): Tx to 5 len 4 xid 26
2023-05-11T16:32:33.345Z,1683822753.345 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-11T16:32:33.345Z,1683822753.345 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-11T16:32:33.596Z,1683822753.596 [DATMMP](INFO): GSXN notify for xid: 26
2023-05-11T16:32:33.597Z,1683822753.597 [DATMMP](INFO): cmd_result rx: 	 x1	 x7	 x0	 x1
2023-05-11T16:32:33.597Z,1683822753.597 [DATMMP](DEBUG): In rxCmdResult, sent ack so set commsState_ = SENDING_VERIFIED
2023-05-11T16:32:33.597Z,1683822753.597 [DATMMP](DEBUG): Command complete send
2023-05-11T16:32:33.598Z,1683822753.598 [DATMMP](ERROR): 1:COMPLETE
2023-05-11T16:32:33.598Z,1683822753.598 [DATMMP](INFO): Received message type: cmd_result
2023-05-11T16:32:33.598Z,1683822753.598 [DATMMP](INFO): Handled
2023-05-11T16:32:33.598Z,1683822753.598 [DATMMP](INFO): *** SENDING_VERIFIED ***
2023-05-11T16:32:33.598Z,1683822753.598 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2023-05-11T16:32:33.702Z,1683822753.702 [CommandExec](IMPORTANT): got command set _.humidity 12.916615 percent
2023-05-11T16:32:33.848Z,1683822753.848 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:33.849Z,1683822753.849 [DATMMP](INFO): timestamp rx: 	 x0	 x10	 x20	 x20	 x106F
2023-05-11T16:32:33.850Z,1683822753.850 [DATMMP](INFO): Received message type: timestamp
2023-05-11T16:32:33.850Z,1683822753.850 [DATMMP](INFO): Handled
2023-05-11T16:32:41.413Z,1683822761.413 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:41.413Z,1683822761.413 [DATMMP](INFO): doppler rx: 	 x0
2023-05-11T16:32:41.414Z,1683822761.414 [DATMMP](INFO): Received message type: doppler
2023-05-11T16:32:41.414Z,1683822761.414 [DATMMP](INFO): Handled
2023-05-11T16:32:41.664Z,1683822761.664 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:41.665Z,1683822761.665 [DATMMP](INFO): timestamp rx: 	 x1	 x10	 x20	 x27	 x2117
2023-05-11T16:32:41.666Z,1683822761.666 [DATMMP](INFO): Rx dataTimestamp_ set to:1683822777.759808
2023-05-11T16:32:41.666Z,1683822761.666 [DATMMP](INFO): Rx ping set to:1683822761.665351
2023-05-11T16:32:41.666Z,1683822761.666 [DATMMP](INFO): Received message type: timestamp
2023-05-11T16:32:41.666Z,1683822761.666 [DATMMP](INFO): Handled
2023-05-11T16:32:41.916Z,1683822761.916 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:41.918Z,1683822761.918 [DATMMP](INFO): remote_header rx: 	 xF	 x4	 x5	 x20	 x0	 xA	 x5	 x0
2023-05-11T16:32:41.918Z,1683822761.918 [DATMMP](INFO): DATA Src=5, Dst=10
2023-05-11T16:32:41.918Z,1683822761.918 [DATMMP](INFO): Received message type: remote_header
2023-05-11T16:32:41.918Z,1683822761.918 [DATMMP](INFO): Handled
2023-05-11T16:32:42.420Z,1683822762.420 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:42.421Z,1683822762.421 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-11T16:32:42.421Z,1683822762.421 [DATMMP](INFO): Received message type: nav_stat
2023-05-11T16:32:42.421Z,1683822762.421 [DATMMP](INFO): Handled
2023-05-11T16:32:42.676Z,1683822762.676 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:42.678Z,1683822762.678 [DATMMP](INFO): directional_debug rx: 	 x192	 x115	 x21	 x1A8	 x2B80	 x48D1	 x7552	 x6F03
2023-05-11T16:32:42.679Z,1683822762.679 [DATMMP](INFO): Received message type: directional_debug
2023-05-11T16:32:42.679Z,1683822762.679 [DATMMP](INFO): Handled
2023-05-11T16:32:42.928Z,1683822762.928 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:42.930Z,1683822762.930 [DATMMP](INFO): directional rx: 	 x1B3	 xFF	 x44A	 xFEEB	 xAFF	 xFEEA	 x0	 x6B6	 x2	 x0	 x2318600	 x0
2023-05-11T16:32:42.932Z,1683822762.932 [DATMMP](INFO): Received message type: directional
2023-05-11T16:32:42.932Z,1683822762.932 [DATMMP](INFO): Handled
2023-05-11T16:32:43.180Z,1683822763.180 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:43.182Z,1683822763.182 [DATMMP](INFO): acstats rx: 	 x5	 x5	 x0	 x1B8	 x23	 x7E	 xC4	 xC9	 xD	 xFFFF	 xA9	 x20	 xC	 x0
2023-05-11T16:32:43.182Z,1683822763.182 [DATMMP](INFO): Received message type: acstats
2023-05-11T16:32:43.182Z,1683822763.182 [DATMMP](INFO): Handled
2023-05-11T16:32:43.432Z,1683822763.432 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:43.433Z,1683822763.433 [DATMMP](INFO): data_rx rx: 	 x5	 x0	 x0	 x20
2023-05-11T16:32:43.433Z,1683822763.433 [DATMMP](INFO): Check CRC
2023-05-11T16:32:43.433Z,1683822763.433 [DATMMP](INFO): data rx parseDataResponse 32
2023-05-11T16:32:43.434Z,1683822763.434 [DATMMP](INFO): Got DATA: len 32
2023-05-11T16:32:43.434Z,1683822763.434 [DATMMP](INFO): Received command: set _.humidity 12.916615 percent
2023-05-11T16:32:43.434Z,1683822763.434 [DATMMP](INFO): #Outgoing data=1
2023-05-11T16:32:43.434Z,1683822763.434 [DATMMP](INFO): Sending ack
2023-05-11T16:32:43.434Z,1683822763.434 [DATMMP](INFO): Received message type: data_rx
2023-05-11T16:32:43.435Z,1683822763.435 [DATMMP](INFO): Handled
2023-05-11T16:32:43.435Z,1683822763.435 [DATMMP](INFO): *** SENDING_FILL_BUFFER ***
2023-05-11T16:32:43.435Z,1683822763.435 [DATMMP](ERROR): Waiting for previous to be ack'd
2023-05-11T16:32:43.435Z,1683822763.435 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA
2023-05-11T16:32:43.684Z,1683822763.684 [DATMMP](INFO): *** SENDING_NAV_DATA ***
2023-05-11T16:32:43.684Z,1683822763.684 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT
2023-05-11T16:32:43.936Z,1683822763.936 [DATMMP](INFO): *** SENDING_TRANSMIT ***
2023-05-11T16:32:43.937Z,1683822763.937 [DATMMP](INFO): Tx to 5 len 4 xid 27
2023-05-11T16:32:43.937Z,1683822763.937 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-11T16:32:43.937Z,1683822763.937 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-11T16:32:44.188Z,1683822764.188 [DATMMP](INFO): GSXN notify for xid: 27
2023-05-11T16:32:44.189Z,1683822764.189 [DATMMP](INFO): cmd_result rx: 	 x1	 x7	 x0	 x1
2023-05-11T16:32:44.189Z,1683822764.189 [DATMMP](DEBUG): In rxCmdResult, sent ack so set commsState_ = SENDING_VERIFIED
2023-05-11T16:32:44.189Z,1683822764.189 [DATMMP](DEBUG): Command complete send
2023-05-11T16:32:44.190Z,1683822764.190 [DATMMP](ERROR): 1:COMPLETE
2023-05-11T16:32:44.190Z,1683822764.190 [DATMMP](INFO): Received message type: cmd_result
2023-05-11T16:32:44.190Z,1683822764.190 [DATMMP](INFO): Handled
2023-05-11T16:32:44.190Z,1683822764.190 [DATMMP](INFO): *** SENDING_VERIFIED ***
2023-05-11T16:32:44.190Z,1683822764.190 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2023-05-11T16:32:44.440Z,1683822764.440 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:44.441Z,1683822764.441 [DATMMP](INFO): timestamp rx: 	 x0	 x10	 x20	 x2B	 xDC
2023-05-11T16:32:44.442Z,1683822764.442 [DATMMP](INFO): Received message type: timestamp
2023-05-11T16:32:44.442Z,1683822764.442 [DATMMP](INFO): Handled
2023-05-11T16:32:44.587Z,1683822764.587 [CommandExec](IMPORTANT): got command set _.humidity 12.916615 percent
2023-05-11T16:32:52.260Z,1683822772.260 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:52.261Z,1683822772.261 [DATMMP](INFO): doppler rx: 	 x0
2023-05-11T16:32:52.261Z,1683822772.261 [DATMMP](INFO): Received message type: doppler
2023-05-11T16:32:52.261Z,1683822772.261 [DATMMP](INFO): Handled
2023-05-11T16:32:52.513Z,1683822772.513 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:52.516Z,1683822772.516 [DATMMP](INFO): timestamp rx: 	 x1	 x10	 x20	 x32	 x1B49
2023-05-11T16:32:52.518Z,1683822772.518 [DATMMP](INFO): Rx dataTimestamp_ set to:1683822774.223232
2023-05-11T16:32:52.519Z,1683822772.519 [DATMMP](INFO): Rx ping set to:1683822772.516346
2023-05-11T16:32:52.519Z,1683822772.519 [DATMMP](INFO): Received message type: timestamp
2023-05-11T16:32:52.520Z,1683822772.520 [DATMMP](INFO): Handled
2023-05-11T16:32:52.764Z,1683822772.764 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:52.766Z,1683822772.766 [DATMMP](INFO): remote_header rx: 	 xF	 x4	 x5	 x20	 x0	 xA	 x5	 x0
2023-05-11T16:32:52.766Z,1683822772.766 [DATMMP](INFO): DATA Src=5, Dst=10
2023-05-11T16:32:52.766Z,1683822772.766 [DATMMP](INFO): Received message type: remote_header
2023-05-11T16:32:52.766Z,1683822772.766 [DATMMP](INFO): Handled
2023-05-11T16:32:53.268Z,1683822773.268 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:53.269Z,1683822773.269 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-11T16:32:53.269Z,1683822773.269 [DATMMP](INFO): Received message type: nav_stat
2023-05-11T16:32:53.269Z,1683822773.269 [DATMMP](INFO): Handled
2023-05-11T16:32:53.520Z,1683822773.520 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:53.522Z,1683822773.522 [DATMMP](INFO): directional_debug rx: 	 x1A4	 xFE	 x20	 x1A6	 x31F0	 x3FA1	 x6752	 x62E3
2023-05-11T16:32:53.523Z,1683822773.523 [DATMMP](INFO): Received message type: directional_debug
2023-05-11T16:32:53.523Z,1683822773.523 [DATMMP](INFO): Handled
2023-05-11T16:32:53.772Z,1683822773.772 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:53.774Z,1683822773.774 [DATMMP](INFO): directional rx: 	 x1C9	 xED	 x438	 xFF02	 xAED	 xFF01	 x0	 x6B5	 x1	 x1	 x2318600	 x0
2023-05-11T16:32:53.776Z,1683822773.776 [DATMMP](INFO): Received message type: directional
2023-05-11T16:32:53.776Z,1683822773.776 [DATMMP](INFO): Handled
2023-05-11T16:32:54.024Z,1683822774.024 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:54.026Z,1683822774.026 [DATMMP](INFO): acstats rx: 	 x5	 x5	 x0	 x2D0	 x23	 x7F	 xBA	 xB1	 xD	 xFFFF	 xA6	 x22	 xC	 x0
2023-05-11T16:32:54.026Z,1683822774.026 [DATMMP](INFO): Received message type: acstats
2023-05-11T16:32:54.027Z,1683822774.027 [DATMMP](INFO): Handled
2023-05-11T16:32:54.276Z,1683822774.276 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:54.277Z,1683822774.277 [DATMMP](INFO): data_rx rx: 	 x5	 x0	 x0	 x20
2023-05-11T16:32:54.278Z,1683822774.278 [DATMMP](INFO): Check CRC
2023-05-11T16:32:54.278Z,1683822774.278 [DATMMP](INFO): data rx parseDataResponse 32
2023-05-11T16:32:54.278Z,1683822774.278 [DATMMP](INFO): Got DATA: len 32
2023-05-11T16:32:54.278Z,1683822774.278 [DATMMP](INFO): Received command: set _.humidity 12.916615 percent
2023-05-11T16:32:54.278Z,1683822774.278 [DATMMP](INFO): #Outgoing data=1
2023-05-11T16:32:54.279Z,1683822774.279 [DATMMP](INFO): Sending ack
2023-05-11T16:32:54.279Z,1683822774.279 [DATMMP](INFO): Received message type: data_rx
2023-05-11T16:32:54.279Z,1683822774.279 [DATMMP](INFO): Handled
2023-05-11T16:32:54.279Z,1683822774.279 [DATMMP](INFO): *** SENDING_FILL_BUFFER ***
2023-05-11T16:32:54.279Z,1683822774.279 [DATMMP](ERROR): Waiting for previous to be ack'd
2023-05-11T16:32:54.280Z,1683822774.280 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA
2023-05-11T16:32:54.530Z,1683822774.530 [DATMMP](INFO): *** SENDING_NAV_DATA ***
2023-05-11T16:32:54.530Z,1683822774.530 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT
2023-05-11T16:32:54.780Z,1683822774.780 [DATMMP](INFO): *** SENDING_TRANSMIT ***
2023-05-11T16:32:54.781Z,1683822774.781 [DATMMP](INFO): Tx to 5 len 4 xid 28
2023-05-11T16:32:54.781Z,1683822774.781 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-11T16:32:54.781Z,1683822774.781 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-11T16:32:55.032Z,1683822775.032 [DATMMP](INFO): GSXN notify for xid: 28
2023-05-11T16:32:55.033Z,1683822775.033 [DATMMP](INFO): cmd_result rx: 	 x1	 x7	 x0	 x1
2023-05-11T16:32:55.033Z,1683822775.033 [DATMMP](DEBUG): In rxCmdResult, sent ack so set commsState_ = SENDING_VERIFIED
2023-05-11T16:32:55.034Z,1683822775.034 [DATMMP](DEBUG): Command complete send
2023-05-11T16:32:55.034Z,1683822775.034 [DATMMP](ERROR): 1:COMPLETE
2023-05-11T16:32:55.034Z,1683822775.034 [DATMMP](INFO): Received message type: cmd_result
2023-05-11T16:32:55.034Z,1683822775.034 [DATMMP](INFO): Handled
2023-05-11T16:32:55.034Z,1683822775.034 [DATMMP](INFO): *** SENDING_VERIFIED ***
2023-05-11T16:32:55.034Z,1683822775.034 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2023-05-11T16:32:55.284Z,1683822775.284 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-11T16:32:55.285Z,1683822775.285 [DATMMP](INFO): timestamp rx: 	 x0	 x10	 x20	 x35	 x2202
2023-05-11T16:32:55.285Z,1683822775.285 [DATMMP](INFO): Received message type: timestamp
2023-05-11T16:32:55.286Z,1683822775.286 [DATMMP](INFO): Handled
2023-05-11T16:32:55.531Z,1683822775.531 [CommandExec](IMPORTANT): got command set _.humidity 12.916615 percent
2023-05-11T16:33:32.250Z,1683822812.250 [CommandExec](IMPORTANT): got command show variable address
2023-05-11T16:33:32.252Z,1683822812.252 [CommandExec](IMPORTANT): acoustic_contact_address (enum)
2023-05-11T16:33:32.265Z,1683822812.265 [CommandExec](IMPORTANT): AcousticModem_Benthos_ATM900.localAddress (count)
2023-05-11T16:33:32.266Z,1683822812.266 [CommandExec](IMPORTANT): AcousticModem_Benthos_ATM900.sbdAddress (enum)
2023-05-11T16:33:32.266Z,1683822812.266 [CommandExec](IMPORTANT): AcousticModem_Benthos_ATM900.transponderAddress (enum)
2023-05-11T16:33:32.270Z,1683822812.270 [CommandExec](IMPORTANT): DAT.sbdAddress (enum)
2023-05-11T16:33:32.270Z,1683822812.270 [CommandExec](IMPORTANT): DAT.transponderAddress (enum)
2023-05-11T16:33:32.271Z,1683822812.271 [CommandExec](IMPORTANT): DATMMP.sbdAddress (enum)
2023-05-11T16:33:32.272Z,1683822812.272 [CommandExec](IMPORTANT): DATMMP.transponderAddress (enum)
2023-05-11T16:33:32.275Z,1683822812.275 [CommandExec](IMPORTANT): Micromodem.localAddress (enum)
2023-05-11T16:33:32.275Z,1683822812.275 [CommandExec](IMPORTANT): Micromodem.destinationAddress (enum)
2023-05-11T16:33:32.286Z,1683822812.286 [CommandExec](IMPORTANT): Config/workSite.beacon1Address (count)
2023-05-11T16:33:32.287Z,1683822812.287 [CommandExec](IMPORTANT): Config/workSite.beacon2Address (count)
2023-05-11T16:33:32.287Z,1683822812.287 [CommandExec](IMPORTANT): Config/workSite.beacon3Address (count)
2023-05-11T16:33:32.656Z,1683822812.656 [CommandExec](IMPORTANT): DATMMP.acoustic_contact_address (enum)
2023-05-11T16:33:32.658Z,1683822812.658 [CommandExec](IMPORTANT): DATMMP.localAddressReading (enum)
2023-05-11T16:33:42.056Z,1683822822.056 [CommandExec](IMPORTANT): got command get DATMMP.acoustic_contact_address
2023-05-11T16:33:42.056Z,1683822822.056 [CommandExec](IMPORTANT): DATMMP.acoustic_contact_address 0 enum
2023-05-11T16:33:49.557Z,1683822829.557 [CommandExec](IMPORTANT): got command get DATMMP.sbdAddress
2023-05-11T16:33:49.557Z,1683822829.557 [CommandExec](IMPORTANT): DATMMP.sbdAddress -1 enum
2023-05-11T16:33:58.137Z,1683822838.137 [CommandExec](IMPORTANT): got command get DAT.transponderAddress 
2023-05-11T16:33:58.138Z,1683822838.138 [CommandExec](IMPORTANT): DAT.transponderAddress 0 enum
2023-05-11T16:34:10.806Z,1683822850.806 [CommandExec](IMPORTANT): got command get DATMMP.localAddressReading
2023-05-11T16:34:10.806Z,1683822850.806 [CommandExec](IMPORTANT): DATMMP.localAddressReading 0 enum
2023-05-11T16:34:27.089Z,1683822867.089 [CommandExec](IMPORTANT): got command get DATMMP.acoustic_contact_address
2023-05-11T16:34:27.089Z,1683822867.089 [CommandExec](IMPORTANT): DATMMP.acoustic_contact_address 0 enum
2023-05-11T16:35:34.045Z,1683822934.045 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-05-11T16:36:04.712Z,1683822964.712 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-11T16:36:47.937Z,1683823007.937 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2023-05-11T16:36:47.940Z,1683823007.940 [BPC1](INFO): Received data from all battery sticks.
2023-05-11T16:37:33.594Z,1683823053.594 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-11T16:37:33.594Z,1683823053.594 [Default:CheckIn:C.Wait] Stopped
2023-05-11T16:37:33.594Z,1683823053.594 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-11T16:37:33.594Z,1683823053.594 [Default:CheckIn:D] Running Loop=1
2023-05-11T16:37:34.003Z,1683823054.003 [Default:CheckIn:D] Stopped
2023-05-11T16:37:34.003Z,1683823054.003 [Default:CheckIn:E] Running Loop=1
2023-05-11T16:37:34.415Z,1683823054.415 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 5.566849 min 
2023-05-11T16:37:34.415Z,1683823054.415 [Default:CheckIn:E] Stopped
2023-05-11T16:37:34.415Z,1683823054.415 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-11T16:37:34.415Z,1683823054.415 [Default:CheckIn] Stopped
2023-05-11T16:37:34.415Z,1683823054.415 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-11T16:37:34.416Z,1683823054.416 [Default:CheckIn](INFO): Running loop #2
2023-05-11T16:37:34.416Z,1683823054.416 [Default:CheckIn] Running Loop=2
2023-05-11T16:37:34.416Z,1683823054.416 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-11T16:37:34.416Z,1683823054.416 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-11T16:38:07.117Z,1683823087.117 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-05-11T16:38:07.200Z,1683823087.200 [NAL9602](ERROR): received: 
+CSQ:0

OK
2023-05-11T16:42:34.671Z,1683823354.671 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-05-11T16:37:34.4Z
2023-05-11T16:42:34.671Z,1683823354.671 [Default:CheckIn:Read_GPS] Stopped
2023-05-11T16:42:34.671Z,1683823354.671 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-11T16:42:38.693Z,1683823358.693 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-05-11T16:42:42.056Z,1683823362.056 [DataOverHttps](INFO): Sending 167 bytes from file Logs/20230511T162055/Courier0004.lzma
2023-05-11T16:42:43.057Z,1683823363.057 [DataOverHttps](INFO): Moved sent file to Logs/20230511T162055/Courier0004.lzma.bak
2023-05-11T16:42:43.058Z,1683823363.058 [DataOverHttps](INFO): SBD MOMSN=18290373
2023-05-11T16:42:58.139Z,1683823378.139 [DataOverHttps](INFO): Sending 248 bytes from file Logs/20230511T162939/Courier0000.lzma
2023-05-11T16:42:59.142Z,1683823379.142 [DataOverHttps](INFO): Moved sent file to Logs/20230511T162939/Courier0000.lzma.bak
2023-05-11T16:42:59.142Z,1683823379.142 [DataOverHttps](INFO): SBD MOMSN=18290375
2023-05-11T16:43:09.380Z,1683823389.380 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-11T16:43:15.116Z,1683823395.116 [DataOverHttps](INFO): Sending 274 bytes from file Logs/20230511T162055/Express0005.lzma
2023-05-11T16:43:16.117Z,1683823396.117 [DataOverHttps](INFO): Moved sent file to Logs/20230511T162055/Express0005.lzma.bak
2023-05-11T16:43:16.117Z,1683823396.117 [DataOverHttps](INFO): SBD MOMSN=18290378
2023-05-11T16:43:32.154Z,1683823412.154 [DataOverHttps](INFO): Sending 1659 bytes from file Logs/20230511T162939/Express0001.lzma
2023-05-11T16:43:33.158Z,1683823413.158 [DataOverHttps](INFO): Moved sent file to Logs/20230511T162939/Express0001.lzma.bak
2023-05-11T16:43:33.158Z,1683823413.158 [DataOverHttps](INFO): SBD MOMSN=18290386