2024-09-05T21:41:31.206Z,1725572491.206 [Supervisor](DEBUG): Initializing supervisor.
2024-09-05T21:41:31.210Z,1725572491.210 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2024-09-05T21:41:31.210Z,1725572491.210 [SyncHandler](INFO): Protected caller Thread ID is 834
2024-09-05T21:41:31.211Z,1725572491.211 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2024-09-05T21:41:31.212Z,1725572491.212 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2024-09-05T21:41:31.213Z,1725572491.213 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 835
2024-09-05T21:41:31.216Z,1725572491.216 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2024-09-05T21:41:31.234Z,1725572491.234 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2024-09-05T21:41:31.235Z,1725572491.235 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2024-09-05T21:41:31.235Z,1725572491.235 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 836
2024-09-05T21:41:31.239Z,1725572491.239 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2024-09-05T21:41:31.240Z,1725572491.240 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2024-09-05T21:41:31.240Z,1725572491.240 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 837
2024-09-05T21:41:31.243Z,1725572491.243 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2024-09-05T21:41:31.243Z,1725572491.243 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2024-09-05T21:41:31.244Z,1725572491.244 [logger ThreadHandler](INFO): Protected caller Thread ID is 838
2024-09-05T21:41:31.247Z,1725572491.247 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2024-09-05T21:41:31.248Z,1725572491.248 [Supervisor](INFO): Looking for Config files in directory: Config/
2024-09-05T21:41:31.252Z,1725572491.252 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2024-09-05T21:41:31.597Z,1725572491.597 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2024-09-05T21:41:31.599Z,1725572491.599 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2024-09-05T21:41:32.372Z,1725572492.372 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2024-09-05T21:41:32.374Z,1725572492.374 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2024-09-05T21:41:32.493Z,1725572492.493 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2024-09-05T21:41:32.495Z,1725572492.495 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2024-09-05T21:41:33.061Z,1725572493.061 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2024-09-05T21:41:33.062Z,1725572493.062 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2024-09-05T21:41:33.170Z,1725572493.170 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2024-09-05T21:41:33.172Z,1725572493.172 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2024-09-05T21:41:33.266Z,1725572493.266 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2024-09-05T21:41:33.814Z,1725572493.814 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2024-09-05T21:41:33.815Z,1725572493.815 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2024-09-05T21:41:34.214Z,1725572494.214 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2024-09-05T21:41:34.216Z,1725572494.216 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2024-09-05T21:41:34.486Z,1725572494.486 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2024-09-05T21:41:35.128Z,1725572495.128 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2024-09-05T21:41:35.619Z,1725572495.619 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2024-09-05T21:41:35.620Z,1725572495.620 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2024-09-05T21:41:36.189Z,1725572496.189 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2024-09-05T21:41:36.190Z,1725572496.190 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2024-09-05T21:41:36.650Z,1725572496.650 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2024-09-05T21:41:36.651Z,1725572496.651 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2024-09-05T21:41:36.745Z,1725572496.745 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2024-09-05T21:41:36.953Z,1725572496.953 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2024-09-05T21:41:36.955Z,1725572496.955 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2024-09-05T21:41:37.201Z,1725572497.201 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2024-09-05T21:41:37.203Z,1725572497.203 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2024-09-05T21:41:37.516Z,1725572497.516 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2024-09-05T21:41:37.518Z,1725572497.518 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-brizo/
2024-09-05T21:41:37.523Z,1725572497.523 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Control.cfg
2024-09-05T21:41:37.643Z,1725572497.643 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Sensor.cfg
2024-09-05T21:41:37.806Z,1725572497.806 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Simulator.cfg
2024-09-05T21:41:37.904Z,1725572497.904 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/secure.cfg
2024-09-05T21:41:37.000Z,1725572498.000 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Servo.cfg
2024-09-05T21:41:38.120Z,1725572498.120 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/workSite.cfg
2024-09-05T21:41:38.216Z,1725572498.216 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/vehicle.cfg
2024-09-05T21:41:38.334Z,1725572498.334 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Battery.cfg
2024-09-05T21:41:38.608Z,1725572498.608 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2024-09-05T21:41:38.608Z,1725572498.608 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Science.cfg
2024-09-05T21:41:38.753Z,1725572498.753 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/logger.cfg
2024-09-05T21:41:38.858Z,1725572498.858 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/BIT.cfg
2024-09-05T21:41:38.962Z,1725572498.962 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Navigation.cfg
2024-09-05T21:41:39.068Z,1725572499.068 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg
2024-09-05T21:41:39.083Z,1725572499.083 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2024-09-05T21:41:39.223Z,1725572499.223 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2024-09-05T21:41:39.223Z,1725572499.223 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2024-09-05T21:41:39.239Z,1725572499.239 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2024-09-05T21:41:39.239Z,1725572499.239 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2024-09-05T21:41:39.309Z,1725572499.309 [DepthRateCalculator] Loaded
2024-09-05T21:41:39.309Z,1725572499.309 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2024-09-05T21:41:39.314Z,1725572499.314 [PitchRateCalculator] Loaded
2024-09-05T21:41:39.315Z,1725572499.315 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2024-09-05T21:41:39.325Z,1725572499.325 [SpeedCalculator] Loaded
2024-09-05T21:41:39.325Z,1725572499.325 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2024-09-05T21:41:39.330Z,1725572499.330 [YawRateCalculator] Loaded
2024-09-05T21:41:39.330Z,1725572499.330 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2024-09-05T21:41:39.351Z,1725572499.351 [ElevatorOffsetCalculator] Loaded
2024-09-05T21:41:39.351Z,1725572499.351 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2024-09-05T21:41:39.352Z,1725572499.352 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2024-09-05T21:41:39.352Z,1725572499.352 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2024-09-05T21:41:39.421Z,1725572499.421 [VerticalControl](DEBUG): Construct VerticalControl.
2024-09-05T21:41:39.476Z,1725572499.476 [VerticalControl] Loaded
2024-09-05T21:41:39.476Z,1725572499.476 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2024-09-05T21:41:39.479Z,1725572499.479 [HorizontalControl](DEBUG): Construct HorizontalControl.
2024-09-05T21:41:39.525Z,1725572499.525 [HorizontalControl] Loaded
2024-09-05T21:41:39.526Z,1725572499.526 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2024-09-05T21:41:39.528Z,1725572499.528 [SpeedControl](DEBUG): Construct SpeedControl.
2024-09-05T21:41:39.531Z,1725572499.531 [SpeedControl] Loaded
2024-09-05T21:41:39.531Z,1725572499.531 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2024-09-05T21:41:39.533Z,1725572499.533 [LoopControl](DEBUG): Construct LoopControl.
2024-09-05T21:41:39.534Z,1725572499.534 [LoopControl] Loaded
2024-09-05T21:41:39.534Z,1725572499.534 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2024-09-05T21:41:39.535Z,1725572499.535 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2024-09-05T21:41:39.535Z,1725572499.535 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2024-09-05T21:41:40.259Z,1725572500.259 [DeadReckonUsingMultipleVelocitySources] Loaded
2024-09-05T21:41:40.259Z,1725572500.259 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2024-09-05T21:41:40.273Z,1725572500.273 [NavChart] Loaded
2024-09-05T21:41:40.274Z,1725572500.274 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2024-09-05T21:41:40.279Z,1725572500.279 [UniversalFixResidualReporter] Loaded
2024-09-05T21:41:40.279Z,1725572500.279 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2024-09-05T21:41:40.280Z,1725572500.280 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2024-09-05T21:41:40.281Z,1725572500.281 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2024-09-05T21:41:40.711Z,1725572500.711 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2024-09-05T21:41:40.711Z,1725572500.711 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2024-09-05T21:41:41.521Z,1725572501.521 [AHRS_M2] Loaded
2024-09-05T21:41:41.522Z,1725572501.522 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2024-09-05T21:41:41.775Z,1725572501.775 [BackseatComponent] Loaded
2024-09-05T21:41:41.775Z,1725572501.775 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2024-09-05T21:41:41.777Z,1725572501.777 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 409384E0
2024-09-05T21:41:41.777Z,1725572501.777 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 924
2024-09-05T21:41:41.780Z,1725572501.780 [LcmUniversalReporter] Loaded
2024-09-05T21:41:41.780Z,1725572501.780 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2024-09-05T21:41:42.602Z,1725572502.602 [BPC1] Loaded
2024-09-05T21:41:42.603Z,1725572502.603 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2024-09-05T21:41:42.689Z,1725572502.689 [DATMMP] Loaded
2024-09-05T21:41:42.689Z,1725572502.689 [ComponentRegistry](DEBUG): Component "DATMMP" handled in its own thread.
2024-09-05T21:41:42.690Z,1725572502.690 [DATMMP ThreadHandler](DEBUG): Created PCaller Thread at 409694E0
2024-09-05T21:41:42.690Z,1725572502.690 [DATMMP ThreadHandler](INFO): Protected caller Thread ID is 925
2024-09-05T21:41:42.835Z,1725572502.835 [DataOverHttps] Loaded
2024-09-05T21:41:42.835Z,1725572502.835 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2024-09-05T21:41:42.836Z,1725572502.836 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409994E0
2024-09-05T21:41:42.836Z,1725572502.836 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 926
2024-09-05T21:41:42.859Z,1725572502.859 [Depth_Keller] Loaded
2024-09-05T21:41:42.859Z,1725572502.859 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2024-09-05T21:41:42.899Z,1725572502.899 [DVL_micro] Loaded
2024-09-05T21:41:42.899Z,1725572502.899 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2024-09-05T21:41:42.962Z,1725572502.962 [NAL9602] Loaded
2024-09-05T21:41:42.962Z,1725572502.962 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2024-09-05T21:41:42.992Z,1725572502.992 [Onboard] Loaded
2024-09-05T21:41:42.992Z,1725572502.992 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2024-09-05T21:41:42.993Z,1725572502.993 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409C94E0
2024-09-05T21:41:42.993Z,1725572502.993 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 927
2024-09-05T21:41:43.007Z,1725572503.007 [Power24vConverter] Loaded
2024-09-05T21:41:43.007Z,1725572503.007 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2024-09-05T21:41:43.023Z,1725572503.023 [Radio_Surface] Loaded
2024-09-05T21:41:43.023Z,1725572503.023 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2024-09-05T21:41:43.024Z,1725572503.024 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409F94E0
2024-09-05T21:41:43.024Z,1725572503.024 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 928
2024-09-05T21:41:43.039Z,1725572503.039 [Sonardyne_Nano] Loaded
2024-09-05T21:41:43.040Z,1725572503.040 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread.
2024-09-05T21:41:43.040Z,1725572503.040 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2024-09-05T21:41:43.041Z,1725572503.041 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2024-09-05T21:41:43.199Z,1725572503.199 [BuoyancyServo] Loaded
2024-09-05T21:41:43.200Z,1725572503.200 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2024-09-05T21:41:43.223Z,1725572503.223 [ElevatorServo] Loaded
2024-09-05T21:41:43.223Z,1725572503.223 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2024-09-05T21:41:43.245Z,1725572503.245 [MassServo] Loaded
2024-09-05T21:41:43.245Z,1725572503.245 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2024-09-05T21:41:43.265Z,1725572503.265 [RudderServo] Loaded
2024-09-05T21:41:43.266Z,1725572503.266 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2024-09-05T21:41:43.282Z,1725572503.282 [ThrusterHE] Loaded
2024-09-05T21:41:43.282Z,1725572503.282 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2024-09-05T21:41:43.282Z,1725572503.282 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2024-09-05T21:41:43.283Z,1725572503.283 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2024-09-05T21:41:43.379Z,1725572503.379 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2024-09-05T21:41:43.379Z,1725572503.379 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2024-09-05T21:41:43.422Z,1725572503.422 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2024-09-05T21:41:43.422Z,1725572503.422 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2024-09-05T21:41:43.809Z,1725572503.809 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2024-09-05T21:41:43.810Z,1725572503.810 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2024-09-05T21:41:44.033Z,1725572504.033 [CTD_Seabird] Loaded
2024-09-05T21:41:44.033Z,1725572504.033 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2024-09-05T21:41:44.034Z,1725572504.034 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40BB34E0
2024-09-05T21:41:44.034Z,1725572504.034 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 929
2024-09-05T21:41:44.070Z,1725572504.070 [ESPComponent] Loaded
2024-09-05T21:41:44.070Z,1725572504.070 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2024-09-05T21:41:44.092Z,1725572504.092 [PAR_Licor] Loaded
2024-09-05T21:41:44.092Z,1725572504.092 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2024-09-05T21:41:44.136Z,1725572504.136 [WetLabsBB2FL] Loaded
2024-09-05T21:41:44.137Z,1725572504.137 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2024-09-05T21:41:44.138Z,1725572504.138 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40BE34E0
2024-09-05T21:41:44.138Z,1725572504.138 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 930
2024-09-05T21:41:44.139Z,1725572504.139 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2024-09-05T21:41:44.139Z,1725572504.139 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2024-09-05T21:41:44.306Z,1725572504.306 [SBIT](DEBUG): Construct Startup Built In Test.
2024-09-05T21:41:44.315Z,1725572504.315 [SBIT] Loaded
2024-09-05T21:41:44.315Z,1725572504.315 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2024-09-05T21:41:44.318Z,1725572504.318 [IBIT](DEBUG): Construct Initiated Built In Test.
2024-09-05T21:41:44.331Z,1725572504.331 [IBIT] Loaded
2024-09-05T21:41:44.331Z,1725572504.331 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2024-09-05T21:41:44.337Z,1725572504.337 [CBIT](DEBUG): Construct Continuous Built In Test.
2024-09-05T21:41:44.442Z,1725572504.442 [CBIT] Loaded
2024-09-05T21:41:44.442Z,1725572504.442 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2024-09-05T21:41:44.443Z,1725572504.443 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2024-09-05T21:41:44.449Z,1725572504.449 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2024-09-05T21:41:44.452Z,1725572504.452 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2024-09-05T21:41:44.463Z,1725572504.463 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2024-09-05T21:41:44.464Z,1725572504.464 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C524E0
2024-09-05T21:41:44.465Z,1725572504.465 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 931
2024-09-05T21:41:44.469Z,1725572504.469 [Supervisor](INFO): Main Thread ID is 827
2024-09-05T21:41:44.469Z,1725572504.469 [Supervisor](DEBUG): Running supervisor.
2024-09-05T21:41:44.470Z,1725572504.470 [CommandExec ThreadHandler](INFO): Handler Thread ID is 932
2024-09-05T21:41:44.471Z,1725572504.471 [CommandExec](INFO): Initializing the command executive.
2024-09-05T21:41:44.472Z,1725572504.472 [CommandLine ThreadHandler](INFO): Handler Thread ID is 933
2024-09-05T21:41:44.474Z,1725572504.474 [controlThread ThreadHandler](INFO): Handler Thread ID is 934
2024-09-05T21:41:44.474Z,1725572504.474 [controlThread](DEBUG): Initializing ControlThread
2024-09-05T21:41:44.475Z,1725572504.475 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2024-09-05T21:41:44.476Z,1725572504.476 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2024-09-05T21:41:44.476Z,1725572504.476 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2024-09-05T21:41:44.476Z,1725572504.476 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2024-09-05T21:41:44.477Z,1725572504.477 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2024-09-05T21:41:44.477Z,1725572504.477 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2024-09-05T21:41:44.479Z,1725572504.479 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2024-09-05T21:41:44.479Z,1725572504.479 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2024-09-05T21:41:44.480Z,1725572504.480 [LoopControl](DEBUG): Initialize LoopControlComponent.
2024-09-05T21:41:44.481Z,1725572504.481 [NavChart](DEBUG): Initialize NavChart Navigation.
2024-09-05T21:41:44.481Z,1725572504.481 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2024-09-05T21:41:44.491Z,1725572504.491 [SBIT](INFO): Initialize SBIT Component.
2024-09-05T21:41:44.491Z,1725572504.491 [SBIT](IMPORTANT): git: 2024-09-05
2024-09-05T21:41:44.492Z,1725572504.492 [SBIT](INFO): git hash: dce0dc62070cf863068ea7da7140e449252762ed
2024-09-05T21:41:44.492Z,1725572504.492 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2024-09-05T21:41:44.493Z,1725572504.493 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Tue Sep 24 11:12:27 PDT 2019
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2024-09-05T21:41:44.494Z,1725572504.494 [SBIT](INFO): Beginning SBIT in 128.000000 seconds.
2024-09-05T21:41:44.495Z,1725572504.495 [IBIT](INFO): Initialize IBIT Component.
2024-09-05T21:41:44.496Z,1725572504.496 [CBIT](DEBUG): Initialize CBIT Component.
2024-09-05T21:41:44.496Z,1725572504.496 [logger ThreadHandler](INFO): Handler Thread ID is 935
2024-09-05T21:41:44.507Z,1725572504.507 [CBIT](DEBUG): Initialized mux pins.
2024-09-05T21:41:44.507Z,1725572504.507 [CBIT](DEBUG): Initializing the watchdog timer.
2024-09-05T21:41:44.515Z,1725572504.515 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 936
2024-09-05T21:41:44.527Z,1725572504.527 [DATMMP ThreadHandler](INFO): Handler Thread ID is 937
2024-09-05T21:41:44.528Z,1725572504.528 [DATMMP](INFO): Start
2024-09-05T21:41:44.528Z,1725572504.528 [DATMMP](INFO): Powering up
2024-09-05T21:41:44.528Z,1725572504.528 [DATMMP](DEBUG): Initializing DATMMP.
2024-09-05T21:41:44.531Z,1725572504.531 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2024-09-05T21:41:44.531Z,1725572504.531 [CBIT](DEBUG): Initializing heartbeat.
2024-09-05T21:41:44.533Z,1725572504.533 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 939
2024-09-05T21:41:44.535Z,1725572504.535 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2024-09-05T21:41:44.543Z,1725572504.543 [Onboard ThreadHandler](INFO): Handler Thread ID is 940
2024-09-05T21:41:44.573Z,1725572504.573 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 941
2024-09-05T21:41:44.583Z,1725572504.583 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 942
2024-09-05T21:41:44.584Z,1725572504.584 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2024-09-05T21:41:44.588Z,1725572504.588 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 944
2024-09-05T21:41:44.591Z,1725572504.591 [WetLabsBB2FL](INFO): Powering up
2024-09-05T21:41:44.592Z,1725572504.592 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 946
2024-09-05T21:41:44.601Z,1725572504.601 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2024-09-05T21:41:44.601Z,1725572504.601 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2024-09-05T21:41:44.601Z,1725572504.601 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2024-09-05T21:41:44.601Z,1725572504.601 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2024-09-05T21:41:44.601Z,1725572504.601 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2024-09-05T21:41:44.601Z,1725572504.601 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2024-09-05T21:41:44.602Z,1725572504.602 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2024-09-05T21:41:44.602Z,1725572504.602 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2024-09-05T21:41:44.603Z,1725572504.603 [CBIT](DEBUG): Deactivating GF circuits.
2024-09-05T21:41:44.603Z,1725572504.603 [CBIT](DEBUG): Deactivating emergency mode.
2024-09-05T21:41:44.643Z,1725572504.643 [CBIT](DEBUG): Backplane powered.
2024-09-05T21:41:44.643Z,1725572504.643 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser
2024-09-05T21:41:44.644Z,1725572504.644 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl
2024-09-05T21:41:44.644Z,1725572504.644 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl
2024-09-05T21:41:44.651Z,1725572504.651 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl
2024-09-05T21:41:44.721Z,1725572504.721 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into:
2024-09-05T21:41:44.725Z,1725572504.725 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2024-09-05T21:41:44.773Z,1725572504.773 [MissionManager](DEBUG):
# Copyright (c) 2024 MBARI
# MBARI Proprietary Information. Confidential. All Rights Reserved
# Unauthorized copying or distribution of this file via any medium is strictly
# prohibited.
#
# WARNING - This file contains information whose export is restricted by the
# Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as
# amended. Violations of these export laws are subject to severe civil and/or
# criminal penalties.
mission Startup {
behavior Guidance:GoToSurface {
run in progression
}
aggregate StartupSatComms {
run in sequence
readDatum {
timeout duration=P1M
Universal:latitude_fix
}
readDatum {
timeout duration=P1M
Universal:platform_communications
}
}
}
2024-09-05T21:41:44.774Z,1725572504.774 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl
2024-09-05T21:41:44.774Z,1725572504.774 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl
2024-09-05T21:41:44.779Z,1725572504.779 [DATMMP](INFO): Starting
2024-09-05T21:41:44.784Z,1725572504.784 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl
2024-09-05T21:41:44.975Z,1725572504.975 [Radio_Surface](INFO): Powering up
2024-09-05T21:41:45.031Z,1725572505.031 [DATMMP](INFO): Starting
2024-09-05T21:41:45.155Z,1725572505.155 [MissionManager](DEBUG): TethyslAPI: Missions/Default.tl translated into:
0
13
Burn on
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2024-09-05T21:41:45.180Z,1725572505.180 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2024-09-05T21:41:45.181Z,1725572505.181 [Default:A.Wait](DEBUG): Construct Wait.
2024-09-05T21:41:45.208Z,1725572505.208 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2024-09-05T21:41:45.262Z,1725572505.262 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2024-09-05T21:41:45.279Z,1725572505.279 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2024-09-05T21:41:45.283Z,1725572505.283 [DATMMP](INFO): Starting
2024-09-05T21:41:45.301Z,1725572505.301 [Default:E.Execute](DEBUG): Construct Execute.
2024-09-05T21:41:45.312Z,1725572505.312 [MissionManager](DEBUG):
# Copyright (c) 2024 MBARI
# MBARI Proprietary Information. Confidential. All Rights Reserved
# Unauthorized copying or distribution of this file via any medium is strictly
# prohibited.
#
# WARNING - This file contains information whose export is restricted by the
# Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as
# amended. Violations of these export laws are subject to severe civil and/or
# criminal penalties.
mission Default {
arguments {
ElapsedSinceDefaultStarted = 0 minute
}
behavior Guidance:Wait {
"""
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
"""
run in sequence
set duration = 13 second
}
behavior Guidance:GoToSurface {
run in progression
}
aggregate CheckIn {
run in sequence repeat=288
readDatum id="Read_GPS" {
timeout duration=P5M
Universal:time_fix
}
readDatum id="Read_Iridium" {
timeout duration=P4H {
behavior Guidance:Execute {
run in sequence
set command = "Burn on"
}
syslog critical "Dropped weight due to communications timeout."
}
Universal:platform_communications
}
behavior Guidance:Wait {
run in sequence
set duration = 5 minute
}
assign in sequence ElapsedSinceDefaultStarted = elapsed ( Universal:mission_started )
syslog important "Default mission has been running for " + ElapsedSinceDefaultStarted~minute
}
syslog important "Restarting logs and Default mission."
behavior Guidance:Execute {
run in sequence
set command = "restart logs"
}
}
2024-09-05T21:41:45.317Z,1725572505.317 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DVL_micro,NAL9602,Power24vConverter,Sonardyne_Nano,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2024-09-05T21:41:45.339Z,1725572505.339 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2024-09-05T21:41:45.488Z,1725572505.488 [Power24vConverter](INFO): Powering up.
2024-09-05T21:41:45.489Z,1725572505.489 [Sonardyne_Nano](INFO): Initializing.
2024-09-05T21:41:45.535Z,1725572505.535 [DATMMP](INFO): Starting
2024-09-05T21:41:45.544Z,1725572505.544 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2024-09-05T21:41:45.551Z,1725572505.551 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2024-09-05T21:41:45.552Z,1725572505.552 [ElevatorServo](DEBUG): Initializing EZServoServo.
2024-09-05T21:41:45.559Z,1725572505.559 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2024-09-05T21:41:45.560Z,1725572505.560 [MassServo](DEBUG): Initializing EZServoServo.
2024-09-05T21:41:45.567Z,1725572505.567 [MassServo](DEBUG): Initializing MassServo.
2024-09-05T21:41:45.568Z,1725572505.568 [RudderServo](DEBUG): Initializing EZServoServo.
2024-09-05T21:41:45.575Z,1725572505.575 [RudderServo](DEBUG): Initializing RudderServo.
2024-09-05T21:41:45.576Z,1725572505.576 [ThrusterHE](DEBUG): Initializing EZServoServo.
2024-09-05T21:41:45.583Z,1725572505.583 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2024-09-05T21:41:45.787Z,1725572505.787 [DATMMP](INFO): Starting
2024-09-05T21:41:46.039Z,1725572506.039 [DATMMP](INFO): Starting
2024-09-05T21:41:46.291Z,1725572506.291 [DATMMP](INFO): Starting
2024-09-05T21:41:46.543Z,1725572506.543 [DATMMP](INFO): Starting
2024-09-05T21:41:46.795Z,1725572506.795 [DATMMP](INFO): Starting
2024-09-05T21:41:47.047Z,1725572507.047 [DATMMP](INFO): Starting
2024-09-05T21:41:47.203Z,1725572507.203 [WetLabsBB2FL](INFO): Powering down
2024-09-05T21:41:47.299Z,1725572507.299 [DATMMP](INFO): Starting
2024-09-05T21:41:47.551Z,1725572507.551 [DATMMP](INFO): Starting
2024-09-05T21:41:47.749Z,1725572507.749 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART
2024-09-05T21:41:47.803Z,1725572507.803 [DATMMP](INFO): Starting
2024-09-05T21:41:48.055Z,1725572508.055 [DATMMP](INFO): Starting
2024-09-05T21:41:48.307Z,1725572508.307 [DATMMP](INFO): Starting
2024-09-05T21:41:48.559Z,1725572508.559 [DATMMP](INFO): Starting
2024-09-05T21:41:48.811Z,1725572508.811 [DATMMP](INFO): Starting
2024-09-05T21:41:48.987Z,1725572508.987 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2207
2024-09-05T21:41:49.063Z,1725572509.063 [DATMMP](INFO): Starting
2024-09-05T21:41:49.315Z,1725572509.315 [DATMMP](INFO): Starting
2024-09-05T21:41:49.567Z,1725572509.567 [DATMMP](INFO): Starting
2024-09-05T21:41:49.819Z,1725572509.819 [DATMMP](INFO): Starting
2024-09-05T21:41:50.071Z,1725572510.071 [DATMMP](INFO): Starting
2024-09-05T21:41:50.323Z,1725572510.323 [DATMMP](INFO): Starting
2024-09-05T21:41:50.575Z,1725572510.575 [DATMMP](INFO): Starting
2024-09-05T21:41:50.827Z,1725572510.827 [DATMMP](INFO): Starting
2024-09-05T21:41:51.079Z,1725572511.079 [DATMMP](INFO): Starting
2024-09-05T21:41:51.088Z,1725572511.088 [ThrusterHE](ERROR): Zero Speed Commanded.
2024-09-05T21:41:51.331Z,1725572511.331 [DATMMP](INFO): Starting
2024-09-05T21:41:51.583Z,1725572511.583 [DATMMP](INFO): Starting
2024-09-05T21:41:51.615Z,1725572511.615 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2024-09-05T21:41:51.835Z,1725572511.835 [DATMMP](INFO): Starting
2024-09-05T21:41:52.087Z,1725572512.087 [DATMMP](INFO): Starting
2024-09-05T21:41:52.339Z,1725572512.339 [DATMMP](INFO): Starting
2024-09-05T21:41:52.591Z,1725572512.591 [DATMMP](INFO): Starting
2024-09-05T21:41:52.843Z,1725572512.843 [DATMMP](INFO): Starting
2024-09-05T21:41:53.095Z,1725572513.095 [DATMMP](INFO): Starting
2024-09-05T21:41:53.347Z,1725572513.347 [DATMMP](INFO): Starting
2024-09-05T21:41:53.599Z,1725572513.599 [DATMMP](INFO): Starting
2024-09-05T21:41:53.851Z,1725572513.851 [DATMMP](INFO): Starting
2024-09-05T21:41:54.103Z,1725572514.103 [DATMMP](INFO): Starting
2024-09-05T21:41:54.355Z,1725572514.355 [DATMMP](INFO): Starting
2024-09-05T21:41:54.607Z,1725572514.607 [DATMMP](INFO): Starting
2024-09-05T21:41:54.859Z,1725572514.859 [DATMMP](INFO): Starting
2024-09-05T21:41:55.111Z,1725572515.111 [DATMMP](INFO): Starting
2024-09-05T21:41:55.363Z,1725572515.363 [DATMMP](INFO): Starting
2024-09-05T21:41:55.615Z,1725572515.615 [DATMMP](INFO): Starting
2024-09-05T21:41:55.867Z,1725572515.867 [DATMMP](INFO): Starting
2024-09-05T21:41:56.119Z,1725572516.119 [DATMMP](INFO): Starting
2024-09-05T21:41:56.371Z,1725572516.371 [DATMMP](INFO): Starting
2024-09-05T21:41:56.623Z,1725572516.623 [DATMMP](INFO): Starting
2024-09-05T21:41:56.624Z,1725572516.624 [DATMMP](INFO): DAT read:
2024-09-05T21:41:56.651Z,1725572516.651 [DATMMP](INFO): DAT read: Teledyne Benthos DAT-900 Series
2024-09-05T21:41:56.875Z,1725572516.875 [DATMMP](INFO): Starting
2024-09-05T21:41:57.127Z,1725572517.127 [DATMMP](INFO): Starting
2024-09-05T21:41:57.379Z,1725572517.379 [DATMMP](INFO): Starting
2024-09-05T21:41:57.631Z,1725572517.631 [DATMMP](INFO): Starting
2024-09-05T21:41:57.883Z,1725572517.883 [DATMMP](INFO): Starting
2024-09-05T21:41:58.135Z,1725572518.135 [DATMMP](INFO): Starting
2024-09-05T21:41:58.387Z,1725572518.387 [DATMMP](INFO): Starting
2024-09-05T21:41:58.387Z,1725572518.387 [DATMMP](INFO): DAT read: MF Frequency Band
2024-09-05T21:41:58.388Z,1725572518.388 [DATMMP](INFO): DAT read: Directional Acoustic Transponder version 8.15.0
2024-09-05T21:41:58.389Z,1725572518.389 [DATMMP](INFO): DAT read: Aug 5 2000 21:41:52
2024-09-05T21:41:58.639Z,1725572518.639 [DATMMP](INFO): Starting
2024-09-05T21:41:58.891Z,1725572518.891 [DATMMP](INFO): Starting
2024-09-05T21:41:59.143Z,1725572519.143 [DATMMP](INFO): Starting
2024-09-05T21:41:59.395Z,1725572519.395 [DATMMP](INFO): Starting
2024-09-05T21:41:59.396Z,1725572519.396 [DATMMP](INFO): DAT read: Features enabled [Bearing]
2024-09-05T21:41:59.397Z,1725572519.397 [DATMMP](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP
2024-09-05T21:41:59.397Z,1725572519.397 [DATMMP](INFO): commRate: 800
2024-09-05T21:41:59.647Z,1725572519.647 [DATMMP](INFO): Starting
2024-09-05T21:41:59.899Z,1725572519.899 [DATMMP](INFO): Starting
2024-09-05T21:42:00.151Z,1725572520.151 [DATMMP](INFO): Starting
2024-09-05T21:42:00.403Z,1725572520.403 [DATMMP](INFO): Starting
2024-09-05T21:42:00.655Z,1725572520.655 [DATMMP](INFO): Starting
2024-09-05T21:42:00.907Z,1725572520.907 [DATMMP](INFO): Starting
2024-09-05T21:42:01.159Z,1725572521.159 [DATMMP](INFO): Starting
2024-09-05T21:42:01.411Z,1725572521.411 [DATMMP](INFO): Starting
2024-09-05T21:42:01.463Z,1725572521.463 [DATMMP](INFO): entering command mode
2024-09-05T21:42:01.663Z,1725572521.663 [DATMMP](INFO): Starting
2024-09-05T21:42:01.663Z,1725572521.663 [DATMMP](INFO): DAT read:
2024-09-05T21:42:01.663Z,1725572521.663 [DATMMP](INFO): DAT read: user:1>
2024-09-05T21:42:01.664Z,1725572521.664 [DATMMP](DEBUG): read user prompt 1: user:1>
2024-09-05T21:42:01.664Z,1725572521.664 [DATMMP](INFO): entering MMP mode
2024-09-05T21:42:01.915Z,1725572521.915 [DATMMP](INFO): Starting
2024-09-05T21:42:01.915Z,1725572521.915 [DATMMP](INFO): GSXN notify for xid: 0
2024-09-05T21:42:01.917Z,1725572521.917 [DATMMP](INFO): status rx: x1
2024-09-05T21:42:01.917Z,1725572521.917 [DATMMP](INFO): MMP status: 1: started
2024-09-05T21:42:01.918Z,1725572521.918 [DATMMP](INFO): Received message type: status
2024-09-05T21:42:01.918Z,1725572521.918 [DATMMP](INFO): Handled
2024-09-05T21:42:02.167Z,1725572522.167 [DATMMP](INFO): Starting
2024-09-05T21:42:02.168Z,1725572522.168 [DATMMP](INFO): Sent Tx Power Config 8
2024-09-05T21:42:02.168Z,1725572522.168 [DATMMP](INFO): Setting local address: 11
2024-09-05T21:42:02.170Z,1725572522.170 [DATMMP](INFO): Setting time to: 21:42:2 And date to:9/5/2024
2024-09-05T21:42:02.419Z,1725572522.419 [DATMMP](INFO): Starting
2024-09-05T21:42:02.419Z,1725572522.419 [DATMMP](INFO): GSXN notify for xid: 0
2024-09-05T21:42:02.420Z,1725572522.420 [DATMMP](INFO): mdmpower rx: x8 x0 x5 x0
2024-09-05T21:42:02.420Z,1725572522.420 [DATMMP](INFO): Received message type: mdmpower
2024-09-05T21:42:02.420Z,1725572522.420 [DATMMP](INFO): Handled
2024-09-05T21:42:02.671Z,1725572522.671 [DATMMP](INFO): Starting
2024-09-05T21:42:02.671Z,1725572522.671 [DATMMP](INFO): GSXN notify for xid: 10
2024-09-05T21:42:02.672Z,1725572522.672 [DATMMP](INFO): sreg_txpower rx: x8
2024-09-05T21:42:02.672Z,1725572522.672 [DATMMP](INFO): Received message type: sreg_txpower
2024-09-05T21:42:02.672Z,1725572522.672 [DATMMP](INFO): Match for : sreg_txpower
2024-09-05T21:42:02.672Z,1725572522.672 [DATMMP](INFO): ACK
2024-09-05T21:42:02.923Z,1725572522.923 [DATMMP](INFO): Starting
2024-09-05T21:42:02.923Z,1725572522.923 [DATMMP](INFO): GSXN notify for xid: 0
2024-09-05T21:42:02.924Z,1725572522.924 [DATMMP](INFO): mdmlocal rx: xB x0 x0 x0
2024-09-05T21:42:02.924Z,1725572522.924 [DATMMP](INFO): Received message type: mdmlocal
2024-09-05T21:42:02.924Z,1725572522.924 [DATMMP](INFO): Handled
2024-09-05T21:42:03.175Z,1725572523.175 [DATMMP](INFO): Starting
2024-09-05T21:42:03.176Z,1725572523.176 [DATMMP](INFO): GSXN notify for xid: 11
2024-09-05T21:42:03.177Z,1725572523.177 [DATMMP](INFO): sreg_locaddr rx: xB
2024-09-05T21:42:03.177Z,1725572523.177 [DATMMP](INFO): Received message type: sreg_locaddr
2024-09-05T21:42:03.177Z,1725572523.177 [DATMMP](INFO): Match for : sreg_locaddr
2024-09-05T21:42:03.178Z,1725572523.178 [DATMMP](INFO): ACK
2024-09-05T21:42:03.427Z,1725572523.427 [DATMMP](INFO): Starting
2024-09-05T21:42:03.427Z,1725572523.427 [DATMMP](INFO): GSXN notify for xid: 12
2024-09-05T21:42:03.428Z,1725572523.428 [DATMMP](INFO): timedate rx: x0 x15 x2A x2 x8 x5 x7C x0
2024-09-05T21:42:03.428Z,1725572523.428 [DATMMP](INFO): Received message type: timedate
2024-09-05T21:42:03.428Z,1725572523.428 [DATMMP](INFO): Match for : timedate
2024-09-05T21:42:03.429Z,1725572523.429 [DATMMP](INFO): ACK
2024-09-05T21:42:03.679Z,1725572523.679 [DATMMP](INFO): Starting
2024-09-05T21:42:03.679Z,1725572523.679 [DATMMP](INFO): GSXN notify for xid: 0
2024-09-05T21:42:03.680Z,1725572523.680 [DATMMP](INFO): sys_verb rx: x0 x0 x0 x0
2024-09-05T21:42:03.680Z,1725572523.680 [DATMMP](INFO): Received message type: sys_verb
2024-09-05T21:42:03.680Z,1725572523.680 [DATMMP](INFO): Handled
2024-09-05T21:42:03.931Z,1725572523.931 [DATMMP](INFO): Starting
2024-09-05T21:42:03.931Z,1725572523.931 [DATMMP](INFO): GSXN notify for xid: 13
2024-09-05T21:42:03.932Z,1725572523.932 [DATMMP](INFO): sreg_verbosity rx: x0
2024-09-05T21:42:03.932Z,1725572523.932 [DATMMP](INFO): Received message type: sreg_verbosity
2024-09-05T21:42:03.932Z,1725572523.932 [DATMMP](INFO): Match for : sreg_verbosity
2024-09-05T21:42:03.932Z,1725572523.932 [DATMMP](INFO): ACK
2024-09-05T21:42:04.183Z,1725572524.183 [DATMMP](INFO): Starting
2024-09-05T21:42:04.183Z,1725572524.183 [DATMMP](INFO): GSXN notify for xid: 14
2024-09-05T21:42:04.184Z,1725572524.184 [DATMMP](INFO): version rx: x2 x5
2024-09-05T21:42:04.184Z,1725572524.184 [DATMMP](INFO): DatMMPVersion: 2.5
2024-09-05T21:42:04.184Z,1725572524.184 [DATMMP](INFO): Received message type: version
2024-09-05T21:42:04.184Z,1725572524.184 [DATMMP](INFO): Match for : version
2024-09-05T21:42:04.185Z,1725572524.185 [DATMMP](INFO): ACK
2024-09-05T21:42:04.185Z,1725572524.185 [DATMMP](INFO): in MMP mode: config complete going to runnable
2024-09-05T21:42:13.205Z,1725572533.205 [NAL9602](INFO): Powering up NAL9602
2024-09-05T21:42:17.543Z,1725572537.543 [DATMMP](INFO): GSXN notify for xid: 0
2024-09-05T21:42:17.544Z,1725572537.544 [DATMMP](INFO): timesync rx: x0 x1 x1 x0
2024-09-05T21:42:17.544Z,1725572537.544 [DATMMP](INFO): Received message type: timesync
2024-09-05T21:42:17.544Z,1725572537.544 [DATMMP](INFO): Handled
2024-09-05T21:42:24.117Z,1725572544.117 [NAL9602](INFO): NAL9602 initialized
2024-09-05T21:42:27.372Z,1725572547.372 [DATMMP](INFO): GSXN notify for xid: 0
2024-09-05T21:42:27.372Z,1725572547.372 [DATMMP](INFO): timesync rx: x1 x0 x1 x0
2024-09-05T21:42:27.373Z,1725572547.373 [DATMMP](INFO): Received message type: timesync
2024-09-05T21:42:27.373Z,1725572547.373 [DATMMP](INFO): Handled
2024-09-05T21:43:53.010Z,1725572633.010 [SBIT](IMPORTANT): Beginning Startup BIT
2024-09-05T21:43:53.014Z,1725572633.014 [CBIT](IMPORTANT): Beginning ground fault scan
2024-09-05T21:44:03.950Z,1725572643.950 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.030002
CHAN A1 (24V): 0.021409
CHAN A2 (12V): -0.013977
CHAN A3 (5V): -0.022042
CHAN B0 (3.3V): -0.009711
CHAN B1 (3.15aV): -0.005299
CHAN B2 (3.15bV): -0.002289
CHAN B3 (GND): -0.009577
OPEN: -0.000941
Full Scale: +/- 1 mA
2024-09-05T21:44:30.460Z,1725572670.460 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004162
2024-09-05T21:44:44.764Z,1725572684.764 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2024-09-05T21:44:44.764Z,1725572684.764 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-09-05T21:44:44.781Z,1725572684.781 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-09-05T21:44:45.133Z,1725572685.133 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-09-05T21:44:45.133Z,1725572685.133 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2024-09-05T21:44:47.246Z,1725572687.246 [SBIT](IMPORTANT): SBIT PASSED
2024-09-05T21:44:47.247Z,1725572687.247 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2024-09-05T21:44:47.247Z,1725572687.247 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool;
2024-09-05T21:44:47.247Z,1725572687.247 [SBIT](IMPORTANT): DATMMP.loadAtStartup=1 bool;
2024-09-05T21:44:47.248Z,1725572687.248 [SBIT](IMPORTANT): DATMMP.simulateHardware=0 bool;
2024-09-05T21:44:47.248Z,1725572687.248 [SBIT](IMPORTANT): Depth_Keller.offset=3.6 decibar;
2024-09-05T21:44:47.248Z,1725572687.248 [SBIT](IMPORTANT): DropWeight.loadAtStartup=0 bool;
2024-09-05T21:44:47.248Z,1725572687.248 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=3 minute;
2024-09-05T21:44:47.248Z,1725572687.248 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=186.137647 cubic_centimeter;
2024-09-05T21:44:47.248Z,1725572687.248 [SBIT](IMPORTANT): VerticalControl.massDefault=27.004010 millimeter;
2024-09-05T21:44:47.586Z,1725572687.586 [MissionManager](IMPORTANT): Started mission Startup
2024-09-05T21:44:47.586Z,1725572687.586 [Startup] Running Loop=1
2024-09-05T21:44:47.587Z,1725572687.587 [Startup](DEBUG): Aggregate::initialize Startup
2024-09-05T21:44:47.587Z,1725572687.587 [Startup:A.GoToSurface] Running Loop=1
2024-09-05T21:44:47.587Z,1725572687.587 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2024-09-05T21:44:47.587Z,1725572687.587 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2024-09-05T21:44:47.588Z,1725572687.588 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2024-09-05T21:44:47.588Z,1725572687.588 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2024-09-05T21:44:47.588Z,1725572687.588 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2024-09-05T21:44:47.589Z,1725572687.589 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2024-09-05T21:44:47.589Z,1725572687.589 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2024-09-05T21:44:47.591Z,1725572687.591 [Startup:StartupSatComms] Running Loop=1
2024-09-05T21:44:47.592Z,1725572687.592 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2024-09-05T21:44:47.592Z,1725572687.592 [Startup:StartupSatComms:A] Running Loop=1
2024-09-05T21:44:47.981Z,1725572687.981 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2024-09-05T21:45:35.210Z,1725572735.210 [NAL9602](INFO): SBD MO Status=0, MOMSN=21570, MT Status=0, MTMSN=0
2024-09-05T21:45:35.210Z,1725572735.210 [NAL9602](INFO): No messages in MT queue
2024-09-05T21:45:36.426Z,1725572736.426 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214532.00,A,3648.14267,N,12147.22480,W,0.019,0.00,050924,,,D*7A
2024-09-05T21:45:36.429Z,1725572736.429 [NAL9602](INFO): GPS fix at 20240905T214532: (36.802378, -121.787080)
2024-09-05T21:45:36.441Z,1725572736.441 [Startup:StartupSatComms:A] Stopped
2024-09-05T21:45:36.441Z,1725572736.441 [Startup:StartupSatComms:B] Running Loop=1
2024-09-05T21:45:36.855Z,1725572736.855 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2024-09-05T21:45:46.083Z,1725572746.083 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20240905T194139/Courier0067.lzma
2024-09-05T21:45:47.085Z,1725572747.085 [DataOverHttps](INFO): Moved sent file to Logs/20240905T194139/Courier0067.lzma.bak
2024-09-05T21:45:47.085Z,1725572747.085 [DataOverHttps](INFO): SBD MOMSN=23132239
2024-09-05T21:46:04.039Z,1725572764.039 [DataOverHttps](INFO): Sending 267 bytes from file Logs/20240905T214131/Courier0000.lzma
2024-09-05T21:46:05.040Z,1725572765.040 [DataOverHttps](INFO): Moved sent file to Logs/20240905T214131/Courier0000.lzma.bak
2024-09-05T21:46:05.041Z,1725572765.041 [DataOverHttps](INFO): SBD MOMSN=23132241
2024-09-05T21:46:08.764Z,1725572768.764 [NAL9602](INFO): Not Powering down - fast GPS
2024-09-05T21:46:20.973Z,1725572780.973 [DataOverHttps](INFO): Sending 183 bytes from file Logs/20240905T194139/Express0068.lzma
2024-09-05T21:46:21.973Z,1725572781.973 [DataOverHttps](INFO): Moved sent file to Logs/20240905T194139/Express0068.lzma.bak
2024-09-05T21:46:21.973Z,1725572781.973 [DataOverHttps](INFO): SBD MOMSN=23132246
2024-09-05T21:46:36.681Z,1725572796.681 [Startup:StartupSatComms:B](INFO): Timed out from 2024-09-05T21:45:36.4Z
2024-09-05T21:46:36.682Z,1725572796.682 [Startup:StartupSatComms:B] Stopped
2024-09-05T21:46:36.682Z,1725572796.682 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2024-09-05T21:46:36.682Z,1725572796.682 [Startup:StartupSatComms] Stopped
2024-09-05T21:46:36.682Z,1725572796.682 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2024-09-05T21:46:36.687Z,1725572796.687 [Startup](INFO): Completed Startup
2024-09-05T21:46:36.687Z,1725572796.687 [MissionManager](INFO): Startup is completed.
2024-09-05T21:46:36.687Z,1725572796.687 [MissionManager](INFO): Uninitializing Mission Startup
2024-09-05T21:46:36.687Z,1725572796.687 [Startup] Stopped
2024-09-05T21:46:36.688Z,1725572796.688 [Startup](DEBUG): Aggregate::uninitialize Startup
2024-09-05T21:46:36.688Z,1725572796.688 [Startup:A.GoToSurface] Stopped
2024-09-05T21:46:36.688Z,1725572796.688 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2024-09-05T21:46:37.110Z,1725572797.110 [MissionManager](IMPORTANT): Started mission Default
2024-09-05T21:46:37.115Z,1725572797.115 [Default] Running Loop=1
2024-09-05T21:46:37.115Z,1725572797.115 [Default](DEBUG): Aggregate::initialize Default
2024-09-05T21:46:37.115Z,1725572797.115 [Default:B.GoToSurface] Running Loop=1
2024-09-05T21:46:37.115Z,1725572797.115 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2024-09-05T21:46:37.115Z,1725572797.115 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2024-09-05T21:46:37.115Z,1725572797.115 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2024-09-05T21:46:37.116Z,1725572797.116 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2024-09-05T21:46:37.116Z,1725572797.116 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2024-09-05T21:46:37.116Z,1725572797.116 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2024-09-05T21:46:37.117Z,1725572797.117 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2024-09-05T21:46:37.117Z,1725572797.117 [Default:A.Wait] Running Loop=1
2024-09-05T21:46:37.117Z,1725572797.117 [Default:A.Wait](DEBUG): Initialize Wait Component.
2024-09-05T21:46:38.380Z,1725572798.380 [DataOverHttps](INFO): Sending 935 bytes from file Logs/20240905T214131/Express0001.lzma
2024-09-05T21:46:39.384Z,1725572799.384 [DataOverHttps](INFO): Moved sent file to Logs/20240905T214131/Express0001.lzma.bak
2024-09-05T21:46:39.384Z,1725572799.384 [DataOverHttps](INFO): SBD MOMSN=23132252
2024-09-05T21:46:50.395Z,1725572810.395 [Default:A.Wait](INFO): Done Waiting.
2024-09-05T21:46:50.395Z,1725572810.395 [Default:A.Wait] Stopped
2024-09-05T21:46:50.395Z,1725572810.395 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2024-09-05T21:46:50.795Z,1725572810.795 [Default:CheckIn] Running Loop=1
2024-09-05T21:46:50.795Z,1725572810.795 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-05T21:46:50.795Z,1725572810.795 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-05T21:46:51.209Z,1725572811.209 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2024-09-05T21:46:52.805Z,1725572812.805 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214649.00,A,3648.14057,N,12147.22550,W,0.039,0.00,050924,,,D*7A
2024-09-05T21:46:52.816Z,1725572812.816 [NAL9602](INFO): GPS fix at 20240905T214649: (36.802343, -121.787092)
2024-09-05T21:46:52.828Z,1725572812.828 [Default:CheckIn:Read_GPS] Stopped
2024-09-05T21:46:52.828Z,1725572812.828 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-05T21:46:53.244Z,1725572813.244 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2024-09-05T21:47:00.382Z,1725572820.382 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20240905T214131/Courier0004.lzma
2024-09-05T21:47:01.384Z,1725572821.384 [DataOverHttps](INFO): Moved sent file to Logs/20240905T214131/Courier0004.lzma.bak
2024-09-05T21:47:01.384Z,1725572821.384 [DataOverHttps](INFO): SBD MOMSN=23132282
2024-09-05T21:47:17.306Z,1725572837.306 [DataOverHttps](INFO): Sending 104 bytes from file Logs/20240905T214131/Express0005.lzma
2024-09-05T21:47:18.308Z,1725572838.308 [DataOverHttps](INFO): Moved sent file to Logs/20240905T214131/Express0005.lzma.bak
2024-09-05T21:47:18.309Z,1725572838.309 [DataOverHttps](INFO): SBD MOMSN=23132285
2024-09-05T21:47:19.487Z,1725572839.487 [Default:CheckIn:Read_Iridium] Stopped
2024-09-05T21:47:19.487Z,1725572839.487 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-05T21:47:19.487Z,1725572839.487 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-05T21:48:35.833Z,1725572915.833 [NAL9602](INFO): SBD MO Status=2, MOMSN=21571, MT Status=2, MTMSN=0
2024-09-05T21:48:35.833Z,1725572915.833 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2024-09-05T21:50:11.993Z,1725573011.993 [BPC1](INFO): Calculating totals. Valid battery stick count: 35. Valid reserve battery stick count: 3.
2024-09-05T21:50:11.997Z,1725573011.997 [BPC1](INFO): Received data from all battery sticks.
2024-09-05T21:51:55.434Z,1725573115.434 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2024-09-05T21:52:20.096Z,1725573140.096 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-05T21:52:20.096Z,1725573140.096 [Default:CheckIn:C.Wait] Stopped
2024-09-05T21:52:20.096Z,1725573140.096 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-05T21:52:20.096Z,1725573140.096 [Default:CheckIn:D] Running Loop=1
2024-09-05T21:52:20.474Z,1725573140.474 [Default:CheckIn:D] Stopped
2024-09-05T21:52:20.474Z,1725573140.474 [Default:CheckIn:E] Running Loop=1
2024-09-05T21:52:20.878Z,1725573140.878 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 5.722722 min
2024-09-05T21:52:20.878Z,1725573140.878 [Default:CheckIn:E] Stopped
2024-09-05T21:52:20.879Z,1725573140.879 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-05T21:52:20.879Z,1725573140.879 [Default:CheckIn] Stopped
2024-09-05T21:52:20.879Z,1725573140.879 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-05T21:52:20.879Z,1725573140.879 [Default:CheckIn](INFO): Running loop #2
2024-09-05T21:52:20.879Z,1725573140.879 [Default:CheckIn] Running Loop=2
2024-09-05T21:52:20.879Z,1725573140.879 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-05T21:52:20.879Z,1725573140.879 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-05T21:52:22.890Z,1725573142.890 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215222.00,A,3648.14194,N,12147.23087,W,0.039,0.00,050924,,,D*72
2024-09-05T21:52:22.898Z,1725573142.898 [NAL9602](INFO): GPS fix at 20240905T215222: (36.802366, -121.787181)
2024-09-05T21:52:22.909Z,1725573142.909 [Default:CheckIn:Read_GPS] Stopped
2024-09-05T21:52:22.909Z,1725573142.909 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-05T21:52:30.243Z,1725573150.243 [DataOverHttps](INFO): Sending 203 bytes from file Logs/20240905T214131/Courier0007.lzma
2024-09-05T21:52:31.244Z,1725573151.244 [DataOverHttps](INFO): Moved sent file to Logs/20240905T214131/Courier0007.lzma.bak
2024-09-05T21:52:31.245Z,1725573151.245 [DataOverHttps](INFO): SBD MOMSN=23132340
2024-09-05T21:52:47.123Z,1725573167.123 [DataOverHttps](INFO): Sending 247 bytes from file Logs/20240905T214131/Express0008.lzma
2024-09-05T21:52:48.124Z,1725573168.124 [DataOverHttps](INFO): Moved sent file to Logs/20240905T214131/Express0008.lzma.bak
2024-09-05T21:52:48.124Z,1725573168.124 [DataOverHttps](INFO): SBD MOMSN=23132343
2024-09-05T21:52:49.191Z,1725573169.191 [Default:CheckIn:Read_Iridium] Stopped
2024-09-05T21:52:49.191Z,1725573169.191 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-05T21:52:49.191Z,1725573169.191 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-05T21:52:55.608Z,1725573175.608 [NAL9602](INFO): Not Powering down - fast GPS
2024-09-05T21:57:49.746Z,1725573469.746 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-05T21:57:49.746Z,1725573469.746 [Default:CheckIn:C.Wait] Stopped
2024-09-05T21:57:49.746Z,1725573469.746 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-05T21:57:49.762Z,1725573469.762 [Default:CheckIn:D] Running Loop=1
2024-09-05T21:57:50.147Z,1725573470.147 [Default:CheckIn:D] Stopped
2024-09-05T21:57:50.147Z,1725573470.147 [Default:CheckIn:E] Running Loop=1
2024-09-05T21:57:50.552Z,1725573470.552 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.217265 min
2024-09-05T21:57:50.552Z,1725573470.552 [Default:CheckIn:E] Stopped
2024-09-05T21:57:50.552Z,1725573470.552 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-05T21:57:50.552Z,1725573470.552 [Default:CheckIn] Stopped
2024-09-05T21:57:50.552Z,1725573470.552 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-05T21:57:50.552Z,1725573470.552 [Default:CheckIn](INFO): Running loop #3
2024-09-05T21:57:50.552Z,1725573470.552 [Default:CheckIn] Running Loop=3
2024-09-05T21:57:50.552Z,1725573470.552 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-05T21:57:50.552Z,1725573470.552 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-05T21:57:52.562Z,1725573472.562 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215751.00,A,3648.14072,N,12147.22816,W,0.019,0.00,050924,,,D*79
2024-09-05T21:57:52.576Z,1725573472.576 [NAL9602](INFO): GPS fix at 20240905T215751: (36.802345, -121.787136)
2024-09-05T21:57:52.596Z,1725573472.596 [Default:CheckIn:Read_GPS] Stopped
2024-09-05T21:57:52.596Z,1725573472.596 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-05T21:57:59.586Z,1725573479.586 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20240905T214131/Courier0010.lzma
2024-09-05T21:58:00.589Z,1725573480.589 [DataOverHttps](INFO): Moved sent file to Logs/20240905T214131/Courier0010.lzma.bak
2024-09-05T21:58:00.589Z,1725573480.589 [DataOverHttps](INFO): SBD MOMSN=23132369
2024-09-05T21:58:18.082Z,1725573498.082 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20240905T214131/Express0011.lzma
2024-09-05T21:58:19.084Z,1725573499.084 [DataOverHttps](INFO): Moved sent file to Logs/20240905T214131/Express0011.lzma.bak
2024-09-05T21:58:19.085Z,1725573499.085 [DataOverHttps](INFO): SBD MOMSN=23132372
2024-09-05T21:58:20.466Z,1725573500.466 [Default:CheckIn:Read_Iridium] Stopped
2024-09-05T21:58:20.466Z,1725573500.466 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-05T21:58:20.485Z,1725573500.485 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-05T21:58:23.276Z,1725573503.276 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2024-09-05T21:58:23.351Z,1725573503.351 [NAL9602](ERROR): received:
+CSQ:0
OK571, 2, 0, 0, 0
OK
2024-09-05T22:00:24.903Z,1725573624.903 [NAL9602](INFO): SBD MO Status=2, MOMSN=21571, MT Status=2, MTMSN=0
2024-09-05T22:00:24.903Z,1725573624.903 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2024-09-05T22:00:53.177Z,1725573653.177 [NAL9602](INFO): SBD MO Status=2, MOMSN=21571, MT Status=2, MTMSN=0
2024-09-05T22:00:53.177Z,1725573653.177 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2024-09-05T22:01:14.988Z,1725573674.988 [NAL9602](INFO): SBD MO Status=2, MOMSN=21571, MT Status=2, MTMSN=0
2024-09-05T22:01:14.988Z,1725573674.988 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2024-09-05T22:02:01.944Z,1725573721.944 [DataOverHttps](IMPORTANT): SBD MTMSN=20240905T220200
2024-09-05T22:02:09.507Z,1725573729.507 [DataOverHttps](INFO): Received command: schedule resume
2024-09-05T22:02:09.573Z,1725573729.573 [CommandExec](IMPORTANT): got command schedule resume
2024-09-05T22:02:54.384Z,1725573774.384 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2024-09-05T22:03:21.046Z,1725573801.046 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-05T22:03:21.046Z,1725573801.046 [Default:CheckIn:C.Wait] Stopped
2024-09-05T22:03:21.046Z,1725573801.046 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-05T22:03:21.046Z,1725573801.046 [Default:CheckIn:D] Running Loop=1
2024-09-05T22:03:21.461Z,1725573801.461 [Default:CheckIn:D] Stopped
2024-09-05T22:03:21.461Z,1725573801.461 [Default:CheckIn:E] Running Loop=1
2024-09-05T22:03:21.858Z,1725573801.858 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 16.739175 min
2024-09-05T22:03:21.859Z,1725573801.859 [Default:CheckIn:E] Stopped
2024-09-05T22:03:21.859Z,1725573801.859 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-05T22:03:21.859Z,1725573801.859 [Default:CheckIn] Stopped
2024-09-05T22:03:21.859Z,1725573801.859 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-05T22:03:21.859Z,1725573801.859 [Default:CheckIn](INFO): Running loop #4
2024-09-05T22:03:21.859Z,1725573801.859 [Default:CheckIn] Running Loop=4
2024-09-05T22:03:21.859Z,1725573801.859 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-05T22:03:21.859Z,1725573801.859 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-05T22:03:23.864Z,1725573803.864 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220323.00,A,3648.14136,N,12147.22855,W,0.058,0.00,050924,,,D*7D
2024-09-05T22:03:23.866Z,1725573803.866 [NAL9602](INFO): GPS fix at 20240905T220323: (36.802356, -121.787143)
2024-09-05T22:03:23.877Z,1725573803.877 [Default:CheckIn:Read_GPS] Stopped
2024-09-05T22:03:23.878Z,1725573803.878 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-05T22:03:31.054Z,1725573811.054 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20240905T214131/Courier0013.lzma
2024-09-05T22:03:32.056Z,1725573812.056 [DataOverHttps](INFO): Moved sent file to Logs/20240905T214131/Courier0013.lzma.bak
2024-09-05T22:03:32.057Z,1725573812.057 [DataOverHttps](INFO): SBD MOMSN=23132397
2024-09-05T22:03:48.163Z,1725573828.163 [DataOverHttps](INFO): Sending 310 bytes from file Logs/20240905T214131/Express0014.lzma
2024-09-05T22:03:49.165Z,1725573829.165 [DataOverHttps](INFO): Moved sent file to Logs/20240905T214131/Express0014.lzma.bak
2024-09-05T22:03:49.166Z,1725573829.166 [DataOverHttps](INFO): SBD MOMSN=23132407
2024-09-05T22:03:56.588Z,1725573836.588 [NAL9602](INFO): Not Powering down - fast GPS
2024-09-05T22:03:57.608Z,1725573837.608 [DataOverHttps](IMPORTANT): SBD MTMSN=20240905T220356
2024-09-05T22:04:05.020Z,1725573845.020 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20240905T214131/Express0017.lzma
2024-09-05T22:04:05.024Z,1725573845.024 [DataOverHttps](INFO): Received command: load Transport/transit.tl;set transit.NeedCommsTime 15 min;set transit.Latitude 36.797 degree;set transit.Longitude -121.847 degree;run
2024-09-05T22:04:05.091Z,1725573845.091 [CommandExec](IMPORTANT): got command load ./Missions/Transport/transit.tl
2024-09-05T22:04:05.091Z,1725573845.091 [MissionManager](INFO): Loading Mission from file: ./Missions/Transport/transit.tl
2024-09-05T22:04:05.091Z,1725573845.091 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Transport/transit.tl
2024-09-05T22:04:05.095Z,1725573845.095 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Transport/transit.tl
2024-09-05T22:04:05.816Z,1725573845.816 [MissionManager](DEBUG): TethyslAPI: ./Missions/Transport/transit.tl translated into:
60
30
NaN
NaN
0
0
10
1
20
1
7
1
2024-09-05T22:04:05.822Z,1725573845.822 [MissionManager](INFO): DefineArg transit.MissionTimeout = 60.000000 min
2024-09-05T22:04:05.825Z,1725573845.825 [MissionManager](INFO): DefineArg transit.NeedCommsTime = 30.000000 min
2024-09-05T22:04:05.828Z,1725573845.828 [MissionManager](INFO): DefineArg transit.Latitude = nan arcdeg
2024-09-05T22:04:05.831Z,1725573845.831 [MissionManager](INFO): DefineArg transit.Longitude = nan arcdeg
2024-09-05T22:04:05.834Z,1725573845.834 [MissionManager](INFO): DefineArg transit.Northings = 0.000000 m
2024-09-05T22:04:05.837Z,1725573845.837 [MissionManager](INFO): DefineArg transit.Eastings = 0.000000 m
2024-09-05T22:04:05.840Z,1725573845.840 [MissionManager](INFO): DefineArg transit.Depth = 10.000000 m
2024-09-05T22:04:05.843Z,1725573845.843 [MissionManager](INFO): DefineArg transit.Speed = 1.000000 m/s
2024-09-05T22:04:05.845Z,1725573845.845 [MissionManager](INFO): DefineArg transit.MaxDepth = 20.000000 m
2024-09-05T22:04:05.848Z,1725573845.848 [MissionManager](INFO): DefineArg transit.MinOffshore = 1.000000 km
2024-09-05T22:04:05.851Z,1725573845.851 [MissionManager](INFO): DefineArg transit.MinAltitude = 7.000000 m
2024-09-05T22:04:05.853Z,1725573845.853 [MissionManager](INFO): DefineArg transit.MassHold = 1 bool
2024-09-05T22:04:05.856Z,1725573845.856 [MissionManager](INFO): DefineArg transit.BuoyancyHold = 1 bool
2024-09-05T22:04:05.856Z,1725573845.856 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/NeedComms.tl
2024-09-05T22:04:05.857Z,1725573845.857 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/NeedComms.tl
2024-09-05T22:04:05.858Z,1725573845.858 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/NeedComms.tl
2024-09-05T22:04:06.455Z,1725573846.455 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/NeedComms.tl translated into:
1
10
20
NaN
1
1000
7
30
0
last time_fix was:
first GPS update timeout
Comms timed out after
minutes
second GPS update timeout
2024-09-05T22:04:06.465Z,1725573846.465 [MissionManager](INFO): DefineArg transit:NeedComms.DiveInterval = 1.000000 h
2024-09-05T22:04:06.472Z,1725573846.472 [MissionManager](INFO): DefineArg transit:NeedComms.WaitForPitchUp = 10.000000 min
2024-09-05T22:04:06.503Z,1725573846.503 [MissionManager](INFO): DefineArg transit:NeedComms.SurfacePitch = 20.000000 arcdeg
2024-09-05T22:04:06.506Z,1725573846.506 [MissionManager](INFO): DefineArg transit:NeedComms.SurfaceDepthRate = nan m/s
2024-09-05T22:04:06.517Z,1725573846.517 [MissionManager](INFO): DefineArg transit:NeedComms.SurfaceSpeed = 1.000000 m/s
2024-09-05T22:04:06.543Z,1725573846.543 [MissionManager](INFO): DefineArg transit:NeedComms.SurfacingTimeout = 1000.000000 s
2024-09-05T22:04:06.546Z,1725573846.546 [MissionManager](INFO): DefineArg transit:NeedComms.GPSTimeout = 7.000000 min
2024-09-05T22:04:06.550Z,1725573846.550 [DataOverHttps](INFO): Moved sent file to Logs/20240905T214131/Express0017.lzma.bak
2024-09-05T22:04:06.558Z,1725573846.558 [DataOverHttps](INFO): SBD MOMSN=23132416
2024-09-05T22:04:06.572Z,1725573846.572 [MissionManager](INFO): DefineArg transit:NeedComms.CommsTimeout = 30.000000 min
2024-09-05T22:04:06.588Z,1725573846.588 [transit:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface.
2024-09-05T22:04:06.635Z,1725573846.635 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/StandardEnvelopes.tl
2024-09-05T22:04:06.635Z,1725573846.635 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/StandardEnvelopes.tl
2024-09-05T22:04:06.636Z,1725573846.636 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/StandardEnvelopes.tl
2024-09-05T22:04:06.836Z,1725573846.836 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/StandardEnvelopes.tl translated into:
5
0
200
2000
2024-09-05T22:04:06.845Z,1725573846.845 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MinAltitude = 5.000000 m
2024-09-05T22:04:06.848Z,1725573846.848 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MaxDepthIgnore = 0.000000 m
2024-09-05T22:04:06.859Z,1725573846.859 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MaxDepth = 200.000000 m
2024-09-05T22:04:06.862Z,1725573846.862 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MinOffshore = 2000.000000 m
2024-09-05T22:04:06.867Z,1725573846.867 [transit:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2024-09-05T22:04:06.888Z,1725573846.888 [transit:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2024-09-05T22:04:06.906Z,1725573846.906 [transit:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2024-09-05T22:04:06.934Z,1725573846.934 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl
2024-09-05T22:04:06.934Z,1725573846.934 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/BackseatDriver.tl
2024-09-05T22:04:06.940Z,1725573846.940 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/BackseatDriver.tl
2024-09-05T22:04:06.987Z,1725573846.987 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/BackseatDriver.tl translated into:
2024-09-05T22:04:06.995Z,1725573846.995 [MissionManager](INFO): DefineArg transit:BackseatDriver.EnableBackseat = 0 bool
2024-09-05T22:04:06.998Z,1725573846.998 [transit:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver.
2024-09-05T22:04:07.002Z,1725573847.002 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/PowerOnly.tl
2024-09-05T22:04:07.002Z,1725573847.002 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/PowerOnly.tl
2024-09-05T22:04:07.011Z,1725573847.011 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/PowerOnly.tl
2024-09-05T22:04:07.282Z,1725573847.282 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/PowerOnly.tl translated into:
99999
2024-09-05T22:04:07.290Z,1725573847.290 [MissionManager](INFO): DefineArg transit:PowerOnly.SampleAll = 0 bool
2024-09-05T22:04:07.297Z,1725573847.297 [MissionManager](INFO): DefineArg transit:PowerOnly.SampleLoad1 = 0 bool
2024-09-05T22:04:07.300Z,1725573847.300 [MissionManager](INFO): DefineArg transit:PowerOnly.SampleLoad2 = 0 bool
2024-09-05T22:04:07.311Z,1725573847.311 [MissionManager](INFO): DefineArg transit:PowerOnly.SampleLoad3 = 0 bool
2024-09-05T22:04:07.314Z,1725573847.314 [MissionManager](INFO): DefineArg transit:PowerOnly.EnabledPowerOnly = 0 bool
2024-09-05T22:04:07.340Z,1725573847.340 [transit:PowerOnly:E.Wait](DEBUG): Construct Wait.
2024-09-05T22:04:07.342Z,1725573847.342 [transit:BuoyancyHold.Buoyancy](DEBUG): Construct Buoyancy.
2024-09-05T22:04:07.355Z,1725573847.355 [transit:MassHold.Pitch](DEBUG): Construct.
2024-09-05T22:04:07.372Z,1725573847.372 [transit:Transit:A.Pitch](DEBUG): Construct.
2024-09-05T22:04:07.389Z,1725573847.389 [transit:Transit:B.SetSpeed](DEBUG): Construct.
2024-09-05T22:04:07.405Z,1725573847.405 [transit:Transit:Wpt1.Waypoint](DEBUG): Construct Waypoint.
2024-09-05T22:04:07.445Z,1725573847.445 [MissionManager](DEBUG):
# Copyright (c) 2024 MBARI
# MBARI Proprietary Information. Confidential. All Rights Reserved
# Unauthorized copying or distribution of this file via any medium is strictly
# prohibited.
#
# WARNING - This file contains information whose export is restricted by the
# Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as
# amended. Violations of these export laws are subject to severe civil and/or
# criminal penalties.
mission transit {
"""
Vehicle transits to desired waypoint and can be commanded to use/hold
mass or buoyancy.
"""
arguments {
MissionTimeout = 60 minute
"""
Maximum duration of mission
"""
NeedCommsTime = 30 minute
"""
How often to surface for commumications
"""
Latitude = NaN degree
"""
Latitude of waypoint to seek. If set to NaN, uses latitude at mission
initialization.
"""
Longitude = NaN degree
"""
Longitude of waypoint to seek. If set to NaN, uses longitude at mission
initialization.
"""
Northings = 0 meter
"""
Northward distance of the waypoint to seek. If combined with Latitude
and/or Longitude, this is an offset from the specified Latitude and/or
Longitude.
"""
Eastings = 0 meter
"""
Eastward distance of the waypoint to seek. If combined with Latitude
and/or Longitude, this is an offset from the specified Latitude and/or
Longitude.
"""
Depth = 10 meter
"""
Depth of flat and level flight during the mission.
"""
Speed = 1 meter_per_second
"""
Speed of vehicle (relative to water) during the mission.
"""
MaxDepth = 20 meter
"""
Maximum depth for the entire mission.
"""
MinOffshore = 1 kilometer
"""
Minimum distance offshore for the entire mission.
"""
MinAltitude = 7 meter
"""
Minimum height above the sea floor for the entire mission.
"""
MassHold = true
"""
Set to True in order to hold mass at default position, False to allow
mass to run on its own.
"""
BuoyancyHold = true
"""
Set to True in order to hold buoyancy at neutral position, False to
allow buoyancy to run on its own.
"""
}
timeout duration=MissionTimeout
insert id="NeedComms" Insert/NeedComms.tl
assign in sequence NeedComms:DiveInterval = NeedCommsTime
assign in sequence NeedComms:WaitForPitchUp = 1 second
insert Insert/StandardEnvelopes.tl
assign in sequence StandardEnvelopes:MinAltitude = MinAltitude
assign in sequence StandardEnvelopes:MaxDepth = MaxDepth
assign in sequence StandardEnvelopes:MinOffshore = MinOffshore
insert Insert/BackseatDriver.tl
insert Insert/PowerOnly.tl
behavior Guidance:Buoyancy id="BuoyancyHold" {
run while ( BuoyancyHold )
set position = Control:VerticalControl.buoyancyNeutral
}
behavior Guidance:Pitch id="MassHold" {
run while ( MassHold )
set massPosition = Control:VerticalControl.massDefault
}
aggregate Transit {
run in sequence
behavior Guidance:Pitch {
run in parallel
set depth = Depth
}
behavior Guidance:SetSpeed {
run in parallel
set speed = Speed
}
behavior Guidance:Waypoint id="Wpt1" {
run in sequence
set latitude = Latitude
set longitude = Longitude
set northingsDelta = Northings
set eastingsDelta = Eastings
}
call id="PhoneHome" refId="NeedComms"
}
}
2024-09-05T22:04:07.446Z,1725573847.446 [CommandExec](IMPORTANT): Loaded ./Missions/Transport/transit.tl id=transit
2024-09-05T22:04:14.705Z,1725573854.705 [CommandExec](IMPORTANT): got command set transit.NeedCommsTime 15 minute
2024-09-05T22:04:14.706Z,1725573854.706 [CommandExec](IMPORTANT): got command set transit.Latitude 36.797 degree
2024-09-05T22:04:14.711Z,1725573854.711 [CommandExec](IMPORTANT): got command set transit.Longitude -121.847 degree
2024-09-05T22:04:14.711Z,1725573854.711 [CommandExec](IMPORTANT): got command run
2024-09-05T22:04:14.713Z,1725573854.713 [CommandExec](IMPORTANT): Running
2024-09-05T22:04:14.816Z,1725573854.816 [Default] Stopped
2024-09-05T22:04:14.817Z,1725573854.817 [Default](DEBUG): Aggregate::uninitialize Default
2024-09-05T22:04:14.817Z,1725573854.817 [Default:B.GoToSurface] Stopped
2024-09-05T22:04:14.817Z,1725573854.817 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2024-09-05T22:04:14.817Z,1725573854.817 [Default:CheckIn] Stopped
2024-09-05T22:04:14.817Z,1725573854.817 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-05T22:04:14.817Z,1725573854.817 [Default:CheckIn:Read_Iridium] Stopped
2024-09-05T22:04:14.817Z,1725573854.817 [MissionManager](IMPORTANT): Started mission transit
2024-09-05T22:04:14.817Z,1725573854.817 [transit] Running Loop=1
2024-09-05T22:04:14.817Z,1725573854.817 [transit](DEBUG): Aggregate::initialize transit
2024-09-05T22:04:14.818Z,1725573854.818 [transit:StandardEnvelopes] Running Loop=1
2024-09-05T22:04:14.818Z,1725573854.818 [transit:StandardEnvelopes](DEBUG): Aggregate::initialize transit:StandardEnvelopes
2024-09-05T22:04:14.818Z,1725573854.818 [transit:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2024-09-05T22:04:14.818Z,1725573854.818 [transit:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2024-09-05T22:04:14.818Z,1725573854.818 [transit:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2024-09-05T22:04:14.818Z,1725573854.818 [transit:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2024-09-05T22:04:14.818Z,1725573854.818 [transit:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2024-09-05T22:04:14.819Z,1725573854.819 [transit:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2024-09-05T22:04:14.819Z,1725573854.819 [transit:BackseatDriver] Running Loop=1
2024-09-05T22:04:14.819Z,1725573854.819 [transit:BackseatDriver](DEBUG): Aggregate::initialize transit:BackseatDriver
2024-09-05T22:04:14.819Z,1725573854.819 [transit:BackseatDriver:A.BackseatDriver] Running Loop=1
2024-09-05T22:04:14.819Z,1725573854.819 [transit:PowerOnly] Running Loop=1
2024-09-05T22:04:14.819Z,1725573854.819 [transit:PowerOnly](DEBUG): Aggregate::initialize transit:PowerOnly
2024-09-05T22:04:14.819Z,1725573854.819 [transit:PowerOnly:A] Running Loop=1
2024-09-05T22:04:14.819Z,1725573854.819 [transit:PowerOnly:B] Running Loop=1
2024-09-05T22:04:14.819Z,1725573854.819 [transit:PowerOnly:C] Running Loop=1
2024-09-05T22:04:14.819Z,1725573854.819 [transit:PowerOnly:D] Running Loop=1
2024-09-05T22:04:14.819Z,1725573854.819 [transit:PowerOnly:E.Wait] Running Loop=1
2024-09-05T22:04:14.820Z,1725573854.820 [transit:PowerOnly:E.Wait](DEBUG): Initialize Wait Component.
2024-09-05T22:04:14.820Z,1725573854.820 [transit:BuoyancyHold.Buoyancy] Running Loop=1
2024-09-05T22:04:14.820Z,1725573854.820 [transit:BuoyancyHold.Buoyancy](DEBUG): Initialize Buoyancy Component.
2024-09-05T22:04:14.820Z,1725573854.820 [transit:MassHold.Pitch] Running Loop=1
2024-09-05T22:04:14.820Z,1725573854.820 [transit:MassHold.Pitch](DEBUG): Initialize.
2024-09-05T22:04:14.820Z,1725573854.820 [transit:B] Running Loop=1
2024-09-05T22:04:14.821Z,1725573854.821 [transit:MassHold.Pitch] Running Loop=1
2024-09-05T22:04:14.821Z,1725573854.821 [transit:BuoyancyHold.Buoyancy] Running Loop=1
2024-09-05T22:04:14.821Z,1725573854.821 [transit:PowerOnly] Running Loop=1
2024-09-05T22:04:14.822Z,1725573854.822 [transit:PowerOnly:D] Stopped
2024-09-05T22:04:14.822Z,1725573854.822 [transit:PowerOnly:C] Stopped
2024-09-05T22:04:14.822Z,1725573854.822 [transit:PowerOnly:B] Stopped
2024-09-05T22:04:14.822Z,1725573854.822 [transit:PowerOnly:A] Stopped
2024-09-05T22:04:14.822Z,1725573854.822 [transit:BackseatDriver] Running Loop=1
2024-09-05T22:04:14.838Z,1725573854.838 [transit:StandardEnvelopes] Running Loop=1
2024-09-05T22:04:14.838Z,1725573854.838 [transit:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2024-09-05T22:04:14.839Z,1725573854.839 [transit:StandardEnvelopes:C.OffshoreEnvelope](IMPORTANT): Offshore envelope ACTIVE
2024-09-05T22:04:14.853Z,1725573854.853 [transit:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2024-09-05T22:04:14.854Z,1725573854.854 [transit:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2024-09-05T22:04:14.875Z,1725573854.875 [transit:B] Stopped
2024-09-05T22:04:14.875Z,1725573854.875 [transit:C] Running Loop=1
2024-09-05T22:04:14.879Z,1725573854.879 [HorizontalControl](DEBUG): kpHeading = 0.400000
2024-09-05T22:04:14.880Z,1725573854.880 [HorizontalControl](DEBUG): kiHeading = 0.001000
2024-09-05T22:04:14.880Z,1725573854.880 [HorizontalControl](DEBUG): kdHeading = 0.050000
2024-09-05T22:04:15.223Z,1725573855.223 [transit:C] Stopped
2024-09-05T22:04:15.223Z,1725573855.223 [transit:E] Running Loop=1
2024-09-05T22:04:15.623Z,1725573855.623 [transit:E] Stopped
2024-09-05T22:04:15.623Z,1725573855.623 [transit:F] Running Loop=1
2024-09-05T22:04:16.004Z,1725573856.004 [transit:F] Stopped
2024-09-05T22:04:16.004Z,1725573856.004 [transit:G] Running Loop=1
2024-09-05T22:04:16.404Z,1725573856.404 [transit:G] Stopped
2024-09-05T22:04:16.404Z,1725573856.404 [transit:Transit] Running Loop=1
2024-09-05T22:04:16.404Z,1725573856.404 [transit:Transit](DEBUG): Aggregate::initialize transit:Transit
2024-09-05T22:04:16.404Z,1725573856.404 [transit:Transit:A.Pitch] Running Loop=1
2024-09-05T22:04:16.404Z,1725573856.404 [transit:Transit:A.Pitch](DEBUG): Initialize.
2024-09-05T22:04:16.405Z,1725573856.405 [transit:Transit:B.SetSpeed] Running Loop=1
2024-09-05T22:04:16.405Z,1725573856.405 [transit:Transit:B.SetSpeed](DEBUG): Initialize.
2024-09-05T22:04:16.405Z,1725573856.405 [transit:Transit:Wpt1.Waypoint] Running Loop=1
2024-09-05T22:04:16.405Z,1725573856.405 [transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2024-09-05T22:04:16.407Z,1725573856.407 [transit:Transit:Wpt1.Waypoint](IMPORTANT): Navigating to waypoint: 36.797001,-121.847000
2024-09-05T22:04:16.415Z,1725573856.415 [transit:StandardEnvelopes:A.AltitudeEnvelope](ERROR): Altitude Measurement is not Active.
2024-09-05T22:04:16.808Z,1725573856.808 [transit:Transit:Wpt1.Waypoint](INFO): Navigating to waypoint: 36.797001,-121.847000
2024-09-05T22:04:16.808Z,1725573856.808 [transit:Transit:B.SetSpeed] Running Loop=1
2024-09-05T22:04:16.809Z,1725573856.809 [transit:Transit:A.Pitch] Running Loop=1
2024-09-05T22:04:27.806Z,1725573867.806 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20240905T214131/Courier0019.lzma
2024-09-05T22:04:28.811Z,1725573868.811 [DataOverHttps](INFO): Moved sent file to Logs/20240905T214131/Courier0019.lzma.bak
2024-09-05T22:04:28.811Z,1725573868.811 [DataOverHttps](INFO): SBD MOMSN=23132426
2024-09-05T22:04:32.543Z,1725573872.543 [CommandExec](IMPORTANT): got command stop
2024-09-05T22:04:32.544Z,1725573872.543 [CommandExec](IMPORTANT): Scheduling is paused
2024-09-05T22:04:32.544Z,1725573872.544 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2024-09-05T22:04:32.632Z,1725573872.632 [MissionManager](INFO): MissionManager is completed.
2024-09-05T22:04:32.632Z,1725573872.632 [MissionManager](INFO): Uninitializing Mission transit
2024-09-05T22:04:32.632Z,1725573872.632 [transit] Stopped
2024-09-05T22:04:32.632Z,1725573872.632 [transit](DEBUG): Aggregate::uninitialize transit
2024-09-05T22:04:32.632Z,1725573872.632 [transit:StandardEnvelopes] Stopped
2024-09-05T22:04:32.632Z,1725573872.632 [transit:StandardEnvelopes](DEBUG): Aggregate::uninitialize transit:StandardEnvelopes
2024-09-05T22:04:32.632Z,1725573872.632 [transit:StandardEnvelopes:A.AltitudeEnvelope] Stopped
2024-09-05T22:04:32.632Z,1725573872.632 [transit:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2024-09-05T22:04:32.632Z,1725573872.632 [transit:StandardEnvelopes:B.DepthEnvelope] Stopped
2024-09-05T22:04:32.633Z,1725573872.633 [transit:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize.
2024-09-05T22:04:32.633Z,1725573872.633 [transit:StandardEnvelopes:C.OffshoreEnvelope] Stopped
2024-09-05T22:04:32.633Z,1725573872.633 [transit:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2024-09-05T22:04:32.633Z,1725573872.633 [transit:BackseatDriver] Stopped
2024-09-05T22:04:32.633Z,1725573872.633 [transit:BackseatDriver](DEBUG): Aggregate::uninitialize transit:BackseatDriver
2024-09-05T22:04:32.633Z,1725573872.633 [transit:BackseatDriver:A.BackseatDriver] Stopped
2024-09-05T22:04:32.633Z,1725573872.633 [transit:PowerOnly] Stopped
2024-09-05T22:04:32.633Z,1725573872.633 [transit:PowerOnly](DEBUG): Aggregate::uninitialize transit:PowerOnly
2024-09-05T22:04:32.633Z,1725573872.633 [transit:PowerOnly:E.Wait] Stopped
2024-09-05T22:04:32.633Z,1725573872.633 [transit:PowerOnly:E.Wait](DEBUG): Uninitialize Wait Component.
2024-09-05T22:04:32.633Z,1725573872.633 [transit:BuoyancyHold.Buoyancy] Stopped
2024-09-05T22:04:32.633Z,1725573872.633 [transit:BuoyancyHold.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2024-09-05T22:04:32.633Z,1725573872.633 [transit:MassHold.Pitch] Stopped
2024-09-05T22:04:32.634Z,1725573872.634 [transit:Transit] Stopped
2024-09-05T22:04:32.634Z,1725573872.634 [transit:Transit](DEBUG): Aggregate::uninitialize transit:Transit
2024-09-05T22:04:32.634Z,1725573872.634 [transit:Transit:A.Pitch] Stopped
2024-09-05T22:04:32.634Z,1725573872.634 [transit:Transit:B.SetSpeed] Stopped
2024-09-05T22:04:32.634Z,1725573872.634 [transit:Transit:B.SetSpeed](DEBUG): Uninitialize.
2024-09-05T22:04:32.634Z,1725573872.634 [transit:Transit:Wpt1.Waypoint] Stopped
2024-09-05T22:04:32.634Z,1725573872.634 [transit:Transit:Wpt1.Waypoint](DEBUG): Uninitialize WaypointComponent.
2024-09-05T22:04:32.988Z,1725573872.988 [MissionManager](IMPORTANT): Started mission Default
2024-09-05T22:04:32.988Z,1725573872.988 [Default] Running Loop=1
2024-09-05T22:04:32.988Z,1725573872.988 [Default](DEBUG): Aggregate::initialize Default
2024-09-05T22:04:32.989Z,1725573872.989 [Default:B.GoToSurface] Running Loop=1
2024-09-05T22:04:32.989Z,1725573872.989 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2024-09-05T22:04:32.989Z,1725573872.989 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2024-09-05T22:04:32.989Z,1725573872.989 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2024-09-05T22:04:32.989Z,1725573872.989 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2024-09-05T22:04:32.990Z,1725573872.990 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2024-09-05T22:04:32.990Z,1725573872.990 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2024-09-05T22:04:32.991Z,1725573872.991 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2024-09-05T22:04:32.991Z,1725573872.991 [Default:A.Wait] Running Loop=1
2024-09-05T22:04:32.991Z,1725573872.991 [Default:A.Wait](DEBUG): Initialize Wait Component.
2024-09-05T22:04:34.936Z,1725573874.936 [CommandExec](IMPORTANT): got command schedule resume
2024-09-05T22:04:34.936Z,1725573874.936 [CommandExec](IMPORTANT): Scheduling is resumed
2024-09-05T22:04:46.311Z,1725573886.311 [Default:A.Wait](INFO): Done Waiting.
2024-09-05T22:04:46.311Z,1725573886.311 [Default:A.Wait] Stopped
2024-09-05T22:04:46.311Z,1725573886.311 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2024-09-05T22:04:46.716Z,1725573886.716 [Default:CheckIn] Running Loop=1
2024-09-05T22:04:46.716Z,1725573886.716 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-05T22:04:46.717Z,1725573886.717 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-05T22:04:48.726Z,1725573888.726 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220447.00,A,3648.14067,N,12147.22874,W,0.019,0.00,050924,,,D*7B
2024-09-05T22:04:48.728Z,1725573888.728 [NAL9602](INFO): GPS fix at 20240905T220447: (36.802344, -121.787146)
2024-09-05T22:04:48.743Z,1725573888.743 [Default:CheckIn:Read_GPS] Stopped
2024-09-05T22:04:48.743Z,1725573888.743 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-05T22:05:05.215Z,1725573905.215 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20240905T214131/Courier0022.lzma
2024-09-05T22:05:06.217Z,1725573906.217 [DataOverHttps](INFO): Moved sent file to Logs/20240905T214131/Courier0022.lzma.bak
2024-09-05T22:05:06.217Z,1725573906.217 [DataOverHttps](INFO): SBD MOMSN=23132428
2024-09-05T22:05:19.451Z,1725573919.451 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2024-09-05T22:05:19.535Z,1725573919.535 [NAL9602](ERROR): received:
+CSQ:1
OK571, 2, 0, 0, 0
OK
2024-09-05T22:05:22.382Z,1725573922.382 [DataOverHttps](INFO): Sending 157 bytes from file Logs/20240905T214131/Express0020.lzma
2024-09-05T22:05:23.384Z,1725573923.384 [DataOverHttps](INFO): Moved sent file to Logs/20240905T214131/Express0020.lzma.bak
2024-09-05T22:05:23.385Z,1725573923.385 [DataOverHttps](INFO): SBD MOMSN=23132431
2024-09-05T22:05:39.323Z,1725573939.323 [DataOverHttps](INFO): Sending 432 bytes from file Logs/20240905T214131/Express0023.lzma
2024-09-05T22:05:40.324Z,1725573940.324 [DataOverHttps](INFO): Moved sent file to Logs/20240905T214131/Express0023.lzma.bak
2024-09-05T22:05:40.325Z,1725573940.325 [DataOverHttps](INFO): SBD MOMSN=23132437
2024-09-05T22:05:41.668Z,1725573941.668 [Default:CheckIn:Read_Iridium] Stopped
2024-09-05T22:05:41.668Z,1725573941.668 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-05T22:05:41.668Z,1725573941.668 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-05T22:08:57.189Z,1725574137.189 [NAL9602](INFO): SBD MO Status=2, MOMSN=21571, MT Status=2, MTMSN=0
2024-09-05T22:08:57.189Z,1725574137.189 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2024-09-05T22:09:51.339Z,1725574191.339 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2024-09-05T22:10:22.024Z,1725574222.024 [NAL9602](INFO): Not Powering down - fast GPS
2024-09-05T22:10:42.235Z,1725574242.235 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-05T22:10:42.235Z,1725574242.235 [Default:CheckIn:C.Wait] Stopped
2024-09-05T22:10:42.235Z,1725574242.235 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-05T22:10:42.236Z,1725574242.236 [Default:CheckIn:D] Running Loop=1
2024-09-05T22:10:42.648Z,1725574242.648 [Default:CheckIn:D] Stopped
2024-09-05T22:10:42.649Z,1725574242.649 [Default:CheckIn:E] Running Loop=1
2024-09-05T22:10:43.047Z,1725574243.047 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 6.161000 min
2024-09-05T22:10:43.047Z,1725574243.047 [Default:CheckIn:E] Stopped
2024-09-05T22:10:43.047Z,1725574243.047 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-05T22:10:43.047Z,1725574243.047 [Default:CheckIn] Stopped
2024-09-05T22:10:43.047Z,1725574243.047 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-05T22:10:43.047Z,1725574243.047 [Default:CheckIn](INFO): Running loop #2
2024-09-05T22:10:43.047Z,1725574243.047 [Default:CheckIn] Running Loop=2
2024-09-05T22:10:43.047Z,1725574243.047 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-05T22:10:43.047Z,1725574243.047 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-05T22:10:45.053Z,1725574245.053 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221044.00,A,3648.14980,N,12147.22061,W,0.311,67.26,050924,,,D*4F
2024-09-05T22:10:45.056Z,1725574245.056 [NAL9602](INFO): GPS fix at 20240905T221044: (36.802497, -121.787010)
2024-09-05T22:10:45.067Z,1725574245.067 [Default:CheckIn:Read_GPS] Stopped
2024-09-05T22:10:45.067Z,1725574245.067 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-05T22:10:53.034Z,1725574253.034 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240905T214131/Courier0025.lzma
2024-09-05T22:10:54.036Z,1725574254.036 [DataOverHttps](INFO): Moved sent file to Logs/20240905T214131/Courier0025.lzma.bak
2024-09-05T22:10:54.037Z,1725574254.037 [DataOverHttps](INFO): SBD MOMSN=23132498
2024-09-05T22:11:10.118Z,1725574270.118 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20240905T214131/Express0026.lzma
2024-09-05T22:11:10.997Z,1725574270.997 [DataOverHttps](INFO): Moved sent file to Logs/20240905T214131/Express0026.lzma.bak
2024-09-05T22:11:10.997Z,1725574270.997 [DataOverHttps](INFO): SBD MOMSN=23132501
2024-09-05T22:11:12.136Z,1725574272.136 [Default:CheckIn:Read_Iridium] Stopped
2024-09-05T22:11:12.136Z,1725574272.136 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-05T22:11:12.136Z,1725574272.136 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-05T22:11:15.766Z,1725574275.766 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2024-09-05T22:11:15.843Z,1725574275.843 [NAL9602](ERROR): received:
+CSQ:0
OK571, 2, 0, 0, 0
OK
2024-09-05T22:12:07.877Z,1725574327.877 [NAL9602](INFO): SBD MO Status=0, MOMSN=21571, MT Status=0, MTMSN=0
2024-09-05T22:12:07.877Z,1725574327.877 [NAL9602](INFO): No messages in MT queue
2024-09-05T22:12:38.588Z,1725574358.588 [NAL9602](INFO): Not Powering down - fast GPS
2024-09-05T22:13:14.949Z,1725574394.949 [DVL_micro](ERROR): Failed to parse:
:WI,+00162,-04013,+00756,+00000,A
2024-09-05T22:13:49.288Z,1725574429.288 [DVL_micro](ERROR): Failed to parse:
:WI,+00344,-02990,+00559,+00000,A
2024-09-05T22:16:12.733Z,1725574572.733 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-05T22:16:12.733Z,1725574572.733 [Default:CheckIn:C.Wait] Stopped
2024-09-05T22:16:12.733Z,1725574572.733 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-05T22:16:12.733Z,1725574572.733 [Default:CheckIn:D] Running Loop=1
2024-09-05T22:16:13.126Z,1725574573.126 [Default:CheckIn:D] Stopped
2024-09-05T22:16:13.126Z,1725574573.126 [Default:CheckIn:E] Running Loop=1
2024-09-05T22:16:13.530Z,1725574573.530 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.668957 min
2024-09-05T22:16:13.530Z,1725574573.530 [Default:CheckIn:E] Stopped
2024-09-05T22:16:13.530Z,1725574573.530 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-05T22:16:13.530Z,1725574573.530 [Default:CheckIn] Stopped
2024-09-05T22:16:13.530Z,1725574573.530 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-05T22:16:13.531Z,1725574573.531 [Default:CheckIn](INFO): Running loop #3
2024-09-05T22:16:13.531Z,1725574573.531 [Default:CheckIn] Running Loop=3
2024-09-05T22:16:13.531Z,1725574573.531 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-05T22:16:13.531Z,1725574573.531 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-05T22:16:15.546Z,1725574575.546 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221614.00,A,3648.32028,N,12147.11475,W,5.210,4.92,050924,,,D*7D
2024-09-05T22:16:15.548Z,1725574575.548 [NAL9602](INFO): GPS fix at 20240905T221614: (36.805338, -121.785246)
2024-09-05T22:16:15.559Z,1725574575.559 [Default:CheckIn:Read_GPS] Stopped
2024-09-05T22:16:15.559Z,1725574575.559 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-05T22:16:22.706Z,1725574582.706 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240905T214131/Courier0028.lzma
2024-09-05T22:16:23.708Z,1725574583.708 [DataOverHttps](INFO): Moved sent file to Logs/20240905T214131/Courier0028.lzma.bak
2024-09-05T22:16:23.709Z,1725574583.709 [DataOverHttps](INFO): SBD MOMSN=23132537
2024-09-05T22:16:39.514Z,1725574599.514 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20240905T214131/Express0029.lzma
2024-09-05T22:16:40.516Z,1725574600.516 [DataOverHttps](INFO): Moved sent file to Logs/20240905T214131/Express0029.lzma.bak
2024-09-05T22:16:40.517Z,1725574600.517 [DataOverHttps](INFO): SBD MOMSN=23132540
2024-09-05T22:16:41.811Z,1725574601.811 [Default:CheckIn:Read_Iridium] Stopped
2024-09-05T22:16:41.811Z,1725574601.811 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-05T22:16:41.811Z,1725574601.811 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-05T22:16:47.867Z,1725574607.867 [NAL9602](INFO): SBD MO Status=0, MOMSN=21572, MT Status=0, MTMSN=0
2024-09-05T22:16:47.867Z,1725574607.867 [NAL9602](INFO): No messages in MT queue
2024-09-05T22:17:18.565Z,1725574638.565 [NAL9602](INFO): Not Powering down - fast GPS
2024-09-05T22:21:42.414Z,1725574902.414 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-05T22:21:42.414Z,1725574902.414 [Default:CheckIn:C.Wait] Stopped
2024-09-05T22:21:42.414Z,1725574902.414 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-05T22:21:42.415Z,1725574902.415 [Default:CheckIn:D] Running Loop=1
2024-09-05T22:21:42.791Z,1725574902.791 [Default:CheckIn:D] Stopped
2024-09-05T22:21:42.791Z,1725574902.791 [Default:CheckIn:E] Running Loop=1
2024-09-05T22:21:43.194Z,1725574903.194 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 17.163381 min
2024-09-05T22:21:43.194Z,1725574903.194 [Default:CheckIn:E] Stopped
2024-09-05T22:21:43.194Z,1725574903.194 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-05T22:21:43.194Z,1725574903.194 [Default:CheckIn] Stopped
2024-09-05T22:21:43.194Z,1725574903.194 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-05T22:21:43.195Z,1725574903.195 [Default:CheckIn](INFO): Running loop #4
2024-09-05T22:21:43.195Z,1725574903.195 [Default:CheckIn] Running Loop=4
2024-09-05T22:21:43.195Z,1725574903.195 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-05T22:21:43.195Z,1725574903.195 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-05T22:21:45.206Z,1725574905.206 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222144.00,A,3648.34772,N,12147.68106,W,14.248,275.10,050924,,,D*4E
2024-09-05T22:21:45.208Z,1725574905.208 [NAL9602](INFO): GPS fix at 20240905T222144: (36.805795, -121.794684)
2024-09-05T22:21:45.234Z,1725574905.234 [Default:CheckIn:Read_GPS] Stopped
2024-09-05T22:21:45.234Z,1725574905.234 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-05T22:21:52.866Z,1725574912.866 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240905T214131/Courier0031.lzma
2024-09-05T22:21:53.868Z,1725574913.868 [DataOverHttps](INFO): Moved sent file to Logs/20240905T214131/Courier0031.lzma.bak
2024-09-05T22:21:53.869Z,1725574913.869 [DataOverHttps](INFO): SBD MOMSN=23132563
2024-09-05T22:22:09.440Z,1725574929.440 [NAL9602](INFO): SBD MO Status=2, MOMSN=21573, MT Status=2, MTMSN=0
2024-09-05T22:22:09.440Z,1725574929.440 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2024-09-05T22:22:09.782Z,1725574929.782 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20240905T214131/Express0032.lzma
2024-09-05T22:22:10.784Z,1725574930.784 [DataOverHttps](INFO): Moved sent file to Logs/20240905T214131/Express0032.lzma.bak
2024-09-05T22:22:10.785Z,1725574930.785 [DataOverHttps](INFO): SBD MOMSN=23132566
2024-09-05T22:22:11.880Z,1725574931.880 [Default:CheckIn:Read_Iridium] Stopped
2024-09-05T22:22:11.880Z,1725574931.880 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-05T22:22:11.880Z,1725574931.880 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-05T22:22:54.284Z,1725574974.284 [NAL9602](INFO): SBD MO Status=2, MOMSN=21573, MT Status=2, MTMSN=0
2024-09-05T22:22:54.284Z,1725574974.284 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2024-09-05T22:24:21.549Z,1725575061.549 [NAL9602](INFO): SBD MO Status=0, MOMSN=21573, MT Status=0, MTMSN=0
2024-09-05T22:24:21.549Z,1725575061.549 [NAL9602](INFO): No messages in MT queue
2024-09-05T22:24:52.256Z,1725575092.256 [NAL9602](INFO): Not Powering down - fast GPS
2024-09-05T22:27:12.477Z,1725575232.477 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-05T22:27:12.477Z,1725575232.477 [Default:CheckIn:C.Wait] Stopped
2024-09-05T22:27:12.477Z,1725575232.477 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-05T22:27:12.477Z,1725575232.477 [Default:CheckIn:D] Running Loop=1
2024-09-05T22:27:12.862Z,1725575232.862 [Default:CheckIn:D] Stopped
2024-09-05T22:27:12.862Z,1725575232.862 [Default:CheckIn:E] Running Loop=1
2024-09-05T22:27:13.267Z,1725575233.267 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 22.664559 min
2024-09-05T22:27:13.267Z,1725575233.267 [Default:CheckIn:E] Stopped
2024-09-05T22:27:13.267Z,1725575233.267 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-05T22:27:13.267Z,1725575233.267 [Default:CheckIn] Stopped
2024-09-05T22:27:13.267Z,1725575233.267 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-05T22:27:13.267Z,1725575233.267 [Default:CheckIn](INFO): Running loop #5
2024-09-05T22:27:13.267Z,1725575233.267 [Default:CheckIn] Running Loop=5
2024-09-05T22:27:13.267Z,1725575233.267 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-05T22:27:13.267Z,1725575233.267 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-05T22:27:15.283Z,1725575235.283 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222714.00,A,3648.18736,N,12148.94805,W,0.525,128.52,050924,,,D*71
2024-09-05T22:27:15.285Z,1725575235.285 [NAL9602](INFO): GPS fix at 20240905T222714: (36.803123, -121.815801)
2024-09-05T22:27:15.296Z,1725575235.296 [Default:CheckIn:Read_GPS] Stopped
2024-09-05T22:27:15.296Z,1725575235.296 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-05T22:27:22.346Z,1725575242.346 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20240905T214131/Courier0034.lzma
2024-09-05T22:27:23.348Z,1725575243.348 [DataOverHttps](INFO): Moved sent file to Logs/20240905T214131/Courier0034.lzma.bak
2024-09-05T22:27:23.348Z,1725575243.348 [DataOverHttps](INFO): SBD MOMSN=23132577
2024-09-05T22:27:39.250Z,1725575259.250 [DataOverHttps](INFO): Sending 141 bytes from file Logs/20240905T214131/Express0035.lzma
2024-09-05T22:27:40.253Z,1725575260.253 [DataOverHttps](INFO): Moved sent file to Logs/20240905T214131/Express0035.lzma.bak
2024-09-05T22:27:40.253Z,1725575260.253 [DataOverHttps](INFO): SBD MOMSN=23132580
2024-09-05T22:27:41.566Z,1725575261.566 [Default:CheckIn:Read_Iridium] Stopped
2024-09-05T22:27:41.567Z,1725575261.567 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-05T22:27:41.567Z,1725575261.567 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-05T22:27:56.072Z,1725575276.072 [NAL9602](INFO): SBD MO Status=2, MOMSN=21574, MT Status=2, MTMSN=0
2024-09-05T22:27:56.072Z,1725575276.072 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2024-09-05T22:28:12.637Z,1725575292.637 [NAL9602](INFO): SBD MO Status=2, MOMSN=21574, MT Status=2, MTMSN=0
2024-09-05T22:28:12.637Z,1725575292.637 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2024-09-05T22:28:22.333Z,1725575302.333 [NAL9602](INFO): SBD MO Status=0, MOMSN=21574, MT Status=0, MTMSN=0
2024-09-05T22:28:22.334Z,1725575302.334 [NAL9602](INFO): No messages in MT queue
2024-09-05T22:28:53.053Z,1725575333.053 [NAL9602](INFO): Not Powering down - fast GPS
2024-09-05T22:31:57.463Z,1725575517.463 [DataOverHttps](IMPORTANT): SBD MTMSN=20240905T223156
2024-09-05T22:32:04.930Z,1725575524.930 [DataOverHttps](INFO): Received command: restart logs