2023-04-28T17:21:03.085Z,1682702463.085 [Supervisor](DEBUG): Initializing supervisor.
2023-04-28T17:21:03.090Z,1682702463.090 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2023-04-28T17:21:03.090Z,1682702463.090 [SyncHandler](INFO): Protected caller Thread ID is 1269
2023-04-28T17:21:03.091Z,1682702463.091 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2023-04-28T17:21:03.092Z,1682702463.092 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2023-04-28T17:21:03.092Z,1682702463.092 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1270
2023-04-28T17:21:03.096Z,1682702463.096 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2023-04-28T17:21:03.113Z,1682702463.113 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2023-04-28T17:21:03.114Z,1682702463.114 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2023-04-28T17:21:03.115Z,1682702463.115 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 1271
2023-04-28T17:21:03.119Z,1682702463.119 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2023-04-28T17:21:03.120Z,1682702463.120 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2023-04-28T17:21:03.120Z,1682702463.120 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1272
2023-04-28T17:21:03.122Z,1682702463.122 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2023-04-28T17:21:03.123Z,1682702463.123 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2023-04-28T17:21:03.123Z,1682702463.123 [logger ThreadHandler](INFO): Protected caller Thread ID is 1273
2023-04-28T17:21:03.127Z,1682702463.127 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2023-04-28T17:21:03.127Z,1682702463.127 [Supervisor](INFO): Looking for Config files in directory: Config/
2023-04-28T17:21:03.129Z,1682702463.129 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2023-04-28T17:21:03.401Z,1682702463.401 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2023-04-28T17:21:03.402Z,1682702463.402 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2023-04-28T17:21:03.482Z,1682702463.482 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2023-04-28T17:21:03.961Z,1682702463.961 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2023-04-28T17:21:03.962Z,1682702463.962 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2023-04-28T17:21:04.290Z,1682702464.290 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2023-04-28T17:21:04.290Z,1682702464.290 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2023-04-28T17:21:04.387Z,1682702464.387 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2023-04-28T17:21:04.388Z,1682702464.388 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2023-04-28T17:21:04.783Z,1682702464.783 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2023-04-28T17:21:04.784Z,1682702464.784 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2023-04-28T17:21:04.995Z,1682702464.995 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2023-04-28T17:21:04.996Z,1682702464.996 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2023-04-28T17:21:05.516Z,1682702465.516 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2023-04-28T17:21:05.517Z,1682702465.517 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2023-04-28T17:21:05.655Z,1682702465.655 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2023-04-28T17:21:05.655Z,1682702465.655 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2023-04-28T17:21:05.735Z,1682702465.735 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2023-04-28T17:21:06.477Z,1682702466.477 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2023-04-28T17:21:06.478Z,1682702466.478 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2023-04-28T17:21:06.891Z,1682702466.891 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2023-04-28T17:21:06.892Z,1682702466.892 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2023-04-28T17:21:07.083Z,1682702467.083 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2023-04-28T17:21:07.083Z,1682702467.083 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2023-04-28T17:21:07.194Z,1682702467.194 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2023-04-28T17:21:07.195Z,1682702467.195 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2023-04-28T17:21:07.419Z,1682702467.419 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2023-04-28T17:21:07.420Z,1682702467.420 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2023-04-28T17:21:07.724Z,1682702467.724 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2023-04-28T17:21:07.726Z,1682702467.726 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2023-04-28T17:21:07.727Z,1682702467.727 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2023-04-28T17:21:08.014Z,1682702468.014 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2023-04-28T17:21:08.183Z,1682702468.183 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2023-04-28T17:21:08.285Z,1682702468.285 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2023-04-28T17:21:08.436Z,1682702468.436 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2023-04-28T17:21:08.577Z,1682702468.577 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2023-04-28T17:21:08.707Z,1682702468.707 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2023-04-28T17:21:08.894Z,1682702468.894 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2023-04-28T17:21:08.971Z,1682702468.971 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2023-04-28T17:21:09.119Z,1682702469.119 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2023-04-28T17:21:09.256Z,1682702469.256 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2023-04-28T17:21:09.366Z,1682702469.366 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2023-04-28T17:21:09.633Z,1682702469.633 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2023-04-28T17:21:09.635Z,1682702469.635 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/
2023-04-28T17:21:09.635Z,1682702469.635 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2023-04-28T17:21:09.643Z,1682702469.643 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2023-04-28T17:21:09.695Z,1682702469.695 [VerticalControl](DEBUG): Construct VerticalControl.
2023-04-28T17:21:09.756Z,1682702469.756 [VerticalControl] Loaded
2023-04-28T17:21:09.756Z,1682702469.756 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2023-04-28T17:21:09.759Z,1682702469.759 [HorizontalControl](DEBUG): Construct HorizontalControl.
2023-04-28T17:21:09.801Z,1682702469.801 [HorizontalControl] Loaded
2023-04-28T17:21:09.801Z,1682702469.801 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2023-04-28T17:21:09.803Z,1682702469.803 [SpeedControl](DEBUG): Construct SpeedControl.
2023-04-28T17:21:09.806Z,1682702469.806 [SpeedControl] Loaded
2023-04-28T17:21:09.807Z,1682702469.807 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2023-04-28T17:21:09.809Z,1682702469.809 [LoopControl](DEBUG): Construct LoopControl.
2023-04-28T17:21:09.810Z,1682702469.810 [LoopControl] Loaded
2023-04-28T17:21:09.810Z,1682702469.810 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2023-04-28T17:21:09.811Z,1682702469.811 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2023-04-28T17:21:09.811Z,1682702469.811 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2023-04-28T17:21:09.821Z,1682702469.821 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2023-04-28T17:21:09.822Z,1682702469.822 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2023-04-28T17:21:09.976Z,1682702469.976 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2023-04-28T17:21:09.977Z,1682702469.977 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2023-04-28T17:21:10.134Z,1682702470.134 [BuoyancyServo] Loaded
2023-04-28T17:21:10.134Z,1682702470.134 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2023-04-28T17:21:10.154Z,1682702470.154 [ElevatorServo] Loaded
2023-04-28T17:21:10.155Z,1682702470.155 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2023-04-28T17:21:10.174Z,1682702470.174 [MassServo] Loaded
2023-04-28T17:21:10.174Z,1682702470.174 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2023-04-28T17:21:10.192Z,1682702470.192 [RudderServo] Loaded
2023-04-28T17:21:10.192Z,1682702470.192 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2023-04-28T17:21:10.210Z,1682702470.210 [ThrusterServo] Loaded
2023-04-28T17:21:10.210Z,1682702470.210 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2023-04-28T17:21:10.210Z,1682702470.210 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2023-04-28T17:21:10.211Z,1682702470.211 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2023-04-28T17:21:10.324Z,1682702470.324 [DeadReckonUsingMultipleVelocitySources] Loaded
2023-04-28T17:21:10.325Z,1682702470.325 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2023-04-28T17:21:10.338Z,1682702470.338 [NavChart] Loaded
2023-04-28T17:21:10.339Z,1682702470.339 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2023-04-28T17:21:10.344Z,1682702470.344 [UniversalFixResidualReporter] Loaded
2023-04-28T17:21:10.345Z,1682702470.345 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2023-04-28T17:21:10.345Z,1682702470.345 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2023-04-28T17:21:10.346Z,1682702470.346 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2023-04-28T17:21:10.403Z,1682702470.403 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2023-04-28T17:21:10.404Z,1682702470.404 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2023-04-28T17:21:10.828Z,1682702470.828 [AHRS_M2] Loaded
2023-04-28T17:21:10.828Z,1682702470.828 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2023-04-28T17:21:11.646Z,1682702471.646 [BPC1] Loaded
2023-04-28T17:21:11.646Z,1682702471.646 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2023-04-28T17:21:11.719Z,1682702471.719 [DataOverHttps] Loaded
2023-04-28T17:21:11.719Z,1682702471.719 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2023-04-28T17:21:11.720Z,1682702471.720 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408FD4E0
2023-04-28T17:21:11.720Z,1682702471.720 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1358
2023-04-28T17:21:11.741Z,1682702471.741 [Depth_Keller] Loaded
2023-04-28T17:21:11.742Z,1682702471.742 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2023-04-28T17:21:11.747Z,1682702471.747 [DropWeight] Loaded
2023-04-28T17:21:11.747Z,1682702471.747 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2023-04-28T17:21:11.809Z,1682702471.809 [NAL9602] Loaded
2023-04-28T17:21:11.809Z,1682702471.809 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2023-04-28T17:21:11.839Z,1682702471.839 [Onboard] Loaded
2023-04-28T17:21:11.839Z,1682702471.839 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2023-04-28T17:21:11.840Z,1682702471.840 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4092D4E0
2023-04-28T17:21:11.840Z,1682702471.840 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 1359
2023-04-28T17:21:11.854Z,1682702471.854 [Power24vConverter] Loaded
2023-04-28T17:21:11.854Z,1682702471.854 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2023-04-28T17:21:11.867Z,1682702471.867 [Radio_Surface] Loaded
2023-04-28T17:21:11.867Z,1682702471.867 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2023-04-28T17:21:11.869Z,1682702471.869 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4095D4E0
2023-04-28T17:21:11.869Z,1682702471.869 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1360
2023-04-28T17:21:11.870Z,1682702471.870 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2023-04-28T17:21:11.870Z,1682702471.870 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2023-04-28T17:21:11.923Z,1682702471.923 [DepthRateCalculator] Loaded
2023-04-28T17:21:11.923Z,1682702471.923 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2023-04-28T17:21:11.928Z,1682702471.928 [PitchRateCalculator] Loaded
2023-04-28T17:21:11.929Z,1682702471.929 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2023-04-28T17:21:11.938Z,1682702471.938 [SpeedCalculator] Loaded
2023-04-28T17:21:11.939Z,1682702471.939 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2023-04-28T17:21:11.943Z,1682702471.943 [YawRateCalculator] Loaded
2023-04-28T17:21:11.943Z,1682702471.943 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2023-04-28T17:21:11.962Z,1682702471.962 [ElevatorOffsetCalculator] Loaded
2023-04-28T17:21:11.962Z,1682702471.962 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2023-04-28T17:21:11.963Z,1682702471.963 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2023-04-28T17:21:11.964Z,1682702471.964 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2023-04-28T17:21:12.096Z,1682702472.096 [CANONSampler] Loaded
2023-04-28T17:21:12.096Z,1682702472.096 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2023-04-28T17:21:12.155Z,1682702472.155 [CTD_Seabird] Loaded
2023-04-28T17:21:12.156Z,1682702472.156 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2023-04-28T17:21:12.157Z,1682702472.157 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A164E0
2023-04-28T17:21:12.157Z,1682702472.157 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1361
2023-04-28T17:21:12.178Z,1682702472.178 [PAR_Licor] Loaded
2023-04-28T17:21:12.178Z,1682702472.178 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2023-04-28T17:21:12.210Z,1682702472.210 [WetLabsBB2FL] Loaded
2023-04-28T17:21:12.210Z,1682702472.210 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2023-04-28T17:21:12.211Z,1682702472.211 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A464E0
2023-04-28T17:21:12.211Z,1682702472.211 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1362
2023-04-28T17:21:12.212Z,1682702472.212 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2023-04-28T17:21:12.213Z,1682702472.213 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2023-04-28T17:21:12.240Z,1682702472.240 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2023-04-28T17:21:12.240Z,1682702472.240 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2023-04-28T17:21:12.559Z,1682702472.559 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2023-04-28T17:21:12.560Z,1682702472.560 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2023-04-28T17:21:12.704Z,1682702472.704 [SBIT](DEBUG): Construct Startup Built In Test.
2023-04-28T17:21:12.713Z,1682702472.713 [SBIT] Loaded
2023-04-28T17:21:12.713Z,1682702472.713 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2023-04-28T17:21:12.716Z,1682702472.716 [IBIT](DEBUG): Construct Initiated Built In Test.
2023-04-28T17:21:12.729Z,1682702472.729 [IBIT] Loaded
2023-04-28T17:21:12.729Z,1682702472.729 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2023-04-28T17:21:12.735Z,1682702472.735 [CBIT](DEBUG): Construct Continuous Built In Test.
2023-04-28T17:21:12.841Z,1682702472.841 [CBIT] Loaded
2023-04-28T17:21:12.842Z,1682702472.842 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2023-04-28T17:21:12.842Z,1682702472.842 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2023-04-28T17:21:12.843Z,1682702472.843 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2023-04-28T17:21:13.160Z,1682702473.160 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2023-04-28T17:21:13.207Z,1682702473.207 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2023-04-28T17:21:13.210Z,1682702473.210 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2023-04-28T17:21:13.221Z,1682702473.221 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2023-04-28T17:21:13.222Z,1682702473.222 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B7E4E0
2023-04-28T17:21:13.222Z,1682702473.222 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1363
2023-04-28T17:21:13.443Z,1682702473.443 [Supervisor](INFO): Main Thread ID is 829
2023-04-28T17:21:13.444Z,1682702473.444 [Supervisor](DEBUG): Running supervisor.
2023-04-28T17:21:13.444Z,1682702473.444 [CommandExec ThreadHandler](INFO): Handler Thread ID is 1364
2023-04-28T17:21:13.445Z,1682702473.445 [CommandExec](INFO): Initializing the command executive.
2023-04-28T17:21:13.447Z,1682702473.447 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1365
2023-04-28T17:21:13.450Z,1682702473.450 [controlThread ThreadHandler](INFO): Handler Thread ID is 1366
2023-04-28T17:21:13.450Z,1682702473.450 [controlThread](DEBUG): Initializing ControlThread
2023-04-28T17:21:13.451Z,1682702473.451 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2023-04-28T17:21:13.453Z,1682702473.453 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2023-04-28T17:21:13.454Z,1682702473.454 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2023-04-28T17:21:13.454Z,1682702473.454 [LoopControl](DEBUG): Initialize LoopControlComponent.
2023-04-28T17:21:13.456Z,1682702473.456 [NavChart](DEBUG): Initialize NavChart Navigation.
2023-04-28T17:21:13.456Z,1682702473.456 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2023-04-28T17:21:13.460Z,1682702473.460 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2023-04-28T17:21:13.460Z,1682702473.460 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2023-04-28T17:21:13.461Z,1682702473.461 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2023-04-28T17:21:13.461Z,1682702473.461 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2023-04-28T17:21:13.461Z,1682702473.461 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2023-04-28T17:21:13.466Z,1682702473.466 [SBIT](INFO): Initialize SBIT Component.
2023-04-28T17:21:13.467Z,1682702473.467 [SBIT](IMPORTANT): git: 2023-04-14_A
2023-04-28T17:21:13.467Z,1682702473.467 [SBIT](INFO): git hash: a5e7240676c499658609ad29f2edbd696bbbdf6d
2023-04-28T17:21:13.467Z,1682702473.467 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2023-04-28T17:21:13.468Z,1682702473.468 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2023-04-28T17:21:13.470Z,1682702473.470 [SBIT](INFO): Beginning SBIT in 63.000000 seconds.
2023-04-28T17:21:13.470Z,1682702473.470 [IBIT](INFO): Initialize IBIT Component.
2023-04-28T17:21:13.471Z,1682702473.471 [CBIT](DEBUG): Initialize CBIT Component.
2023-04-28T17:21:13.472Z,1682702473.472 [logger ThreadHandler](INFO): Handler Thread ID is 1367
2023-04-28T17:21:13.482Z,1682702473.482 [CBIT](DEBUG): Initialized mux pins.
2023-04-28T17:21:13.482Z,1682702473.482 [CBIT](DEBUG): Initializing the watchdog timer.
2023-04-28T17:21:13.491Z,1682702473.491 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1368
2023-04-28T17:21:13.492Z,1682702473.492 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2023-04-28T17:21:13.503Z,1682702473.503 [Onboard ThreadHandler](INFO): Handler Thread ID is 1369
2023-04-28T17:21:13.507Z,1682702473.507 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2023-04-28T17:21:13.507Z,1682702473.507 [CBIT](DEBUG): Initializing heartbeat.
2023-04-28T17:21:13.523Z,1682702473.523 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1370
2023-04-28T17:21:13.539Z,1682702473.539 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1371
2023-04-28T17:21:13.539Z,1682702473.539 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2023-04-28T17:21:13.544Z,1682702473.544 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1373
2023-04-28T17:21:13.547Z,1682702473.547 [WetLabsBB2FL](INFO): Powering up
2023-04-28T17:21:13.548Z,1682702473.548 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1375
2023-04-28T17:21:13.551Z,1682702473.551 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2023-04-28T17:21:13.551Z,1682702473.551 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2023-04-28T17:21:13.551Z,1682702473.551 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2023-04-28T17:21:13.552Z,1682702473.552 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2023-04-28T17:21:13.552Z,1682702473.552 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2023-04-28T17:21:13.552Z,1682702473.552 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2023-04-28T17:21:13.552Z,1682702473.552 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2023-04-28T17:21:13.552Z,1682702473.552 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2023-04-28T17:21:13.578Z,1682702473.578 [CBIT](DEBUG): Deactivating GF circuits.
2023-04-28T17:21:13.578Z,1682702473.578 [CBIT](DEBUG): Deactivating emergency mode.
2023-04-28T17:21:13.618Z,1682702473.618 [CBIT](DEBUG): Backplane powered.
2023-04-28T17:21:13.619Z,1682702473.619 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2023-04-28T17:21:13.632Z,1682702473.632 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2023-04-28T17:21:13.659Z,1682702473.659 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

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

    <Aggregate Id="StartupSatComms">

        <Sequence/>

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

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

    </Aggregate>

</Mission>


2023-04-28T17:21:13.659Z,1682702473.659 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2023-04-28T17:21:13.733Z,1682702473.733 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2023-04-28T17:21:13.734Z,1682702473.734 [Default:A.Wait](DEBUG): Construct Wait.
2023-04-28T17:21:13.736Z,1682702473.736 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-04-28T17:21:13.780Z,1682702473.780 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2023-04-28T17:21:13.783Z,1682702473.783 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2023-04-28T17:21:13.805Z,1682702473.805 [Default:E.Execute](DEBUG): Construct Execute.
2023-04-28T17:21:13.808Z,1682702473.808 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

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

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

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

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

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

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

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

    </Aggregate>

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

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

</Mission>


2023-04-28T17:21:13.832Z,1682702473.832 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2023-04-28T17:21:13.846Z,1682702473.846 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-04-28T17:21:13.913Z,1682702473.913 [Power24vConverter](INFO): Powering up.
2023-04-28T17:21:13.913Z,1682702473.913 [CANONSampler](INFO): Powering down
2023-04-28T17:21:13.926Z,1682702473.926 [Radio_Surface](INFO): Powering up
2023-04-28T17:21:13.964Z,1682702473.964 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2023-04-28T17:21:13.979Z,1682702473.979 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2023-04-28T17:21:13.980Z,1682702473.980 [ElevatorServo](DEBUG): Initializing EZServoServo.
2023-04-28T17:21:13.986Z,1682702473.986 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2023-04-28T17:21:13.987Z,1682702473.987 [MassServo](DEBUG): Initializing EZServoServo.
2023-04-28T17:21:13.994Z,1682702473.994 [MassServo](DEBUG): Initializing MassServo.
2023-04-28T17:21:13.995Z,1682702473.995 [RudderServo](DEBUG): Initializing EZServoServo.
2023-04-28T17:21:14.002Z,1682702474.002 [RudderServo](DEBUG): Initializing RudderServo.
2023-04-28T17:21:14.003Z,1682702474.003 [ThrusterServo](DEBUG): Initializing EZServoServo.
2023-04-28T17:21:14.011Z,1682702474.011 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2023-04-28T17:21:16.158Z,1682702476.158 [WetLabsBB2FL](INFO): Powering down
2023-04-28T17:21:42.124Z,1682702502.124 [NAL9602](INFO): Powering up NAL9602
2023-04-28T17:21:53.032Z,1682702513.032 [NAL9602](INFO): NAL9602 initialized
2023-04-28T17:22:07.985Z,1682702527.985 [NAL9602](INFO): SBD MO Status=0, MOMSN=42693, MT Status=0, MTMSN=0
2023-04-28T17:22:07.985Z,1682702527.985 [NAL9602](INFO): No messages in MT queue
2023-04-28T17:22:16.918Z,1682702536.918 [SBIT](IMPORTANT): Beginning Startup BIT
2023-04-28T17:22:16.922Z,1682702536.922 [CBIT](IMPORTANT): Beginning ground fault scan
2023-04-28T17:22:20.104Z,1682702540.104 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172218.00,A,3648.14397,N,12147.23205,W,0.156,0.00,280423,,,A*78
2023-04-28T17:22:20.107Z,1682702540.107 [NAL9602](INFO): GPS fix at 20230428T172218: (36.802399, -121.787201)
2023-04-28T17:22:27.879Z,1682702547.879 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2023-04-28T17:22:28.276Z,1682702548.276 [CBIT](IMPORTANT): Beginning ground fault scan
2023-04-28T17:22:29.420Z,1682702549.420 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-28T17:22:39.195Z,1682702559.195 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2023-04-28T17:22:39.603Z,1682702559.603 [CBIT](IMPORTANT): Beginning ground fault scan
2023-04-28T17:22:44.343Z,1682702564.343 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-28T17:22:50.491Z,1682702570.491 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.002585
CHAN A1 (24V): 0.000403
CHAN A2 (12V): -0.002103
CHAN A3 (5V): -0.001218
CHAN B0 (3.3V): -0.000030
CHAN B1 (3.15aV): -0.000222
CHAN B2 (3.15bV): -0.000079
CHAN B3 (GND): -0.000254
OPEN: -0.000647
Full Scale: +/- 1 mA
2023-04-28T17:22:52.431Z,1682702572.431 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-28T17:23:00.097Z,1682702580.097 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-28T17:23:11.055Z,1682702591.055 [SBIT](IMPORTANT): SBIT PASSED
2023-04-28T17:23:11.055Z,1682702591.055 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-04-28T17:23:11.056Z,1682702591.056 [SBIT](IMPORTANT): AMEcho.loadAtStartup=0 bool;

2023-04-28T17:23:11.056Z,1682702591.056 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=12 count;

2023-04-28T17:23:11.056Z,1682702591.056 [SBIT](IMPORTANT): CANONSampler.loadAtStartup=1 bool;

2023-04-28T17:23:11.056Z,1682702591.056 [SBIT](IMPORTANT): CBIT.runElevOffsetCalc=1 bool;

2023-04-28T17:23:11.056Z,1682702591.056 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool;

2023-04-28T17:23:11.056Z,1682702591.056 [SBIT](IMPORTANT): RudderServo.offsetAngle=0 degree;

2023-04-28T17:23:11.057Z,1682702591.057 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=210.806836 cubic_centimeter;

2023-04-28T17:23:11.057Z,1682702591.057 [SBIT](IMPORTANT): VerticalControl.massDefault=-10.801766 millimeter;

2023-04-28T17:23:11.431Z,1682702591.431 [MissionManager](IMPORTANT): Started mission Startup
2023-04-28T17:23:11.431Z,1682702591.431 [Startup] Running Loop=1
2023-04-28T17:23:11.431Z,1682702591.431 [Startup](DEBUG): Aggregate::initialize Startup
2023-04-28T17:23:11.432Z,1682702591.432 [Startup:A.GoToSurface] Running Loop=1
2023-04-28T17:23:11.432Z,1682702591.432 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-04-28T17:23:11.432Z,1682702591.432 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-04-28T17:23:11.433Z,1682702591.433 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-04-28T17:23:11.433Z,1682702591.433 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-04-28T17:23:11.433Z,1682702591.433 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-04-28T17:23:11.434Z,1682702591.434 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-04-28T17:23:11.435Z,1682702591.435 [Startup:StartupSatComms] Running Loop=1
2023-04-28T17:23:11.435Z,1682702591.435 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2023-04-28T17:23:11.435Z,1682702591.435 [Startup:StartupSatComms:A] Running Loop=1
2023-04-28T17:23:11.848Z,1682702591.848 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2023-04-28T17:23:13.449Z,1682702593.449 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172311.00,A,3648.14161,N,12147.22960,W,0.019,0.00,280423,,,A*78
2023-04-28T17:23:13.451Z,1682702593.451 [NAL9602](INFO): GPS fix at 20230428T172311: (36.802360, -121.787160)
2023-04-28T17:23:13.462Z,1682702593.462 [Startup:StartupSatComms:A] Stopped
2023-04-28T17:23:13.462Z,1682702593.462 [Startup:StartupSatComms:B] Running Loop=1
2023-04-28T17:23:13.879Z,1682702593.879 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-04-28T17:23:15.050Z,1682702595.050 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2023-04-28T17:23:34.513Z,1682702614.513 [NAL9602](INFO): SBD MO Status=1, MOMSN=42694, MT Status=0, MTMSN=0
2023-04-28T17:23:34.566Z,1682702614.566 [NAL9602](INFO): Sent 39 bytes from file Logs/20230428T165459/Courier0013.lzma
2023-04-28T17:23:34.567Z,1682702614.567 [NAL9602](INFO): Packets left to send: 0
2023-04-28T17:23:45.081Z,1682702625.081 [NAL9602](INFO): SBD MO Status=1, MOMSN=42695, MT Status=0, MTMSN=0
2023-04-28T17:23:45.135Z,1682702625.135 [NAL9602](INFO): Sent 269 bytes from file Logs/20230428T172103/Courier0000.lzma
2023-04-28T17:23:45.135Z,1682702625.135 [NAL9602](INFO): Packets left to send: 0
2023-04-28T17:23:56.037Z,1682702636.037 [NAL9602](INFO): SBD MO Status=1, MOMSN=42696, MT Status=0, MTMSN=0
2023-04-28T17:23:56.099Z,1682702636.099 [NAL9602](INFO): Sent 136 bytes from file Logs/20230428T165459/Express0014.lzma
2023-04-28T17:23:56.099Z,1682702636.099 [NAL9602](INFO): Packets left to send: 0
2023-04-28T17:24:12.241Z,1682702652.241 [NAL9602](INFO): SBD MO Status=2, MOMSN=42697, MT Status=2, MTMSN=0
2023-04-28T17:24:12.241Z,1682702652.241 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-04-28T17:24:13.495Z,1682702653.495 [Startup:StartupSatComms:B](INFO): Timed out from 2023-04-28T17:23:13.5Z
2023-04-28T17:24:13.495Z,1682702653.495 [Startup:StartupSatComms:B] Stopped
2023-04-28T17:24:13.496Z,1682702653.496 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2023-04-28T17:24:13.496Z,1682702653.496 [Startup:StartupSatComms] Stopped
2023-04-28T17:24:13.496Z,1682702653.496 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2023-04-28T17:24:13.497Z,1682702653.497 [Startup](INFO): Completed Startup
2023-04-28T17:24:13.497Z,1682702653.497 [MissionManager](INFO): Startup is completed.
2023-04-28T17:24:13.497Z,1682702653.497 [MissionManager](INFO): Uninitializing Mission Startup
2023-04-28T17:24:13.497Z,1682702653.497 [Startup] Stopped
2023-04-28T17:24:13.497Z,1682702653.497 [Startup](DEBUG): Aggregate::uninitialize Startup
2023-04-28T17:24:13.497Z,1682702653.497 [Startup:A.GoToSurface] Stopped
2023-04-28T17:24:13.497Z,1682702653.497 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-04-28T17:24:13.871Z,1682702653.871 [MissionManager](IMPORTANT): Started mission Default
2023-04-28T17:24:13.872Z,1682702653.872 [Default] Running Loop=1
2023-04-28T17:24:13.872Z,1682702653.872 [Default](DEBUG): Aggregate::initialize Default
2023-04-28T17:24:13.872Z,1682702653.872 [Default:B.GoToSurface] Running Loop=1
2023-04-28T17:24:13.872Z,1682702653.872 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-04-28T17:24:13.872Z,1682702653.872 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-04-28T17:24:13.872Z,1682702653.872 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-04-28T17:24:13.873Z,1682702653.873 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-04-28T17:24:13.873Z,1682702653.873 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-04-28T17:24:13.873Z,1682702653.873 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-04-28T17:24:13.874Z,1682702653.874 [Default:A.Wait] Running Loop=1
2023-04-28T17:24:13.874Z,1682702653.874 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-04-28T17:24:27.206Z,1682702667.206 [Default:A.Wait](INFO): Done Waiting.
2023-04-28T17:24:27.206Z,1682702667.206 [Default:A.Wait] Stopped
2023-04-28T17:24:27.206Z,1682702667.206 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-04-28T17:24:27.623Z,1682702667.623 [Default:CheckIn] Running Loop=1
2023-04-28T17:24:27.623Z,1682702667.623 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-28T17:24:27.623Z,1682702667.623 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-28T17:24:28.039Z,1682702668.039 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-04-28T17:24:29.617Z,1682702669.617 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172427.00,A,3648.14084,N,12147.22941,W,0.039,0.00,280423,,,A*71
2023-04-28T17:24:29.620Z,1682702669.620 [NAL9602](INFO): GPS fix at 20230428T172427: (36.802347, -121.787157)
2023-04-28T17:24:29.647Z,1682702669.647 [Default:CheckIn:Read_GPS] Stopped
2023-04-28T17:24:29.647Z,1682702669.647 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-28T17:24:30.065Z,1682702670.065 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-04-28T17:25:07.136Z,1682702707.136 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004469
2023-04-28T17:25:14.442Z,1682702714.442 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230428T172103/Courier0004.lzma
2023-04-28T17:25:15.444Z,1682702715.444 [DataOverHttps](INFO): Moved sent file to Logs/20230428T172103/Courier0004.lzma.bak
2023-04-28T17:25:15.444Z,1682702715.444 [DataOverHttps](INFO): SBD MOMSN=18272488
2023-04-28T17:25:18.541Z,1682702718.541 [NAL9602](INFO): SBD MO Status=2, MOMSN=42697, MT Status=2, MTMSN=0
2023-04-28T17:25:18.541Z,1682702718.541 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-04-28T17:25:34.867Z,1682702734.867 [DataOverHttps](INFO): Sending 875 bytes from file Logs/20230428T172103/Express0001.lzma
2023-04-28T17:25:35.868Z,1682702735.868 [DataOverHttps](INFO): Moved sent file to Logs/20230428T172103/Express0001.lzma.bak
2023-04-28T17:25:35.868Z,1682702735.868 [DataOverHttps](INFO): SBD MOMSN=18272491
2023-04-28T17:25:49.279Z,1682702749.279 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-28T17:25:51.878Z,1682702751.878 [DataOverHttps](INFO): Sending 103 bytes from file Logs/20230428T172103/Express0005.lzma
2023-04-28T17:25:52.880Z,1682702752.880 [DataOverHttps](INFO): Moved sent file to Logs/20230428T172103/Express0005.lzma.bak
2023-04-28T17:25:52.880Z,1682702752.880 [DataOverHttps](INFO): SBD MOMSN=18272512
2023-04-28T17:25:54.149Z,1682702754.149 [Default:CheckIn:Read_Iridium] Stopped
2023-04-28T17:25:54.150Z,1682702754.150 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-28T17:25:54.150Z,1682702754.150 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-28T17:28:34.255Z,1682702914.255 [DataOverHttps](IMPORTANT): SBD MTMSN=20230428T172833
2023-04-28T17:28:44.978Z,1682702924.978 [DataOverHttps](INFO): Received command: ibit
2023-04-28T17:28:44.980Z,1682702924.980 [CommandExec](IMPORTANT): got command ibit
2023-04-28T17:28:45.072Z,1682702925.072 [IBIT](IMPORTANT): Beginning Initiated BIT
2023-04-28T17:28:45.072Z,1682702925.072 [IBIT](IMPORTANT): Beginning control surface checks.
2023-04-28T17:28:45.080Z,1682702925.080 [CBIT](IMPORTANT): Beginning ground fault scan
2023-04-28T17:28:46.641Z,1682702926.641 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172845.00,A,3648.13983,N,12147.22932,W,0.000,0.00,280423,,,A*7E
2023-04-28T17:28:46.644Z,1682702926.644 [NAL9602](INFO): GPS fix at 20230428T172845: (36.802330, -121.787155)
2023-04-28T17:28:56.001Z,1682702936.001 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2023-04-28T17:28:56.388Z,1682702936.388 [CBIT](IMPORTANT): Beginning ground fault scan
2023-04-28T17:29:01.999Z,1682702941.999 [NAL9602](INFO): SBD MO Status=1, MOMSN=42697, MT Status=0, MTMSN=0
2023-04-28T17:29:01.999Z,1682702941.999 [NAL9602](INFO): No messages in MT queue
2023-04-28T17:29:03.265Z,1682702943.265 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172902.00,A,3648.13963,N,12147.22923,W,0.058,0.00,280423,,,A*7F
2023-04-28T17:29:03.268Z,1682702943.268 [NAL9602](INFO): GPS fix at 20230428T172902: (36.802327, -121.787154)
2023-04-28T17:29:06.028Z,1682702946.028 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172905.00,A,3648.13966,N,12147.22925,W,0.156,0.00,280423,,,A*74
2023-04-28T17:29:06.031Z,1682702946.031 [NAL9602](INFO): GPS fix at 20230428T172905: (36.802328, -121.787154)
2023-04-28T17:29:07.342Z,1682702947.342 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.002547
CHAN A1 (24V): 0.000460
CHAN A2 (12V): -0.002154
CHAN A3 (5V): -0.001333
CHAN B0 (3.3V): 0.000043
CHAN B1 (3.15aV): 0.000228
CHAN B2 (3.15bV): 0.000042
CHAN B3 (GND): 0.000132
OPEN: -0.000389
Full Scale: +/- 1 mA
2023-04-28T17:29:09.007Z,1682702949.007 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172908.00,A,3648.13972,N,12147.22931,W,0.058,0.00,280423,,,A*76
2023-04-28T17:29:09.009Z,1682702949.009 [NAL9602](INFO): GPS fix at 20230428T172908: (36.802329, -121.787155)
2023-04-28T17:29:12.089Z,1682702952.089 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172911.00,A,3648.13981,N,12147.22932,W,0.039,0.00,280423,,,A*76
2023-04-28T17:29:12.092Z,1682702952.092 [NAL9602](INFO): GPS fix at 20230428T172911: (36.802330, -121.787155)
2023-04-28T17:29:14.916Z,1682702954.916 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172914.00,A,3648.13990,N,12147.22934,W,0.078,0.00,280423,,,A*70
2023-04-28T17:29:14.919Z,1682702954.919 [NAL9602](INFO): GPS fix at 20230428T172914: (36.802332, -121.787156)
2023-04-28T17:29:17.765Z,1682702957.765 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172917.00,A,3648.13996,N,12147.22934,W,0.058,0.00,280423,,,A*77
2023-04-28T17:29:17.768Z,1682702957.768 [NAL9602](INFO): GPS fix at 20230428T172917: (36.802333, -121.787156)
2023-04-28T17:29:20.981Z,1682702960.981 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172920.00,A,3648.14002,N,12147.22937,W,0.058,0.00,280423,,,A*73
2023-04-28T17:29:20.983Z,1682702960.983 [NAL9602](INFO): GPS fix at 20230428T172920: (36.802334, -121.787156)
2023-04-28T17:29:23.827Z,1682702963.827 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172923.00,A,3648.14009,N,12147.22941,W,0.078,0.00,280423,,,A*78
2023-04-28T17:29:23.829Z,1682702963.829 [NAL9602](INFO): GPS fix at 20230428T172923: (36.802335, -121.787157)
2023-04-28T17:29:27.041Z,1682702967.041 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172926.00,A,3648.14015,N,12147.22945,W,0.039,0.00,280423,,,A*71
2023-04-28T17:29:27.043Z,1682702967.043 [NAL9602](INFO): GPS fix at 20230428T172926: (36.802336, -121.787158)
2023-04-28T17:29:29.932Z,1682702969.932 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172929.00,A,3648.14015,N,12147.22948,W,0.078,0.00,280423,,,A*76
2023-04-28T17:29:29.934Z,1682702969.934 [NAL9602](INFO): GPS fix at 20230428T172929: (36.802336, -121.787158)
2023-04-28T17:29:31.119Z,1682702971.119 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 4
Latitude: 36.802338 Longitude: -121.787155
2023-04-28T17:29:31.499Z,1682702971.499 [IBIT](FAULT): Warning: Battery Data not active. Expected only when running primaries. Threshold checking not active.
2023-04-28T17:29:31.907Z,1682702971.907 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2023-04-28T17:29:31.907Z,1682702971.907 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2023-04-28T17:29:31.908Z,1682702971.908 [IBIT](IMPORTANT): Pressure:9.863957 PSI
2023-04-28T17:29:31.908Z,1682702971.908 [IBIT](IMPORTANT): Humidity:1.684776 %
2023-04-28T17:29:32.321Z,1682702972.321 [IBIT](IMPORTANT): Vehicle Pitch:-0.860961 degrees
2023-04-28T17:29:32.322Z,1682702972.322 [IBIT](IMPORTANT): Vehicle  Roll:-9.181691 degrees
2023-04-28T17:29:32.322Z,1682702972.322 [IBIT](IMPORTANT): Vehicle  Heading:15.716091 degrees
2023-04-28T17:29:32.728Z,1682702972.728 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2023-04-28T17:29:32.728Z,1682702972.728 [IBIT](IMPORTANT): buoyancyNeutral: 210.806839 cc
2023-04-28T17:29:32.728Z,1682702972.728 [IBIT](IMPORTANT): massDefault: -1.080177 cm
2023-04-28T17:29:32.729Z,1682702972.729 [IBIT](IMPORTANT): stopDepth: 250.000000 m
2023-04-28T17:29:32.729Z,1682702972.729 [IBIT](IMPORTANT): abortDepth: 270.000000 m
2023-04-28T17:29:32.729Z,1682702972.729 [IBIT](IMPORTANT): IBIT PASSED
2023-04-28T17:30:02.649Z,1682703002.649 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-28T17:30:29.264Z,1682703029.264 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-28T17:30:44.617Z,1682703044.617 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-28T17:30:54.759Z,1682703054.759 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-28T17:30:54.759Z,1682703054.759 [Default:CheckIn:C.Wait] Stopped
2023-04-28T17:30:54.759Z,1682703054.759 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-28T17:30:54.759Z,1682703054.759 [Default:CheckIn:D] Running Loop=1
2023-04-28T17:30:55.135Z,1682703055.135 [Default:CheckIn:D] Stopped
2023-04-28T17:30:55.135Z,1682703055.135 [Default:CheckIn:E] Running Loop=1
2023-04-28T17:30:55.541Z,1682703055.541 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 6.687717 min 
2023-04-28T17:30:55.542Z,1682703055.542 [Default:CheckIn:E] Stopped
2023-04-28T17:30:55.542Z,1682703055.542 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-28T17:30:55.542Z,1682703055.542 [Default:CheckIn] Stopped
2023-04-28T17:30:55.543Z,1682703055.543 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-28T17:30:55.543Z,1682703055.543 [Default:CheckIn](INFO): Running loop #2
2023-04-28T17:30:55.543Z,1682703055.543 [Default:CheckIn] Running Loop=2
2023-04-28T17:30:55.543Z,1682703055.543 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-28T17:30:55.543Z,1682703055.543 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-28T17:30:57.549Z,1682703057.549 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173056.00,A,3648.14005,N,12147.22965,W,0.039,0.00,280423,,,D*78
2023-04-28T17:30:57.552Z,1682703057.552 [NAL9602](INFO): GPS fix at 20230428T173056: (36.802334, -121.787161)
2023-04-28T17:30:57.590Z,1682703057.590 [Default:CheckIn:Read_GPS] Stopped
2023-04-28T17:30:57.590Z,1682703057.590 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-28T17:30:59.971Z,1682703059.971 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-28T17:31:03.317Z,1682703063.317 [NAL9602](INFO): SBD MO Status=1, MOMSN=42698, MT Status=0, MTMSN=0
2023-04-28T17:31:03.317Z,1682703063.317 [NAL9602](INFO): No messages in MT queue
2023-04-28T17:31:05.457Z,1682703065.457 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230428T172103/Courier0007.lzma
2023-04-28T17:31:06.472Z,1682703066.472 [DataOverHttps](INFO): Moved sent file to Logs/20230428T172103/Courier0007.lzma.bak
2023-04-28T17:31:06.472Z,1682703066.472 [DataOverHttps](INFO): SBD MOMSN=18272526
2023-04-28T17:31:14.918Z,1682703074.918 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-28T17:31:14.927Z,1682703074.927 [Power24vConverter](INFO): Powering down.
2023-04-28T17:31:22.535Z,1682703082.535 [DataOverHttps](INFO): Sending 830 bytes from file Logs/20230428T172103/Express0008.lzma
2023-04-28T17:31:23.536Z,1682703083.536 [DataOverHttps](INFO): Moved sent file to Logs/20230428T172103/Express0008.lzma.bak
2023-04-28T17:31:23.536Z,1682703083.536 [DataOverHttps](INFO): SBD MOMSN=18272532
2023-04-28T17:31:29.864Z,1682703089.864 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-28T17:31:33.906Z,1682703093.906 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-28T17:31:39.558Z,1682703099.558 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20230428T172103/Express0011.lzma
2023-04-28T17:31:40.560Z,1682703100.560 [DataOverHttps](INFO): Moved sent file to Logs/20230428T172103/Express0011.lzma.bak
2023-04-28T17:31:40.560Z,1682703100.560 [DataOverHttps](INFO): SBD MOMSN=18272557
2023-04-28T17:31:41.605Z,1682703101.605 [Default:CheckIn:Read_Iridium] Stopped
2023-04-28T17:31:41.605Z,1682703101.605 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-28T17:31:41.605Z,1682703101.605 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-28T17:31:45.221Z,1682703105.221 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-28T17:32:00.972Z,1682703120.972 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-28T17:32:15.920Z,1682703135.920 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-28T17:32:30.868Z,1682703150.868 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-28T17:32:45.817Z,1682703165.817 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-28T17:36:42.361Z,1682703402.361 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-28T17:36:42.361Z,1682703402.361 [Default:CheckIn:C.Wait] Stopped
2023-04-28T17:36:42.361Z,1682703402.361 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-28T17:36:42.361Z,1682703402.361 [Default:CheckIn:D] Running Loop=1
2023-04-28T17:36:42.745Z,1682703402.745 [Default:CheckIn:D] Stopped
2023-04-28T17:36:42.745Z,1682703402.745 [Default:CheckIn:E] Running Loop=1
2023-04-28T17:36:43.159Z,1682703403.159 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.481223 min 
2023-04-28T17:36:43.159Z,1682703403.159 [Default:CheckIn:E] Stopped
2023-04-28T17:36:43.160Z,1682703403.160 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-28T17:36:43.160Z,1682703403.160 [Default:CheckIn] Stopped
2023-04-28T17:36:43.160Z,1682703403.160 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-28T17:36:43.160Z,1682703403.160 [Default:CheckIn](INFO): Running loop #3
2023-04-28T17:36:43.160Z,1682703403.160 [Default:CheckIn] Running Loop=3
2023-04-28T17:36:43.160Z,1682703403.160 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-28T17:36:43.160Z,1682703403.160 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-28T17:36:45.165Z,1682703405.165 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173644.00,A,3648.13947,N,12147.22933,W,0.039,0.00,280423,,,D*76
2023-04-28T17:36:45.167Z,1682703405.167 [NAL9602](INFO): GPS fix at 20230428T173644: (36.802324, -121.787155)
2023-04-28T17:36:45.177Z,1682703405.177 [Default:CheckIn:Read_GPS] Stopped
2023-04-28T17:36:45.177Z,1682703405.177 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-28T17:36:56.117Z,1682703416.117 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230428T172103/Courier0013.lzma
2023-04-28T17:36:57.120Z,1682703417.120 [DataOverHttps](INFO): Moved sent file to Logs/20230428T172103/Courier0013.lzma.bak
2023-04-28T17:36:57.120Z,1682703417.120 [DataOverHttps](INFO): SBD MOMSN=18272561
2023-04-28T17:37:05.676Z,1682703425.676 [DataOverHttps](IMPORTANT): SBD MTMSN=20230428T173704
2023-04-28T17:37:11.087Z,1682703431.087 [NAL9602](INFO): SBD MO Status=2, MOMSN=42699, MT Status=2, MTMSN=0
2023-04-28T17:37:11.087Z,1682703431.087 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-04-28T17:37:13.146Z,1682703433.146 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230428T172103/Express0014.lzma
2023-04-28T17:37:13.156Z,1682703433.156 [DataOverHttps](INFO): Received command: get VerticalHomogeneityIndexCalculator.loadAtStartup
2023-04-28T17:37:14.592Z,1682703434.592 [DataOverHttps](INFO): Moved sent file to Logs/20230428T172103/Express0014.lzma.bak
2023-04-28T17:37:14.592Z,1682703434.592 [DataOverHttps](INFO): SBD MOMSN=18272565
2023-04-28T17:37:14.992Z,1682703434.992 [CommandExec](IMPORTANT): got command get VerticalHomogeneityIndexCalculator.loadAtStartup
2023-04-28T17:37:14.992Z,1682703434.992 [CommandExec](IMPORTANT): VerticalHomogeneityIndexCalculator.loadAtStartup 0 bool
2023-04-28T17:37:28.453Z,1682703448.453 [NAL9602](INFO): SBD MO Status=2, MOMSN=42699, MT Status=2, MTMSN=0
2023-04-28T17:37:28.453Z,1682703448.453 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-04-28T17:37:30.005Z,1682703450.005 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20230428T172103/Courier0016.lzma
2023-04-28T17:37:31.008Z,1682703451.008 [DataOverHttps](INFO): Moved sent file to Logs/20230428T172103/Courier0016.lzma.bak
2023-04-28T17:37:31.008Z,1682703451.008 [DataOverHttps](INFO): SBD MOMSN=18272569
2023-04-28T17:37:38.961Z,1682703458.961 [NAL9602](INFO): SBD MO Status=1, MOMSN=42699, MT Status=0, MTMSN=0
2023-04-28T17:37:38.961Z,1682703458.961 [NAL9602](INFO): No messages in MT queue
2023-04-28T17:37:47.170Z,1682703467.170 [DataOverHttps](INFO): Sending 105 bytes from file Logs/20230428T172103/Express0017.lzma
2023-04-28T17:37:48.172Z,1682703468.172 [DataOverHttps](INFO): Moved sent file to Logs/20230428T172103/Express0017.lzma.bak
2023-04-28T17:37:48.172Z,1682703468.172 [DataOverHttps](INFO): SBD MOMSN=18272571
2023-04-28T17:37:49.513Z,1682703469.513 [Default:CheckIn:Read_Iridium] Stopped
2023-04-28T17:37:49.513Z,1682703469.513 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-28T17:37:49.513Z,1682703469.513 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-28T17:38:09.659Z,1682703489.659 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-28T17:40:03.278Z,1682703603.278 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-28T17:40:18.629Z,1682703618.629 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-28T17:40:33.589Z,1682703633.589 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-28T17:40:49.345Z,1682703649.345 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-28T17:41:04.696Z,1682703664.696 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-28T17:41:20.049Z,1682703680.049 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-28T17:41:35.400Z,1682703695.400 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-28T17:41:50.754Z,1682703710.754 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-28T17:42:06.536Z,1682703726.536 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-28T17:42:21.485Z,1682703741.485 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2023-04-28T17:42:50.186Z,1682703770.186 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-28T17:42:50.186Z,1682703770.186 [Default:CheckIn:C.Wait] Stopped
2023-04-28T17:42:50.186Z,1682703770.186 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-28T17:42:50.219Z,1682703770.219 [Default:CheckIn:D] Running Loop=1
2023-04-28T17:42:50.585Z,1682703770.585 [Default:CheckIn:D] Stopped
2023-04-28T17:42:50.585Z,1682703770.585 [Default:CheckIn:E] Running Loop=1
2023-04-28T17:42:51.026Z,1682703771.026 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 18.611886 min 
2023-04-28T17:42:51.030Z,1682703771.030 [Default:CheckIn:E] Stopped
2023-04-28T17:42:51.030Z,1682703771.030 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-28T17:42:51.030Z,1682703771.030 [Default:CheckIn] Stopped
2023-04-28T17:42:51.031Z,1682703771.031 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-28T17:42:51.031Z,1682703771.031 [Default:CheckIn](INFO): Running loop #4
2023-04-28T17:42:51.031Z,1682703771.031 [Default:CheckIn] Running Loop=4
2023-04-28T17:42:51.031Z,1682703771.031 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-28T17:42:51.031Z,1682703771.031 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-28T17:42:53.045Z,1682703773.045 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174252.00,A,3648.13896,N,12147.22899,W,0.019,0.00,280423,,,D*7C
2023-04-28T17:42:53.047Z,1682703773.047 [NAL9602](INFO): GPS fix at 20230428T174252: (36.802316, -121.787150)
2023-04-28T17:42:53.097Z,1682703773.097 [Default:CheckIn:Read_GPS] Stopped
2023-04-28T17:42:53.097Z,1682703773.097 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-28T17:43:01.846Z,1682703781.846 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230428T172103/Courier0019.lzma
2023-04-28T17:43:02.848Z,1682703782.848 [DataOverHttps](INFO): Moved sent file to Logs/20230428T172103/Courier0019.lzma.bak
2023-04-28T17:43:02.848Z,1682703782.848 [DataOverHttps](INFO): SBD MOMSN=18272579
2023-04-28T17:43:09.880Z,1682703789.880 [NAL9602](INFO): SBD MO Status=1, MOMSN=42700, MT Status=0, MTMSN=0
2023-04-28T17:43:09.880Z,1682703789.880 [NAL9602](INFO): No messages in MT queue
2023-04-28T17:43:18.778Z,1682703798.778 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20230428T172103/Express0020.lzma
2023-04-28T17:43:19.780Z,1682703799.780 [DataOverHttps](INFO): Moved sent file to Logs/20230428T172103/Express0020.lzma.bak
2023-04-28T17:43:19.780Z,1682703799.780 [DataOverHttps](INFO): SBD MOMSN=18272582
2023-04-28T17:43:20.817Z,1682703800.817 [Default:CheckIn:Read_Iridium] Stopped
2023-04-28T17:43:20.817Z,1682703800.817 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-28T17:43:20.817Z,1682703800.817 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-28T17:43:21.600Z,1682703801.600 [BPC1](INFO): Calculating totals. Valid battery stick count: 47. Valid reserve battery stick count: 5.
2023-04-28T17:43:21.603Z,1682703801.603 [BPC1](INFO): Received data from all battery sticks.
2023-04-28T17:43:40.610Z,1682703820.610 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-28T17:48:21.403Z,1682704101.403 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-28T17:48:21.403Z,1682704101.403 [Default:CheckIn:C.Wait] Stopped
2023-04-28T17:48:21.403Z,1682704101.403 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-28T17:48:21.403Z,1682704101.403 [Default:CheckIn:D] Running Loop=1
2023-04-28T17:48:21.817Z,1682704101.817 [Default:CheckIn:D] Stopped
2023-04-28T17:48:21.817Z,1682704101.817 [Default:CheckIn:E] Running Loop=1
2023-04-28T17:48:22.230Z,1682704102.230 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 24.132424 min 
2023-04-28T17:48:22.230Z,1682704102.230 [Default:CheckIn:E] Stopped
2023-04-28T17:48:22.230Z,1682704102.230 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-28T17:48:22.231Z,1682704102.231 [Default:CheckIn] Stopped
2023-04-28T17:48:22.231Z,1682704102.231 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-28T17:48:22.231Z,1682704102.231 [Default:CheckIn](INFO): Running loop #5
2023-04-28T17:48:22.231Z,1682704102.231 [Default:CheckIn] Running Loop=5
2023-04-28T17:48:22.231Z,1682704102.231 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-28T17:48:22.231Z,1682704102.231 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-28T17:48:24.225Z,1682704104.225 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174823.00,A,3648.13897,N,12147.22958,W,0.000,0.00,280423,,,D*75
2023-04-28T17:48:24.228Z,1682704104.228 [NAL9602](INFO): GPS fix at 20230428T174823: (36.802316, -121.787160)
2023-04-28T17:48:24.238Z,1682704104.238 [Default:CheckIn:Read_GPS] Stopped
2023-04-28T17:48:24.238Z,1682704104.238 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-28T17:48:31.554Z,1682704111.554 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20230428T172103/Courier0022.lzma
2023-04-28T17:48:32.556Z,1682704112.556 [DataOverHttps](INFO): Moved sent file to Logs/20230428T172103/Courier0022.lzma.bak
2023-04-28T17:48:32.556Z,1682704112.556 [DataOverHttps](INFO): SBD MOMSN=18272594
2023-04-28T17:48:36.749Z,1682704116.749 [NAL9602](INFO): SBD MO Status=1, MOMSN=42701, MT Status=0, MTMSN=0
2023-04-28T17:48:36.749Z,1682704116.749 [NAL9602](INFO): No messages in MT queue
2023-04-28T17:48:49.166Z,1682704129.166 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230428T172103/Express0023.lzma
2023-04-28T17:48:50.168Z,1682704130.168 [DataOverHttps](INFO): Moved sent file to Logs/20230428T172103/Express0023.lzma.bak
2023-04-28T17:48:50.169Z,1682704130.169 [DataOverHttps](INFO): SBD MOMSN=18272597
2023-04-28T17:48:51.301Z,1682704131.301 [Default:CheckIn:Read_Iridium] Stopped
2023-04-28T17:48:51.301Z,1682704131.301 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-28T17:48:51.301Z,1682704131.301 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-28T17:49:07.449Z,1682704147.449 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-28T17:53:51.889Z,1682704431.889 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-28T17:53:51.889Z,1682704431.889 [Default:CheckIn:C.Wait] Stopped
2023-04-28T17:53:51.889Z,1682704431.889 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-28T17:53:51.889Z,1682704431.889 [Default:CheckIn:D] Running Loop=1
2023-04-28T17:53:52.287Z,1682704432.287 [Default:CheckIn:D] Stopped
2023-04-28T17:53:52.288Z,1682704432.288 [Default:CheckIn:E] Running Loop=1
2023-04-28T17:53:52.697Z,1682704432.697 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 29.640263 min 
2023-04-28T17:53:52.698Z,1682704432.698 [Default:CheckIn:E] Stopped
2023-04-28T17:53:52.698Z,1682704432.698 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-28T17:53:52.698Z,1682704432.698 [Default:CheckIn] Stopped
2023-04-28T17:53:52.698Z,1682704432.698 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-28T17:53:52.698Z,1682704432.698 [Default:CheckIn](INFO): Running loop #6
2023-04-28T17:53:52.698Z,1682704432.698 [Default:CheckIn] Running Loop=6
2023-04-28T17:53:52.698Z,1682704432.698 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-28T17:53:52.698Z,1682704432.698 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-28T17:53:54.712Z,1682704434.712 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175353.00,A,3648.15337,N,12147.22182,W,0.039,161.49,280423,,,D*71
2023-04-28T17:53:54.715Z,1682704434.715 [NAL9602](INFO): GPS fix at 20230428T175353: (36.802556, -121.787030)
2023-04-28T17:53:54.725Z,1682704434.725 [Default:CheckIn:Read_GPS] Stopped
2023-04-28T17:53:54.725Z,1682704434.725 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-28T17:54:02.341Z,1682704442.341 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230428T172103/Courier0025.lzma
2023-04-28T17:54:03.344Z,1682704443.344 [DataOverHttps](INFO): Moved sent file to Logs/20230428T172103/Courier0025.lzma.bak
2023-04-28T17:54:03.344Z,1682704443.344 [DataOverHttps](INFO): SBD MOMSN=18272606
2023-04-28T17:54:20.598Z,1682704460.598 [DataOverHttps](INFO): Sending 138 bytes from file Logs/20230428T172103/Express0026.lzma
2023-04-28T17:54:21.600Z,1682704461.600 [DataOverHttps](INFO): Moved sent file to Logs/20230428T172103/Express0026.lzma.bak
2023-04-28T17:54:21.600Z,1682704461.600 [DataOverHttps](INFO): SBD MOMSN=18272609
2023-04-28T17:54:23.022Z,1682704463.022 [Default:CheckIn:Read_Iridium] Stopped
2023-04-28T17:54:23.022Z,1682704463.022 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-28T17:54:23.022Z,1682704463.022 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-28T17:55:02.626Z,1682704502.626 [NAL9602](INFO): SBD MO Status=2, MOMSN=42702, MT Status=2, MTMSN=0
2023-04-28T17:55:02.626Z,1682704502.626 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-04-28T17:55:48.281Z,1682704548.281 [NAL9602](INFO): SBD MO Status=2, MOMSN=42702, MT Status=2, MTMSN=0
2023-04-28T17:55:48.281Z,1682704548.281 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-04-28T17:56:12.519Z,1682704572.519 [NAL9602](INFO): SBD MO Status=2, MOMSN=42702, MT Status=2, MTMSN=0
2023-04-28T17:56:12.520Z,1682704572.520 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-04-28T17:56:42.837Z,1682704602.837 [NAL9602](INFO): SBD MO Status=1, MOMSN=42702, MT Status=0, MTMSN=0
2023-04-28T17:56:42.837Z,1682704602.837 [NAL9602](INFO): No messages in MT queue
2023-04-28T17:57:13.522Z,1682704633.522 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-28T17:59:23.628Z,1682704763.628 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-28T17:59:23.628Z,1682704763.628 [Default:CheckIn:C.Wait] Stopped
2023-04-28T17:59:23.628Z,1682704763.628 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-28T17:59:23.629Z,1682704763.629 [Default:CheckIn:D] Running Loop=1
2023-04-28T17:59:24.034Z,1682704764.034 [Default:CheckIn:D] Stopped
2023-04-28T17:59:24.034Z,1682704764.034 [Default:CheckIn:E] Running Loop=1
2023-04-28T17:59:24.427Z,1682704764.427 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 35.169364 min 
2023-04-28T17:59:24.428Z,1682704764.428 [Default:CheckIn:E] Stopped
2023-04-28T17:59:24.428Z,1682704764.428 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-28T17:59:24.428Z,1682704764.428 [Default:CheckIn] Stopped
2023-04-28T17:59:24.428Z,1682704764.428 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-28T17:59:24.428Z,1682704764.428 [Default:CheckIn](INFO): Running loop #7
2023-04-28T17:59:24.428Z,1682704764.428 [Default:CheckIn] Running Loop=7
2023-04-28T17:59:24.428Z,1682704764.428 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-28T17:59:24.428Z,1682704764.428 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-28T17:59:26.449Z,1682704766.449 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175925.00,A,3648.27529,N,12147.12715,W,5.384,4.03,280423,,,D*75
2023-04-28T17:59:26.453Z,1682704766.453 [NAL9602](INFO): GPS fix at 20230428T175925: (36.804588, -121.785453)
2023-04-28T17:59:26.465Z,1682704766.465 [Default:CheckIn:Read_GPS] Stopped
2023-04-28T17:59:26.465Z,1682704766.465 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-28T17:59:33.726Z,1682704773.726 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230428T172103/Courier0028.lzma
2023-04-28T17:59:34.728Z,1682704774.728 [DataOverHttps](INFO): Moved sent file to Logs/20230428T172103/Courier0028.lzma.bak
2023-04-28T17:59:34.729Z,1682704774.729 [DataOverHttps](INFO): SBD MOMSN=18272614
2023-04-28T17:59:40.989Z,1682704780.989 [NAL9602](INFO): SBD MO Status=1, MOMSN=42703, MT Status=0, MTMSN=0
2023-04-28T17:59:40.989Z,1682704780.989 [NAL9602](INFO): No messages in MT queue
2023-04-28T17:59:50.586Z,1682704790.586 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20230428T172103/Express0029.lzma
2023-04-28T17:59:51.588Z,1682704791.588 [DataOverHttps](INFO): Moved sent file to Logs/20230428T172103/Express0029.lzma.bak
2023-04-28T17:59:51.588Z,1682704791.588 [DataOverHttps](INFO): SBD MOMSN=18272618
2023-04-28T17:59:52.708Z,1682704792.708 [Default:CheckIn:Read_Iridium] Stopped
2023-04-28T17:59:52.708Z,1682704792.708 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-28T17:59:52.708Z,1682704792.708 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-28T18:00:11.686Z,1682704811.686 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-28T18:04:53.321Z,1682705093.321 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-28T18:04:53.321Z,1682705093.321 [Default:CheckIn:C.Wait] Stopped
2023-04-28T18:04:53.322Z,1682705093.322 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-28T18:04:53.322Z,1682705093.322 [Default:CheckIn:D] Running Loop=1
2023-04-28T18:04:53.748Z,1682705093.748 [Default:CheckIn:D] Stopped
2023-04-28T18:04:53.748Z,1682705093.748 [Default:CheckIn:E] Running Loop=1
2023-04-28T18:04:54.159Z,1682705094.159 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 40.664604 min 
2023-04-28T18:04:54.159Z,1682705094.159 [Default:CheckIn:E] Stopped
2023-04-28T18:04:54.159Z,1682705094.159 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-28T18:04:54.159Z,1682705094.159 [Default:CheckIn] Stopped
2023-04-28T18:04:54.160Z,1682705094.160 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-28T18:04:54.160Z,1682705094.160 [Default:CheckIn](INFO): Running loop #8
2023-04-28T18:04:54.160Z,1682705094.160 [Default:CheckIn] Running Loop=8
2023-04-28T18:04:54.160Z,1682705094.160 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-28T18:04:54.160Z,1682705094.160 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-28T18:04:56.133Z,1682705096.133 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180455.00,A,3648.22504,N,12147.78047,W,19.283,237.85,280423,,,D*44
2023-04-28T18:04:56.148Z,1682705096.148 [NAL9602](INFO): GPS fix at 20230428T180455: (36.803751, -121.796341)
2023-04-28T18:04:56.158Z,1682705096.158 [Default:CheckIn:Read_GPS] Stopped
2023-04-28T18:04:56.158Z,1682705096.158 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-28T18:05:03.841Z,1682705103.841 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230428T172103/Courier0031.lzma
2023-04-28T18:05:04.844Z,1682705104.844 [DataOverHttps](INFO): Moved sent file to Logs/20230428T172103/Courier0031.lzma.bak
2023-04-28T18:05:04.844Z,1682705104.844 [DataOverHttps](INFO): SBD MOMSN=18272623
2023-04-28T18:05:19.169Z,1682705119.169 [NAL9602](INFO): SBD MO Status=1, MOMSN=42704, MT Status=0, MTMSN=0
2023-04-28T18:05:19.169Z,1682705119.169 [NAL9602](INFO): No messages in MT queue
2023-04-28T18:05:20.706Z,1682705120.706 [DataOverHttps](INFO): Sending 143 bytes from file Logs/20230428T172103/Express0032.lzma
2023-04-28T18:05:21.708Z,1682705121.708 [DataOverHttps](INFO): Moved sent file to Logs/20230428T172103/Express0032.lzma.bak
2023-04-28T18:05:21.708Z,1682705121.708 [DataOverHttps](INFO): SBD MOMSN=18272626
2023-04-28T18:05:22.817Z,1682705122.817 [Default:CheckIn:Read_Iridium] Stopped
2023-04-28T18:05:22.817Z,1682705122.817 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-28T18:05:22.817Z,1682705122.817 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-28T18:05:49.862Z,1682705149.862 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-28T18:10:23.432Z,1682705423.432 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-28T18:10:23.432Z,1682705423.432 [Default:CheckIn:C.Wait] Stopped
2023-04-28T18:10:23.432Z,1682705423.432 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-28T18:10:23.432Z,1682705423.432 [Default:CheckIn:D] Running Loop=1
2023-04-28T18:10:23.842Z,1682705423.842 [Default:CheckIn:D] Stopped
2023-04-28T18:10:23.842Z,1682705423.842 [Default:CheckIn:E] Running Loop=1
2023-04-28T18:10:24.248Z,1682705424.248 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 46.166166 min 
2023-04-28T18:10:24.248Z,1682705424.248 [Default:CheckIn:E] Stopped
2023-04-28T18:10:24.248Z,1682705424.248 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-28T18:10:24.248Z,1682705424.248 [Default:CheckIn] Stopped
2023-04-28T18:10:24.248Z,1682705424.248 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-28T18:10:24.248Z,1682705424.248 [Default:CheckIn](INFO): Running loop #9
2023-04-28T18:10:24.248Z,1682705424.248 [Default:CheckIn] Running Loop=9
2023-04-28T18:10:24.248Z,1682705424.248 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-28T18:10:24.248Z,1682705424.248 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-28T18:10:26.249Z,1682705426.249 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181025.00,A,3647.83031,N,12150.65073,W,26.106,247.91,280423,,,D*4C
2023-04-28T18:10:26.251Z,1682705426.251 [NAL9602](INFO): GPS fix at 20230428T181025: (36.797172, -121.844179)
2023-04-28T18:10:26.285Z,1682705426.285 [Default:CheckIn:Read_GPS] Stopped
2023-04-28T18:10:26.285Z,1682705426.285 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-28T18:10:33.586Z,1682705433.586 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20230428T172103/Courier0034.lzma
2023-04-28T18:10:34.588Z,1682705434.588 [DataOverHttps](INFO): Moved sent file to Logs/20230428T172103/Courier0034.lzma.bak
2023-04-28T18:10:34.588Z,1682705434.588 [DataOverHttps](INFO): SBD MOMSN=18272631
2023-04-28T18:10:47.283Z,1682705447.283 [NAL9602](INFO): SBD MO Status=1, MOMSN=42705, MT Status=0, MTMSN=0
2023-04-28T18:10:47.284Z,1682705447.284 [NAL9602](INFO): No messages in MT queue
2023-04-28T18:10:53.503Z,1682705453.503 [DataOverHttps](INFO): Sending 143 bytes from file Logs/20230428T172103/Express0035.lzma
2023-04-28T18:10:54.504Z,1682705454.504 [DataOverHttps](INFO): Moved sent file to Logs/20230428T172103/Express0035.lzma.bak
2023-04-28T18:10:54.504Z,1682705454.504 [DataOverHttps](INFO): SBD MOMSN=18272634
2023-04-28T18:10:55.797Z,1682705455.797 [Default:CheckIn:Read_Iridium] Stopped
2023-04-28T18:10:55.797Z,1682705455.797 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-28T18:10:55.797Z,1682705455.797 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-28T18:11:18.003Z,1682705478.003 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-28T18:12:26.547Z,1682705546.547 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-04-28T18:12:57.670Z,1682705577.670 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-04-28T18:13:28.795Z,1682705608.795 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-04-28T18:13:59.918Z,1682705639.918 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-04-28T18:15:40.019Z,1682705740.019 [DataOverHttps](IMPORTANT): SBD MTMSN=20230428T181539
2023-04-28T18:15:47.442Z,1682705747.442 [DataOverHttps](INFO): Received command: restart logs