2021-10-04T17:14:03.665Z,1633367643.665 [Supervisor](DEBUG): Initializing supervisor.
2021-10-04T17:14:03.670Z,1633367643.670 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2021-10-04T17:14:03.671Z,1633367643.671 [SyncHandler](INFO): Protected caller Thread ID is 1143
2021-10-04T17:14:03.671Z,1633367643.671 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2021-10-04T17:14:03.672Z,1633367643.672 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2021-10-04T17:14:03.672Z,1633367643.672 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1144
2021-10-04T17:14:03.677Z,1633367643.677 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2021-10-04T17:14:03.695Z,1633367643.695 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2021-10-04T17:14:03.696Z,1633367643.696 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2021-10-04T17:14:03.696Z,1633367643.696 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 1145
2021-10-04T17:14:03.701Z,1633367643.701 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2021-10-04T17:14:03.702Z,1633367643.702 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2021-10-04T17:14:03.703Z,1633367643.703 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1146
2021-10-04T17:14:03.705Z,1633367643.705 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2021-10-04T17:14:03.706Z,1633367643.706 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2021-10-04T17:14:03.706Z,1633367643.706 [logger ThreadHandler](INFO): Protected caller Thread ID is 1147
2021-10-04T17:14:03.710Z,1633367643.710 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2021-10-04T17:14:03.710Z,1633367643.710 [Supervisor](INFO): Looking for Config files in directory: Config/
2021-10-04T17:14:03.712Z,1633367643.712 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2021-10-04T17:14:03.939Z,1633367643.939 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2021-10-04T17:14:03.940Z,1633367643.940 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2021-10-04T17:14:04.021Z,1633367644.021 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2021-10-04T17:14:04.526Z,1633367644.526 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2021-10-04T17:14:04.526Z,1633367644.526 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2021-10-04T17:14:04.850Z,1633367644.850 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2021-10-04T17:14:04.851Z,1633367644.851 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2021-10-04T17:14:04.946Z,1633367644.946 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2021-10-04T17:14:04.947Z,1633367644.947 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2021-10-04T17:14:05.309Z,1633367645.309 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2021-10-04T17:14:05.310Z,1633367645.310 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2021-10-04T17:14:05.506Z,1633367645.506 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2021-10-04T17:14:05.506Z,1633367645.506 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2021-10-04T17:14:05.949Z,1633367645.949 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2021-10-04T17:14:05.950Z,1633367645.950 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2021-10-04T17:14:06.077Z,1633367646.077 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2021-10-04T17:14:06.077Z,1633367646.077 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2021-10-04T17:14:06.156Z,1633367646.156 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2021-10-04T17:14:06.799Z,1633367646.799 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2021-10-04T17:14:06.799Z,1633367646.799 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2021-10-04T17:14:07.154Z,1633367647.154 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2021-10-04T17:14:07.154Z,1633367647.154 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2021-10-04T17:14:07.359Z,1633367647.359 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2021-10-04T17:14:07.360Z,1633367647.360 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2021-10-04T17:14:07.673Z,1633367647.673 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2021-10-04T17:14:07.673Z,1633367647.673 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2021-10-04T17:14:08.207Z,1633367648.207 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2021-10-04T17:14:08.208Z,1633367648.208 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2021-10-04T17:14:08.532Z,1633367648.532 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2021-10-04T17:14:08.534Z,1633367648.534 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2021-10-04T17:14:08.535Z,1633367648.535 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2021-10-04T17:14:08.625Z,1633367648.625 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2021-10-04T17:14:08.710Z,1633367648.710 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2021-10-04T17:14:08.811Z,1633367648.811 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2021-10-04T17:14:08.893Z,1633367648.893 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2021-10-04T17:14:08.988Z,1633367648.988 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2021-10-04T17:14:09.089Z,1633367649.089 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2021-10-04T17:14:09.272Z,1633367649.272 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2021-10-04T17:14:09.348Z,1633367649.348 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2021-10-04T17:14:09.495Z,1633367649.495 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2021-10-04T17:14:09.631Z,1633367649.631 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2021-10-04T17:14:09.747Z,1633367649.747 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2021-10-04T17:14:10.003Z,1633367650.003 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2021-10-04T17:14:10.005Z,1633367650.005 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/
2021-10-04T17:14:10.005Z,1633367650.005 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2021-10-04T17:14:10.017Z,1633367650.017 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2021-10-04T17:14:10.072Z,1633367650.072 [VerticalControl](DEBUG): Construct VerticalControl.
2021-10-04T17:14:10.134Z,1633367650.134 [VerticalControl] Loaded
2021-10-04T17:14:10.135Z,1633367650.135 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2021-10-04T17:14:10.137Z,1633367650.137 [HorizontalControl](DEBUG): Construct HorizontalControl.
2021-10-04T17:14:10.175Z,1633367650.175 [HorizontalControl] Loaded
2021-10-04T17:14:10.176Z,1633367650.176 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2021-10-04T17:14:10.178Z,1633367650.178 [SpeedControl](DEBUG): Construct SpeedControl.
2021-10-04T17:14:10.181Z,1633367650.181 [SpeedControl] Loaded
2021-10-04T17:14:10.181Z,1633367650.181 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2021-10-04T17:14:10.184Z,1633367650.184 [LoopControl](DEBUG): Construct LoopControl.
2021-10-04T17:14:10.184Z,1633367650.184 [LoopControl] Loaded
2021-10-04T17:14:10.185Z,1633367650.185 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2021-10-04T17:14:10.185Z,1633367650.185 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2021-10-04T17:14:10.186Z,1633367650.186 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2021-10-04T17:14:10.196Z,1633367650.196 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2021-10-04T17:14:10.197Z,1633367650.197 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2021-10-04T17:14:10.304Z,1633367650.304 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2021-10-04T17:14:10.305Z,1633367650.305 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2021-10-04T17:14:10.457Z,1633367650.457 [BuoyancyServo] Loaded
2021-10-04T17:14:10.457Z,1633367650.457 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2021-10-04T17:14:10.476Z,1633367650.476 [ElevatorServo] Loaded
2021-10-04T17:14:10.477Z,1633367650.477 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2021-10-04T17:14:10.495Z,1633367650.495 [MassServo] Loaded
2021-10-04T17:14:10.495Z,1633367650.495 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2021-10-04T17:14:10.513Z,1633367650.513 [RudderServo] Loaded
2021-10-04T17:14:10.513Z,1633367650.513 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2021-10-04T17:14:10.530Z,1633367650.530 [ThrusterServo] Loaded
2021-10-04T17:14:10.530Z,1633367650.530 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2021-10-04T17:14:10.531Z,1633367650.531 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2021-10-04T17:14:10.531Z,1633367650.531 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2021-10-04T17:14:10.614Z,1633367650.614 [DeadReckonUsingMultipleVelocitySources] Loaded
2021-10-04T17:14:10.614Z,1633367650.614 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2021-10-04T17:14:10.627Z,1633367650.627 [NavChart] Loaded
2021-10-04T17:14:10.627Z,1633367650.627 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2021-10-04T17:14:10.633Z,1633367650.633 [UniversalFixResidualReporter] Loaded
2021-10-04T17:14:10.633Z,1633367650.633 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2021-10-04T17:14:10.634Z,1633367650.634 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2021-10-04T17:14:10.634Z,1633367650.634 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2021-10-04T17:14:10.693Z,1633367650.693 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2021-10-04T17:14:10.694Z,1633367650.694 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2021-10-04T17:14:11.069Z,1633367651.069 [AHRS_M2] Loaded
2021-10-04T17:14:11.069Z,1633367651.069 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2021-10-04T17:14:11.855Z,1633367651.855 [BPC1] Loaded
2021-10-04T17:14:11.855Z,1633367651.855 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2021-10-04T17:14:11.929Z,1633367651.929 [DataOverHttps] Loaded
2021-10-04T17:14:11.929Z,1633367651.929 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2021-10-04T17:14:11.930Z,1633367651.930 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408BB4E0
2021-10-04T17:14:11.930Z,1633367651.930 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1232
2021-10-04T17:14:11.950Z,1633367651.950 [Depth_Keller] Loaded
2021-10-04T17:14:11.950Z,1633367651.950 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2021-10-04T17:14:11.955Z,1633367651.955 [DropWeight] Loaded
2021-10-04T17:14:11.955Z,1633367651.955 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2021-10-04T17:14:12.013Z,1633367652.013 [NAL9602] Loaded
2021-10-04T17:14:12.014Z,1633367652.014 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2021-10-04T17:14:12.042Z,1633367652.042 [Onboard] Loaded
2021-10-04T17:14:12.042Z,1633367652.042 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2021-10-04T17:14:12.043Z,1633367652.043 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408EB4E0
2021-10-04T17:14:12.043Z,1633367652.043 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 1233
2021-10-04T17:14:12.056Z,1633367652.056 [Power24vConverter] Loaded
2021-10-04T17:14:12.056Z,1633367652.056 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2021-10-04T17:14:12.069Z,1633367652.069 [Radio_Surface] Loaded
2021-10-04T17:14:12.069Z,1633367652.069 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2021-10-04T17:14:12.070Z,1633367652.070 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4091B4E0
2021-10-04T17:14:12.070Z,1633367652.070 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1234
2021-10-04T17:14:12.071Z,1633367652.071 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2021-10-04T17:14:12.072Z,1633367652.072 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2021-10-04T17:14:12.117Z,1633367652.117 [DepthRateCalculator] Loaded
2021-10-04T17:14:12.118Z,1633367652.118 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2021-10-04T17:14:12.122Z,1633367652.122 [PitchRateCalculator] Loaded
2021-10-04T17:14:12.123Z,1633367652.123 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2021-10-04T17:14:12.131Z,1633367652.131 [SpeedCalculator] Loaded
2021-10-04T17:14:12.132Z,1633367652.132 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2021-10-04T17:14:12.145Z,1633367652.145 [TempGradientCalculator] Loaded
2021-10-04T17:14:12.146Z,1633367652.146 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2021-10-04T17:14:12.150Z,1633367652.150 [YawRateCalculator] Loaded
2021-10-04T17:14:12.150Z,1633367652.150 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2021-10-04T17:14:12.168Z,1633367652.168 [ElevatorOffsetCalculator] Loaded
2021-10-04T17:14:12.168Z,1633367652.168 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2021-10-04T17:14:12.168Z,1633367652.168 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2021-10-04T17:14:12.169Z,1633367652.169 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2021-10-04T17:14:12.309Z,1633367652.309 [CANONSampler] Loaded
2021-10-04T17:14:12.310Z,1633367652.310 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2021-10-04T17:14:12.367Z,1633367652.367 [CTD_Seabird] Loaded
2021-10-04T17:14:12.367Z,1633367652.367 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2021-10-04T17:14:12.368Z,1633367652.368 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409D04E0
2021-10-04T17:14:12.369Z,1633367652.369 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1235
2021-10-04T17:14:12.388Z,1633367652.388 [PAR_Licor] Loaded
2021-10-04T17:14:12.389Z,1633367652.389 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2021-10-04T17:14:12.420Z,1633367652.420 [WetLabsBB2FL] Loaded
2021-10-04T17:14:12.420Z,1633367652.420 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2021-10-04T17:14:12.421Z,1633367652.421 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A004E0
2021-10-04T17:14:12.422Z,1633367652.422 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1236
2021-10-04T17:14:12.422Z,1633367652.422 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2021-10-04T17:14:12.423Z,1633367652.423 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2021-10-04T17:14:12.529Z,1633367652.529 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2021-10-04T17:14:12.530Z,1633367652.530 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2021-10-04T17:14:13.492Z,1633367653.492 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2021-10-04T17:14:13.493Z,1633367653.493 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2021-10-04T17:14:13.780Z,1633367653.780 [SBIT](DEBUG): Construct Startup Built In Test.
2021-10-04T17:14:13.789Z,1633367653.789 [SBIT] Loaded
2021-10-04T17:14:13.790Z,1633367653.790 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2021-10-04T17:14:13.792Z,1633367653.792 [IBIT](DEBUG): Construct Initiated Built In Test.
2021-10-04T17:14:13.806Z,1633367653.806 [IBIT] Loaded
2021-10-04T17:14:13.806Z,1633367653.806 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2021-10-04T17:14:13.811Z,1633367653.811 [CBIT](DEBUG): Construct Continuous Built In Test.
2021-10-04T17:14:13.911Z,1633367653.911 [CBIT] Loaded
2021-10-04T17:14:13.911Z,1633367653.911 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2021-10-04T17:14:13.912Z,1633367653.912 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2021-10-04T17:14:13.912Z,1633367653.912 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2021-10-04T17:14:14.010Z,1633367654.010 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2021-10-04T17:14:14.017Z,1633367654.017 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2021-10-04T17:14:14.020Z,1633367654.020 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2021-10-04T17:14:14.031Z,1633367654.031 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2021-10-04T17:14:14.032Z,1633367654.032 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B344E0
2021-10-04T17:14:14.032Z,1633367654.032 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1237
2021-10-04T17:14:14.037Z,1633367654.037 [Supervisor](INFO): Main Thread ID is 829
2021-10-04T17:14:14.037Z,1633367654.037 [Supervisor](DEBUG): Running supervisor.
2021-10-04T17:14:14.038Z,1633367654.038 [CommandExec ThreadHandler](INFO): Handler Thread ID is 1238
2021-10-04T17:14:14.039Z,1633367654.039 [CommandExec](INFO): Initializing the command executive.
2021-10-04T17:14:14.040Z,1633367654.040 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1239
2021-10-04T17:14:14.043Z,1633367654.043 [controlThread ThreadHandler](INFO): Handler Thread ID is 1240
2021-10-04T17:14:14.044Z,1633367654.044 [controlThread](DEBUG): Initializing ControlThread
2021-10-04T17:14:14.045Z,1633367654.045 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2021-10-04T17:14:14.047Z,1633367654.047 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2021-10-04T17:14:14.047Z,1633367654.047 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2021-10-04T17:14:14.048Z,1633367654.048 [LoopControl](DEBUG): Initialize LoopControlComponent.
2021-10-04T17:14:14.050Z,1633367654.050 [NavChart](DEBUG): Initialize NavChart Navigation.
2021-10-04T17:14:14.050Z,1633367654.050 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2021-10-04T17:14:14.055Z,1633367654.055 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2021-10-04T17:14:14.056Z,1633367654.056 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2021-10-04T17:14:14.056Z,1633367654.056 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2021-10-04T17:14:14.056Z,1633367654.056 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2021-10-04T17:14:14.057Z,1633367654.057 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2021-10-04T17:14:14.057Z,1633367654.057 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2021-10-04T17:14:14.062Z,1633367654.062 [SBIT](INFO): Initialize SBIT Component.
2021-10-04T17:14:14.062Z,1633367654.062 [SBIT](IMPORTANT): git: 2021-09-30a
2021-10-04T17:14:14.063Z,1633367654.063 [SBIT](INFO): git hash: 921004aa1e1e6e697b3aa6ab2c76f23053d013df
2021-10-04T17:14:14.063Z,1633367654.063 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2021-10-04T17:14:14.064Z,1633367654.064 [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
2021-10-04T17:14:14.065Z,1633367654.065 [SBIT](INFO): Beginning SBIT in 85.000000 seconds.
2021-10-04T17:14:14.066Z,1633367654.066 [IBIT](INFO): Initialize IBIT Component.
2021-10-04T17:14:14.067Z,1633367654.067 [CBIT](DEBUG): Initialize CBIT Component.
2021-10-04T17:14:14.068Z,1633367654.068 [logger ThreadHandler](INFO): Handler Thread ID is 1241
2021-10-04T17:14:14.081Z,1633367654.081 [CBIT](DEBUG): Initialized mux pins.
2021-10-04T17:14:14.082Z,1633367654.082 [CBIT](DEBUG): Initializing the watchdog timer.
2021-10-04T17:14:14.086Z,1633367654.086 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1242
2021-10-04T17:14:14.087Z,1633367654.087 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2021-10-04T17:14:14.098Z,1633367654.098 [Onboard ThreadHandler](INFO): Handler Thread ID is 1243
2021-10-04T17:14:14.106Z,1633367654.106 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2021-10-04T17:14:14.107Z,1633367654.107 [CBIT](DEBUG): Initializing heartbeat.
2021-10-04T17:14:14.119Z,1633367654.119 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1244
2021-10-04T17:14:14.134Z,1633367654.134 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1245
2021-10-04T17:14:14.135Z,1633367654.135 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2021-10-04T17:14:14.139Z,1633367654.139 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1247
2021-10-04T17:14:14.143Z,1633367654.143 [WetLabsBB2FL](INFO): Powering up
2021-10-04T17:14:14.144Z,1633367654.144 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1249
2021-10-04T17:14:14.147Z,1633367654.147 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2021-10-04T17:14:14.147Z,1633367654.147 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2021-10-04T17:14:14.148Z,1633367654.148 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2021-10-04T17:14:14.148Z,1633367654.148 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2021-10-04T17:14:14.148Z,1633367654.148 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2021-10-04T17:14:14.148Z,1633367654.148 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2021-10-04T17:14:14.148Z,1633367654.148 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2021-10-04T17:14:14.149Z,1633367654.149 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2021-10-04T17:14:14.149Z,1633367654.149 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2021-10-04T17:14:14.149Z,1633367654.149 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2021-10-04T17:14:14.149Z,1633367654.149 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2021-10-04T17:14:14.150Z,1633367654.150 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2021-10-04T17:14:14.150Z,1633367654.150 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2021-10-04T17:14:14.150Z,1633367654.150 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2021-10-04T17:14:14.150Z,1633367654.150 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2021-10-04T17:14:14.151Z,1633367654.151 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2021-10-04T17:14:14.177Z,1633367654.177 [CBIT](DEBUG): Deactivating GF circuits.
2021-10-04T17:14:14.178Z,1633367654.178 [CBIT](DEBUG): Deactivating emergency mode.
2021-10-04T17:14:14.213Z,1633367654.213 [CBIT](DEBUG): Backplane powered.
2021-10-04T17:14:14.214Z,1633367654.214 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2021-10-04T17:14:14.228Z,1633367654.228 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2021-10-04T17:14:14.260Z,1633367654.260 [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>


2021-10-04T17:14:14.261Z,1633367654.261 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2021-10-04T17:14:14.336Z,1633367654.336 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2021-10-04T17:14:14.357Z,1633367654.357 [Default:A.Wait](DEBUG): Construct Wait.
2021-10-04T17:14:14.370Z,1633367654.370 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2021-10-04T17:14:14.390Z,1633367654.390 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2021-10-04T17:14:14.392Z,1633367654.392 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2021-10-04T17:14:14.418Z,1633367654.418 [Default:E.Execute](DEBUG): Construct Execute.
2021-10-04T17:14:14.422Z,1633367654.422 [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="P2H">
                <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>


2021-10-04T17:14:14.434Z,1633367654.434 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2021-10-04T17:14:14.442Z,1633367654.442 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2021-10-04T17:14:14.525Z,1633367654.525 [Radio_Surface](INFO): Powering up
2021-10-04T17:14:14.532Z,1633367654.532 [Power24vConverter](INFO): Powering up.
2021-10-04T17:14:14.533Z,1633367654.533 [CANONSampler](INFO): Powering down
2021-10-04T17:14:14.580Z,1633367654.580 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2021-10-04T17:14:14.586Z,1633367654.586 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2021-10-04T17:14:14.587Z,1633367654.587 [ElevatorServo](DEBUG): Initializing EZServoServo.
2021-10-04T17:14:14.594Z,1633367654.594 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2021-10-04T17:14:14.595Z,1633367654.595 [MassServo](DEBUG): Initializing EZServoServo.
2021-10-04T17:14:14.602Z,1633367654.602 [MassServo](DEBUG): Initializing MassServo.
2021-10-04T17:14:14.603Z,1633367654.603 [RudderServo](DEBUG): Initializing EZServoServo.
2021-10-04T17:14:14.610Z,1633367654.610 [RudderServo](DEBUG): Initializing RudderServo.
2021-10-04T17:14:14.611Z,1633367654.611 [ThrusterServo](DEBUG): Initializing EZServoServo.
2021-10-04T17:14:14.618Z,1633367654.618 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2021-10-04T17:14:16.250Z,1633367656.250 [WetLabsBB2FL](INFO): Powering down
2021-10-04T17:14:42.323Z,1633367682.323 [NAL9602](INFO): Powering up NAL9602
2021-10-04T17:14:53.236Z,1633367693.236 [NAL9602](INFO): NAL9602 initialized
2021-10-04T17:15:19.096Z,1633367719.096 [NAL9602](INFO): SBD MO Status=0, MOMSN=29681, MT Status=0, MTMSN=0
2021-10-04T17:15:19.097Z,1633367719.097 [NAL9602](INFO): No messages in MT queue
2021-10-04T17:15:32.021Z,1633367732.021 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171530.00,A,3648.16512,N,12147.21519,W,0.447,0.00,041021,,,A*7B
2021-10-04T17:15:32.025Z,1633367732.025 [NAL9602](INFO): GPS fix at 20211004T171530: (36.802752, -121.786920)
2021-10-04T17:15:39.722Z,1633367739.722 [SBIT](IMPORTANT): Beginning Startup BIT
2021-10-04T17:15:39.726Z,1633367739.726 [CBIT](IMPORTANT): Beginning ground fault scan
2021-10-04T17:15:50.638Z,1633367750.638 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2021-10-04T17:15:51.060Z,1633367751.060 [CBIT](IMPORTANT): Beginning ground fault scan
2021-10-04T17:16:02.459Z,1633367762.459 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2021-10-04T17:16:02.780Z,1633367762.780 [CBIT](IMPORTANT): Beginning ground fault scan
2021-10-04T17:16:04.343Z,1633367764.343 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-04T17:16:13.692Z,1633367773.692 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.002959
CHAN A1 (24V): -0.180271
CHAN A2 (12V): -0.002435
CHAN A3 (5V): -0.001647
CHAN B0 (3.3V): 0.000026
CHAN B1 (3.15aV): -0.000119
CHAN B2 (3.15bV): -0.000108
CHAN B3 (GND): -0.000221
OPEN: -0.000368
Full Scale: +/- 1 mA
2021-10-04T17:16:33.847Z,1633367793.847 [SBIT](IMPORTANT): SBIT PASSED
2021-10-04T17:16:33.847Z,1633367793.847 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2021-10-04T17:16:33.848Z,1633367793.848 [SBIT](IMPORTANT): AMEcho.loadAtStartup=0 bool;

2021-10-04T17:16:33.848Z,1633367793.848 [SBIT](IMPORTANT): BuoyancyServo.fastPumpDepth=6 meter;

2021-10-04T17:16:33.848Z,1633367793.848 [SBIT](IMPORTANT): CANONSampler.loadAtStartup=1 bool;

2021-10-04T17:16:33.848Z,1633367793.848 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool;

2021-10-04T17:16:33.849Z,1633367793.849 [SBIT](IMPORTANT): DAT.verbosity=3 count;

2021-10-04T17:16:33.849Z,1633367793.849 [SBIT](IMPORTANT): ESPComponent.loadAtStartup=0 bool;

2021-10-04T17:16:33.849Z,1633367793.849 [SBIT](IMPORTANT): ESPComponent.simulateHardware=1 bool;

2021-10-04T17:16:33.849Z,1633367793.849 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=289.165056 cubic_centimeter;

2021-10-04T17:16:33.849Z,1633367793.849 [SBIT](IMPORTANT): VerticalControl.kdDepthBuoy=1000 second;

2021-10-04T17:16:33.849Z,1633367793.849 [SBIT](IMPORTANT): VerticalControl.kiDepthBuoy=0.15 reciprocal_second;

2021-10-04T17:16:33.850Z,1633367793.850 [SBIT](IMPORTANT): VerticalControl.kiDepthOff=0.01 meter_per_second;

2021-10-04T17:16:33.850Z,1633367793.850 [SBIT](IMPORTANT): VerticalControl.kpDepthBuoy=120 ratio;

2021-10-04T17:16:33.850Z,1633367793.850 [SBIT](IMPORTANT): VerticalControl.massDefault=-16.338508 millimeter;

2021-10-04T17:16:34.278Z,1633367794.278 [MissionManager](IMPORTANT): Started mission Startup
2021-10-04T17:16:34.278Z,1633367794.278 [Startup] Running Loop=1
2021-10-04T17:16:34.278Z,1633367794.278 [Startup](DEBUG): Aggregate::initialize Startup
2021-10-04T17:16:34.279Z,1633367794.279 [Startup:A.GoToSurface] Running Loop=1
2021-10-04T17:16:34.279Z,1633367794.279 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-10-04T17:16:34.279Z,1633367794.279 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-10-04T17:16:34.280Z,1633367794.280 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-10-04T17:16:34.280Z,1633367794.280 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-10-04T17:16:34.280Z,1633367794.280 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-10-04T17:16:34.281Z,1633367794.281 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-10-04T17:16:34.282Z,1633367794.282 [Startup:StartupSatComms] Running Loop=1
2021-10-04T17:16:34.282Z,1633367794.282 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2021-10-04T17:16:34.282Z,1633367794.282 [Startup:StartupSatComms:A] Running Loop=1
2021-10-04T17:16:34.650Z,1633367794.650 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2021-10-04T17:16:36.258Z,1633367796.258 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171634.00,A,3648.17583,N,12147.21504,W,0.039,189.45,041021,,,A*75
2021-10-04T17:16:36.260Z,1633367796.260 [NAL9602](INFO): GPS fix at 20211004T171634: (36.802931, -121.786917)
2021-10-04T17:16:36.271Z,1633367796.271 [Startup:StartupSatComms:A] Stopped
2021-10-04T17:16:36.272Z,1633367796.272 [Startup:StartupSatComms:B] Running Loop=1
2021-10-04T17:16:36.684Z,1633367796.684 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-10-04T17:16:59.740Z,1633367819.740 [NAL9602](INFO): SBD MO Status=1, MOMSN=29682, MT Status=0, MTMSN=0
2021-10-04T17:16:59.786Z,1633367819.786 [NAL9602](INFO): Sent 39 bytes from file Logs/20211004T163659/Courier0016.lzma
2021-10-04T17:16:59.786Z,1633367819.786 [NAL9602](INFO): Packets left to send: 0
2021-10-04T17:17:11.524Z,1633367831.524 [NAL9602](INFO): SBD MO Status=1, MOMSN=29683, MT Status=0, MTMSN=0
2021-10-04T17:17:11.586Z,1633367831.586 [NAL9602](INFO): Sent 267 bytes from file Logs/20211004T171403/Courier0000.lzma
2021-10-04T17:17:11.586Z,1633367831.586 [NAL9602](INFO): Packets left to send: 0
2021-10-04T17:17:24.152Z,1633367844.152 [NAL9602](INFO): SBD MO Status=1, MOMSN=29684, MT Status=0, MTMSN=0
2021-10-04T17:17:24.202Z,1633367844.202 [NAL9602](INFO): Sent 109 bytes from file Logs/20211004T163659/Express0017.lzma
2021-10-04T17:17:24.202Z,1633367844.202 [NAL9602](INFO): Packets left to send: 0
2021-10-04T17:17:31.844Z,1633367851.844 [NAL9602](INFO): SBD MO Status=1, MOMSN=29685, MT Status=0, MTMSN=0
2021-10-04T17:17:31.906Z,1633367851.906 [NAL9602](INFO): Sent 332 bytes from file Logs/20211004T171403/Express0001.lzma
2021-10-04T17:17:31.906Z,1633367851.906 [NAL9602](INFO): Packets left to send: 2
2021-10-04T17:17:36.369Z,1633367856.369 [Startup:StartupSatComms:B](INFO): Timed out from 2021-10-04T17:16:36.3Z
2021-10-04T17:17:36.370Z,1633367856.370 [Startup:StartupSatComms:B] Stopped
2021-10-04T17:17:36.370Z,1633367856.370 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2021-10-04T17:17:36.370Z,1633367856.370 [Startup:StartupSatComms] Stopped
2021-10-04T17:17:36.370Z,1633367856.370 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2021-10-04T17:17:36.371Z,1633367856.371 [Startup](INFO): Completed Startup
2021-10-04T17:17:36.371Z,1633367856.371 [MissionManager](INFO): Startup is completed.
2021-10-04T17:17:36.371Z,1633367856.371 [MissionManager](INFO): Uninitializing Mission Startup
2021-10-04T17:17:36.371Z,1633367856.371 [Startup] Stopped
2021-10-04T17:17:36.371Z,1633367856.371 [Startup](DEBUG): Aggregate::uninitialize Startup
2021-10-04T17:17:36.371Z,1633367856.371 [Startup:A.GoToSurface] Stopped
2021-10-04T17:17:36.371Z,1633367856.371 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-10-04T17:17:36.753Z,1633367856.753 [MissionManager](IMPORTANT): Started mission Default
2021-10-04T17:17:36.753Z,1633367856.753 [Default] Running Loop=1
2021-10-04T17:17:36.754Z,1633367856.754 [Default](DEBUG): Aggregate::initialize Default
2021-10-04T17:17:36.754Z,1633367856.754 [Default:B.GoToSurface] Running Loop=1
2021-10-04T17:17:36.754Z,1633367856.754 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-10-04T17:17:36.754Z,1633367856.754 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-10-04T17:17:36.754Z,1633367856.754 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-10-04T17:17:36.755Z,1633367856.755 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-10-04T17:17:36.755Z,1633367856.755 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-10-04T17:17:36.755Z,1633367856.755 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-10-04T17:17:36.756Z,1633367856.756 [Default:A.Wait] Running Loop=1
2021-10-04T17:17:36.756Z,1633367856.756 [Default:A.Wait](DEBUG): Initialize Wait Component.
2021-10-04T17:17:43.612Z,1633367863.612 [NAL9602](INFO): SBD MO Status=1, MOMSN=29686, MT Status=0, MTMSN=0
2021-10-04T17:17:43.662Z,1633367863.662 [NAL9602](INFO): Sent 332 bytes from file Logs/20211004T171403/Express0001.lzma
2021-10-04T17:17:43.662Z,1633367863.662 [NAL9602](INFO): Packets left to send: 1
2021-10-04T17:17:50.094Z,1633367870.094 [Default:A.Wait](INFO): Done Waiting.
2021-10-04T17:17:50.094Z,1633367870.094 [Default:A.Wait] Stopped
2021-10-04T17:17:50.094Z,1633367870.094 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2021-10-04T17:17:50.511Z,1633367870.511 [Default:CheckIn] Running Loop=1
2021-10-04T17:17:50.511Z,1633367870.511 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-04T17:17:50.511Z,1633367870.511 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-04T17:17:50.955Z,1633367870.955 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2021-10-04T17:17:52.497Z,1633367872.497 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171750.00,A,3648.17219,N,12147.21028,W,0.117,189.45,041021,,,A*74
2021-10-04T17:17:52.500Z,1633367872.500 [NAL9602](INFO): GPS fix at 20211004T171750: (36.802870, -121.786838)
2021-10-04T17:17:52.510Z,1633367872.510 [Default:CheckIn:Read_GPS] Stopped
2021-10-04T17:17:52.510Z,1633367872.510 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-04T17:17:52.960Z,1633367872.960 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-10-04T17:17:59.632Z,1633367879.632 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004536
2021-10-04T17:18:04.700Z,1633367884.700 [NAL9602](INFO): SBD MO Status=1, MOMSN=29687, MT Status=0, MTMSN=0
2021-10-04T17:18:04.750Z,1633367884.750 [NAL9602](INFO): Sent 72 bytes from file Logs/20211004T171403/Courier0004.lzma
2021-10-04T17:18:04.750Z,1633367884.750 [NAL9602](INFO): Packets left to send: 0
2021-10-04T17:18:04.802Z,1633367884.802 [Default:CheckIn:Read_Iridium] Stopped
2021-10-04T17:18:04.802Z,1633367884.802 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-04T17:18:04.802Z,1633367884.802 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-04T17:18:07.432Z,1633367887.432 [DataOverHttps](IMPORTANT): Could not stat file Logs/20211004T171403/Courier0004.lzma
2021-10-04T17:18:07.432Z,1633367887.432 [DataOverHttps](FAULT): Could not open file Logs/20211004T171403/Courier0004.lzma
2021-10-04T17:18:15.955Z,1633367895.955 [DataOverHttps](IMPORTANT): Could not stat file Logs/20211004T171403/Courier0004.lzma
2021-10-04T17:18:15.955Z,1633367895.955 [DataOverHttps](FAULT): Could not open file Logs/20211004T171403/Courier0004.lzma
2021-10-04T17:18:35.374Z,1633367915.374 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-04T17:18:46.940Z,1633367926.940 [DataOverHttps](IMPORTANT): Could not stat file Logs/20211004T171403/Courier0004.lzma
2021-10-04T17:18:46.940Z,1633367926.940 [DataOverHttps](FAULT): Could not open file Logs/20211004T171403/Courier0004.lzma
2021-10-04T17:19:17.579Z,1633367957.579 [DataOverHttps](IMPORTANT): Could not stat file Logs/20211004T171403/Courier0004.lzma
2021-10-04T17:19:17.580Z,1633367957.580 [DataOverHttps](FAULT): Could not open file Logs/20211004T171403/Courier0004.lzma
2021-10-04T17:19:48.075Z,1633367988.075 [DataOverHttps](IMPORTANT): Could not stat file Logs/20211004T171403/Courier0004.lzma
2021-10-04T17:19:48.076Z,1633367988.076 [DataOverHttps](FAULT): Could not open file Logs/20211004T171403/Courier0004.lzma
2021-10-04T17:20:19.492Z,1633368019.492 [DataOverHttps](IMPORTANT): Could not stat file Logs/20211004T171403/Courier0004.lzma
2021-10-04T17:20:19.492Z,1633368019.492 [DataOverHttps](FAULT): Could not open file Logs/20211004T171403/Courier0004.lzma
2021-10-04T17:20:50.024Z,1633368050.024 [DataOverHttps](IMPORTANT): Could not stat file Logs/20211004T171403/Courier0004.lzma
2021-10-04T17:20:50.024Z,1633368050.024 [DataOverHttps](FAULT): Could not open file Logs/20211004T171403/Courier0004.lzma
2021-10-04T17:21:19.469Z,1633368079.469 [DataOverHttps](IMPORTANT): Could not stat file Logs/20211004T171403/Courier0004.lzma
2021-10-04T17:21:19.469Z,1633368079.469 [DataOverHttps](FAULT): Could not open file Logs/20211004T171403/Courier0004.lzma
2021-10-04T17:21:20.471Z,1633368080.471 [DataOverHttps](IMPORTANT): SBD MTMSN=20211004T172119
2021-10-04T17:21:28.372Z,1633368088.372 [DataOverHttps](IMPORTANT): Could not stat file Logs/20211004T171403/Courier0004.lzma
2021-10-04T17:21:28.372Z,1633368088.372 [DataOverHttps](FAULT): Could not open file Logs/20211004T171403/Courier0004.lzma
2021-10-04T17:21:28.374Z,1633368088.374 [DataOverHttps](INFO): Received command: ibit
2021-10-04T17:21:28.376Z,1633368088.376 [CommandExec](IMPORTANT): got command ibit
2021-10-04T17:21:28.752Z,1633368088.752 [IBIT](IMPORTANT): Beginning Initiated BIT
2021-10-04T17:21:28.752Z,1633368088.752 [IBIT](IMPORTANT): Beginning control surface checks.
2021-10-04T17:21:28.760Z,1633368088.760 [CBIT](IMPORTANT): Beginning ground fault scan
2021-10-04T17:21:30.340Z,1633368090.340 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172128.00,A,3648.16942,N,12147.21299,W,0.117,189.45,041021,,,A*72
2021-10-04T17:21:30.343Z,1633368090.343 [NAL9602](INFO): GPS fix at 20211004T172128: (36.802824, -121.786883)
2021-10-04T17:21:38.824Z,1633368098.824 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2021-10-04T17:21:38.828Z,1633368098.828 [BPC1](INFO): Received data from all battery sticks.
2021-10-04T17:21:39.675Z,1633368099.675 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2021-10-04T17:21:40.084Z,1633368100.084 [CBIT](IMPORTANT): Beginning ground fault scan
2021-10-04T17:21:51.026Z,1633368111.026 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.002879
CHAN A1 (24V): -0.180237
CHAN A2 (12V): -0.002157
CHAN A3 (5V): -0.001232
CHAN B0 (3.3V): -0.000255
CHAN B1 (3.15aV): -0.000296
CHAN B2 (3.15bV): -0.000419
CHAN B3 (GND): -0.000192
OPEN: -0.000164
Full Scale: +/- 1 mA
2021-10-04T17:21:55.393Z,1633368115.393 [NAL9602](INFO): SBD MO Status=0, MOMSN=29688, MT Status=0, MTMSN=0
2021-10-04T17:21:55.393Z,1633368115.393 [NAL9602](INFO): No messages in MT queue
2021-10-04T17:21:56.597Z,1633368116.597 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172154.00,A,3648.17159,N,12147.21381,W,0.175,189.45,041021,,,A*76
2021-10-04T17:21:56.599Z,1633368116.599 [NAL9602](INFO): GPS fix at 20211004T172154: (36.802860, -121.786897)
2021-10-04T17:21:59.020Z,1633368119.020 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172157.00,A,3648.17120,N,12147.21367,W,0.194,189.45,041021,,,A*7C
2021-10-04T17:21:59.023Z,1633368119.023 [NAL9602](INFO): GPS fix at 20211004T172157: (36.802853, -121.786895)
2021-10-04T17:21:59.139Z,1633368119.139 [DataOverHttps](IMPORTANT): Could not stat file Logs/20211004T171403/Courier0004.lzma
2021-10-04T17:21:59.140Z,1633368119.140 [DataOverHttps](FAULT): Could not open file Logs/20211004T171403/Courier0004.lzma
2021-10-04T17:22:01.857Z,1633368121.857 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172200.00,A,3648.17138,N,12147.21364,W,0.078,189.45,041021,,,A*74
2021-10-04T17:22:01.859Z,1633368121.859 [NAL9602](INFO): GPS fix at 20211004T172200: (36.802856, -121.786894)
2021-10-04T17:22:05.080Z,1633368125.080 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172203.00,A,3648.17195,N,12147.21359,W,0.117,189.45,041021,,,A*76
2021-10-04T17:22:05.083Z,1633368125.083 [NAL9602](INFO): GPS fix at 20211004T172203: (36.802866, -121.786893)
2021-10-04T17:22:07.917Z,1633368127.917 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172206.00,A,3648.17237,N,12147.21362,W,0.097,189.45,041021,,,A*79
2021-10-04T17:22:07.919Z,1633368127.919 [NAL9602](INFO): GPS fix at 20211004T172206: (36.802873, -121.786894)
2021-10-04T17:22:11.140Z,1633368131.140 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172209.00,A,3648.17275,N,12147.21381,W,0.136,189.45,041021,,,A*77
2021-10-04T17:22:11.142Z,1633368131.142 [NAL9602](INFO): GPS fix at 20211004T172209: (36.802879, -121.786897)
2021-10-04T17:22:13.969Z,1633368133.969 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172212.00,A,3648.17312,N,12147.21390,W,0.058,189.45,041021,,,A*74
2021-10-04T17:22:13.972Z,1633368133.972 [NAL9602](INFO): GPS fix at 20211004T172212: (36.802885, -121.786898)
2021-10-04T17:22:15.198Z,1633368135.198 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 3
Latitude: 36.802887 Longitude: -121.786896
2021-10-04T17:22:15.610Z,1633368135.610 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 16.096001
2021-10-04T17:22:15.611Z,1633368135.611 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2021-10-04T17:22:15.611Z,1633368135.611 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2021-10-04T17:22:16.025Z,1633368136.025 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2021-10-04T17:22:16.029Z,1633368136.029 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2021-10-04T17:22:16.030Z,1633368136.030 [IBIT](IMPORTANT): Pressure:9.886297 PSI
2021-10-04T17:22:16.030Z,1633368136.030 [IBIT](IMPORTANT): Humidity:7.471615 %
2021-10-04T17:22:16.413Z,1633368136.413 [IBIT](IMPORTANT): Vehicle Pitch:0.909467 degrees
2021-10-04T17:22:16.413Z,1633368136.413 [IBIT](IMPORTANT): Vehicle  Roll:8.672270 degrees
2021-10-04T17:22:16.414Z,1633368136.414 [IBIT](IMPORTANT): Vehicle  Heading:208.687531 degrees
2021-10-04T17:22:16.881Z,1633368136.881 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2021-10-04T17:22:16.881Z,1633368136.881 [IBIT](IMPORTANT): buoyancyNeutral: 289.165070 cc
2021-10-04T17:22:16.882Z,1633368136.882 [IBIT](IMPORTANT): massDefault: -1.633851 cm
2021-10-04T17:22:16.882Z,1633368136.882 [IBIT](IMPORTANT): stopDepth: 205.000000 m
2021-10-04T17:22:16.882Z,1633368136.882 [IBIT](IMPORTANT): abortDepth: 250.000000 m
2021-10-04T17:22:16.882Z,1633368136.882 [IBIT](IMPORTANT): IBIT PASSED
2021-10-04T17:22:29.707Z,1633368149.707 [DataOverHttps](IMPORTANT): Could not stat file Logs/20211004T171403/Courier0004.lzma
2021-10-04T17:22:29.708Z,1633368149.708 [DataOverHttps](FAULT): Could not open file Logs/20211004T171403/Courier0004.lzma
2021-10-04T17:22:46.695Z,1633368166.695 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-04T17:23:00.155Z,1633368180.155 [DataOverHttps](IMPORTANT): Could not stat file Logs/20211004T171403/Courier0004.lzma
2021-10-04T17:23:00.156Z,1633368180.156 [DataOverHttps](FAULT): Could not open file Logs/20211004T171403/Courier0004.lzma
2021-10-04T17:23:05.300Z,1633368185.300 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-04T17:23:05.300Z,1633368185.300 [Default:CheckIn:C.Wait] Stopped
2021-10-04T17:23:05.301Z,1633368185.301 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-04T17:23:05.301Z,1633368185.301 [Default:CheckIn:D] Running Loop=1
2021-10-04T17:23:05.711Z,1633368185.711 [Default:CheckIn:D] Stopped
2021-10-04T17:23:05.711Z,1633368185.711 [Default:CheckIn:E] Running Loop=1
2021-10-04T17:23:06.101Z,1633368186.101 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 5.482628 min 
2021-10-04T17:23:06.102Z,1633368186.102 [Default:CheckIn:E] Stopped
2021-10-04T17:23:06.102Z,1633368186.102 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-04T17:23:06.102Z,1633368186.102 [Default:CheckIn] Stopped
2021-10-04T17:23:06.102Z,1633368186.102 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-04T17:23:06.102Z,1633368186.102 [Default:CheckIn](INFO): Running loop #2
2021-10-04T17:23:06.102Z,1633368186.102 [Default:CheckIn] Running Loop=2
2021-10-04T17:23:06.102Z,1633368186.102 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-04T17:23:06.102Z,1633368186.102 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-04T17:23:08.117Z,1633368188.117 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172306.00,A,3648.17230,N,12147.21362,W,0.058,189.45,041021,,,A*7C
2021-10-04T17:23:08.119Z,1633368188.119 [NAL9602](INFO): GPS fix at 20211004T172306: (36.802872, -121.786894)
2021-10-04T17:23:08.130Z,1633368188.130 [Default:CheckIn:Read_GPS] Stopped
2021-10-04T17:23:08.130Z,1633368188.130 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-04T17:23:15.737Z,1633368195.737 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20211004T171403/Courier0007.lzma
2021-10-04T17:23:16.739Z,1633368196.739 [DataOverHttps](INFO): Moved sent file to Logs/20211004T171403/Courier0007.lzma.bak
2021-10-04T17:23:16.739Z,1633368196.739 [DataOverHttps](INFO): SBD MOMSN=15970172
2021-10-04T17:23:32.778Z,1633368212.778 [DataOverHttps](INFO): Sending 945 bytes from file Logs/20211004T171403/Express0001.lzma
2021-10-04T17:23:33.779Z,1633368213.779 [DataOverHttps](INFO): Moved sent file to Logs/20211004T171403/Express0001.lzma.bak
2021-10-04T17:23:33.780Z,1633368213.780 [DataOverHttps](INFO): SBD MOMSN=15970176
2021-10-04T17:23:47.705Z,1633368227.705 [NAL9602](INFO): SBD MO Status=2, MOMSN=29689, MT Status=2, MTMSN=0
2021-10-04T17:23:47.705Z,1633368227.705 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-10-04T17:23:49.849Z,1633368229.849 [DataOverHttps](INFO): Sending 104 bytes from file Logs/20211004T171403/Express0005.lzma
2021-10-04T17:23:50.852Z,1633368230.852 [DataOverHttps](INFO): Moved sent file to Logs/20211004T171403/Express0005.lzma.bak
2021-10-04T17:23:50.852Z,1633368230.852 [DataOverHttps](INFO): SBD MOMSN=15970202
2021-10-04T17:24:06.790Z,1633368246.790 [DataOverHttps](INFO): Sending 980 bytes from file Logs/20211004T171403/Express0008.lzma
2021-10-04T17:24:07.791Z,1633368247.791 [DataOverHttps](INFO): Moved sent file to Logs/20211004T171403/Express0008.lzma.bak
2021-10-04T17:24:07.791Z,1633368247.791 [DataOverHttps](INFO): SBD MOMSN=15970205
2021-10-04T17:24:09.116Z,1633368249.116 [NAL9602](INFO): SBD MO Status=0, MOMSN=29689, MT Status=0, MTMSN=0
2021-10-04T17:24:09.116Z,1633368249.116 [NAL9602](INFO): No messages in MT queue
2021-10-04T17:24:15.579Z,1633368255.579 [Power24vConverter](INFO): Powering down.
2021-10-04T17:24:26.536Z,1633368266.536 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20211004T171403/Express0011.lzma
2021-10-04T17:24:27.535Z,1633368267.535 [DataOverHttps](INFO): Moved sent file to Logs/20211004T171403/Express0011.lzma.bak
2021-10-04T17:24:27.536Z,1633368267.536 [DataOverHttps](INFO): SBD MOMSN=15970256
2021-10-04T17:24:28.595Z,1633368268.595 [Default:CheckIn:Read_Iridium] Stopped
2021-10-04T17:24:28.595Z,1633368268.595 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-04T17:24:28.595Z,1633368268.595 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-04T17:24:39.902Z,1633368279.902 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-04T17:29:29.191Z,1633368569.191 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-04T17:29:29.191Z,1633368569.191 [Default:CheckIn:C.Wait] Stopped
2021-10-04T17:29:29.191Z,1633368569.191 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-04T17:29:29.191Z,1633368569.191 [Default:CheckIn:D] Running Loop=1
2021-10-04T17:29:29.601Z,1633368569.601 [Default:CheckIn:D] Stopped
2021-10-04T17:29:29.601Z,1633368569.601 [Default:CheckIn:E] Running Loop=1
2021-10-04T17:29:30.014Z,1633368570.014 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.880796 min 
2021-10-04T17:29:30.014Z,1633368570.014 [Default:CheckIn:E] Stopped
2021-10-04T17:29:30.014Z,1633368570.014 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-04T17:29:30.014Z,1633368570.014 [Default:CheckIn] Stopped
2021-10-04T17:29:30.014Z,1633368570.014 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-04T17:29:30.014Z,1633368570.014 [Default:CheckIn](INFO): Running loop #3
2021-10-04T17:29:30.014Z,1633368570.014 [Default:CheckIn] Running Loop=3
2021-10-04T17:29:30.015Z,1633368570.015 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-04T17:29:30.015Z,1633368570.015 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-04T17:29:32.008Z,1633368572.008 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172931.00,A,3648.52044,N,12147.14501,W,6.084,301.04,041021,,,D*72
2021-10-04T17:29:32.011Z,1633368572.011 [NAL9602](INFO): GPS fix at 20211004T172931: (36.808674, -121.785750)
2021-10-04T17:29:32.022Z,1633368572.022 [Default:CheckIn:Read_GPS] Stopped
2021-10-04T17:29:32.022Z,1633368572.022 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-04T17:29:39.764Z,1633368579.764 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211004T171403/Courier0013.lzma
2021-10-04T17:29:40.763Z,1633368580.763 [DataOverHttps](INFO): Moved sent file to Logs/20211004T171403/Courier0013.lzma.bak
2021-10-04T17:29:40.763Z,1633368580.763 [DataOverHttps](INFO): SBD MOMSN=15970321
2021-10-04T17:29:56.733Z,1633368596.733 [DataOverHttps](INFO): Sending 143 bytes from file Logs/20211004T171403/Express0014.lzma
2021-10-04T17:29:57.735Z,1633368597.735 [DataOverHttps](INFO): Moved sent file to Logs/20211004T171403/Express0014.lzma.bak
2021-10-04T17:29:57.736Z,1633368597.736 [DataOverHttps](INFO): SBD MOMSN=15970324
2021-10-04T17:29:59.081Z,1633368599.081 [Default:CheckIn:Read_Iridium] Stopped
2021-10-04T17:29:59.081Z,1633368599.081 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-04T17:29:59.081Z,1633368599.081 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-04T17:30:01.496Z,1633368601.496 [NAL9602](INFO): SBD MO Status=0, MOMSN=29690, MT Status=0, MTMSN=0
2021-10-04T17:30:01.496Z,1633368601.496 [NAL9602](INFO): No messages in MT queue
2021-10-04T17:30:32.207Z,1633368632.207 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-04T17:31:37.539Z,1633368697.539 [DataOverHttps](IMPORTANT): SBD MTMSN=20211004T173136
2021-10-04T17:31:45.021Z,1633368705.021 [DataOverHttps](INFO): Received command: gfscan
2021-10-04T17:31:45.034Z,1633368705.034 [CommandExec](IMPORTANT): got command gfscan
2021-10-04T17:31:45.357Z,1633368705.357 [CBIT](IMPORTANT): Beginning ground fault scan
2021-10-04T17:31:56.294Z,1633368716.294 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.002600
CHAN A1 (24V): -0.180614
CHAN A2 (12V): -0.002086
CHAN A3 (5V): -0.001381
CHAN B0 (3.3V): -0.000181
CHAN B1 (3.15aV): -0.000399
CHAN B2 (3.15bV): -0.000443
CHAN B3 (GND): -0.000401
OPEN: -0.000494
Full Scale: +/- 1 mA
2021-10-04T17:34:59.701Z,1633368899.701 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-04T17:34:59.701Z,1633368899.701 [Default:CheckIn:C.Wait] Stopped
2021-10-04T17:34:59.701Z,1633368899.701 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-04T17:34:59.701Z,1633368899.701 [Default:CheckIn:D] Running Loop=1
2021-10-04T17:35:00.100Z,1633368900.100 [Default:CheckIn:D] Stopped
2021-10-04T17:35:00.101Z,1633368900.101 [Default:CheckIn:E] Running Loop=1
2021-10-04T17:35:00.509Z,1633368900.509 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 17.389119 min 
2021-10-04T17:35:00.509Z,1633368900.509 [Default:CheckIn:E] Stopped
2021-10-04T17:35:00.509Z,1633368900.509 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-04T17:35:00.509Z,1633368900.509 [Default:CheckIn] Stopped
2021-10-04T17:35:00.509Z,1633368900.509 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-04T17:35:00.509Z,1633368900.509 [Default:CheckIn](INFO): Running loop #4
2021-10-04T17:35:00.510Z,1633368900.510 [Default:CheckIn] Running Loop=4
2021-10-04T17:35:00.510Z,1633368900.510 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-04T17:35:00.510Z,1633368900.510 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-04T17:35:02.516Z,1633368902.516 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173501.00,A,3648.13624,N,12148.17701,W,9.214,250.04,041021,,,A*73
2021-10-04T17:35:02.519Z,1633368902.519 [NAL9602](INFO): GPS fix at 20211004T173501: (36.802271, -121.802950)
2021-10-04T17:35:02.550Z,1633368902.550 [Default:CheckIn:Read_GPS] Stopped
2021-10-04T17:35:02.550Z,1633368902.550 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-04T17:35:10.281Z,1633368910.281 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211004T171403/Courier0016.lzma
2021-10-04T17:35:11.283Z,1633368911.283 [DataOverHttps](INFO): Moved sent file to Logs/20211004T171403/Courier0016.lzma.bak
2021-10-04T17:35:11.283Z,1633368911.283 [DataOverHttps](INFO): SBD MOMSN=15970348
2021-10-04T17:35:21.904Z,1633368921.904 [NAL9602](INFO): SBD MO Status=0, MOMSN=29691, MT Status=0, MTMSN=0
2021-10-04T17:35:21.904Z,1633368921.904 [NAL9602](INFO): No messages in MT queue
2021-10-04T17:35:27.249Z,1633368927.249 [DataOverHttps](INFO): Sending 367 bytes from file Logs/20211004T171403/Express0017.lzma
2021-10-04T17:35:28.251Z,1633368928.251 [DataOverHttps](INFO): Moved sent file to Logs/20211004T171403/Express0017.lzma.bak
2021-10-04T17:35:28.251Z,1633368928.251 [DataOverHttps](INFO): SBD MOMSN=15970351
2021-10-04T17:35:44.189Z,1633368944.189 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20211004T171403/Express0020.lzma
2021-10-04T17:35:45.192Z,1633368945.192 [DataOverHttps](INFO): Moved sent file to Logs/20211004T171403/Express0020.lzma.bak
2021-10-04T17:35:45.192Z,1633368945.192 [DataOverHttps](INFO): SBD MOMSN=15970358
2021-10-04T17:35:46.560Z,1633368946.560 [Default:CheckIn:Read_Iridium] Stopped
2021-10-04T17:35:46.560Z,1633368946.560 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-04T17:35:46.561Z,1633368946.561 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-04T17:35:52.614Z,1633368952.614 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-04T17:38:17.863Z,1633369097.863 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-04T17:39:20.502Z,1633369160.502 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-04T17:39:51.626Z,1633369191.626 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-04T17:40:22.750Z,1633369222.750 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-04T17:40:24.758Z,1633369224.758 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.107391
2021-10-04T17:40:47.297Z,1633369247.297 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-04T17:40:47.297Z,1633369247.297 [Default:CheckIn:C.Wait] Stopped
2021-10-04T17:40:47.297Z,1633369247.297 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-04T17:40:47.297Z,1633369247.297 [Default:CheckIn:D] Running Loop=1
2021-10-04T17:40:47.701Z,1633369247.701 [Default:CheckIn:D] Stopped
2021-10-04T17:40:47.701Z,1633369247.701 [Default:CheckIn:E] Running Loop=1
2021-10-04T17:40:48.101Z,1633369248.101 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 23.182463 min 
2021-10-04T17:40:48.101Z,1633369248.101 [Default:CheckIn:E] Stopped
2021-10-04T17:40:48.101Z,1633369248.101 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-04T17:40:48.101Z,1633369248.101 [Default:CheckIn] Stopped
2021-10-04T17:40:48.101Z,1633369248.101 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-04T17:40:48.101Z,1633369248.101 [Default:CheckIn](INFO): Running loop #5
2021-10-04T17:40:48.102Z,1633369248.102 [Default:CheckIn] Running Loop=5
2021-10-04T17:40:48.102Z,1633369248.102 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-04T17:40:48.102Z,1633369248.102 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-04T17:40:50.116Z,1633369250.116 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174049.00,A,3647.83213,N,12149.81070,W,14.929,262.62,041021,,,A*4C
2021-10-04T17:40:50.118Z,1633369250.118 [NAL9602](INFO): GPS fix at 20211004T174049: (36.797202, -121.830178)
2021-10-04T17:40:50.129Z,1633369250.129 [Default:CheckIn:Read_GPS] Stopped
2021-10-04T17:40:50.130Z,1633369250.130 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-04T17:41:14.794Z,1633369274.794 [NAL9602](INFO): SBD MO Status=2, MOMSN=29692, MT Status=2, MTMSN=0
2021-10-04T17:41:14.794Z,1633369274.794 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-10-04T17:41:24.014Z,1633369284.014 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-04T17:41:31.416Z,1633369291.416 [NAL9602](INFO): SBD MO Status=1, MOMSN=29692, MT Status=0, MTMSN=0
2021-10-04T17:41:31.478Z,1633369291.478 [NAL9602](INFO): Sent 72 bytes from file Logs/20211004T171403/Courier0022.lzma
2021-10-04T17:41:31.478Z,1633369291.478 [NAL9602](INFO): Packets left to send: 0
2021-10-04T17:41:41.458Z,1633369301.458 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003102
2021-10-04T17:41:51.660Z,1633369311.660 [NAL9602](INFO): SBD MO Status=1, MOMSN=29693, MT Status=0, MTMSN=0
2021-10-04T17:41:51.710Z,1633369311.710 [NAL9602](INFO): Sent 146 bytes from file Logs/20211004T171403/Express0023.lzma
2021-10-04T17:41:51.710Z,1633369311.710 [NAL9602](INFO): Packets left to send: 0
2021-10-04T17:41:52.885Z,1633369312.885 [Default:CheckIn:Read_Iridium] Stopped
2021-10-04T17:41:52.885Z,1633369312.885 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-04T17:41:52.885Z,1633369312.885 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-04T17:42:22.366Z,1633369342.366 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-04T17:42:43.726Z,1633369363.726 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-04T17:43:14.850Z,1633369394.850 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-04T17:43:45.974Z,1633369425.974 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-04T17:44:17.098Z,1633369457.098 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-04T17:44:42.198Z,1633369482.198 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.743423
2021-10-04T17:45:18.342Z,1633369518.342 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-04T17:45:49.466Z,1633369549.466 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-04T17:46:20.606Z,1633369580.606 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-04T17:46:51.730Z,1633369611.730 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-04T17:46:53.481Z,1633369613.481 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-04T17:46:53.481Z,1633369613.481 [Default:CheckIn:C.Wait] Stopped
2021-10-04T17:46:53.481Z,1633369613.481 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-04T17:46:53.481Z,1633369613.481 [Default:CheckIn:D] Running Loop=1
2021-10-04T17:46:53.875Z,1633369613.875 [Default:CheckIn:D] Stopped
2021-10-04T17:46:53.875Z,1633369613.875 [Default:CheckIn:E] Running Loop=1
2021-10-04T17:46:54.273Z,1633369614.273 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 29.285356 min 
2021-10-04T17:46:54.273Z,1633369614.273 [Default:CheckIn:E] Stopped
2021-10-04T17:46:54.273Z,1633369614.273 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-04T17:46:54.273Z,1633369614.273 [Default:CheckIn] Stopped
2021-10-04T17:46:54.274Z,1633369614.274 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-04T17:46:54.274Z,1633369614.274 [Default:CheckIn](INFO): Running loop #6
2021-10-04T17:46:54.274Z,1633369614.274 [Default:CheckIn] Running Loop=6
2021-10-04T17:46:54.274Z,1633369614.274 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-04T17:46:54.274Z,1633369614.274 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-04T17:46:56.292Z,1633369616.292 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174655.00,A,3647.81942,N,12150.92103,W,0.641,93.57,041021,,,A*4B
2021-10-04T17:46:56.295Z,1633369616.295 [NAL9602](INFO): GPS fix at 20211004T174655: (36.796990, -121.848684)
2021-10-04T17:46:56.306Z,1633369616.306 [Default:CheckIn:Read_GPS] Stopped
2021-10-04T17:46:56.306Z,1633369616.306 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-04T17:47:21.788Z,1633369641.788 [NAL9602](INFO): SBD MO Status=1, MOMSN=29694, MT Status=0, MTMSN=0
2021-10-04T17:47:21.842Z,1633369641.842 [NAL9602](INFO): Sent 72 bytes from file Logs/20211004T171403/Courier0025.lzma
2021-10-04T17:47:21.842Z,1633369641.842 [NAL9602](INFO): Packets left to send: 0
2021-10-04T17:47:22.854Z,1633369642.854 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-04T17:47:29.920Z,1633369649.920 [NAL9602](INFO): SBD MO Status=1, MOMSN=29695, MT Status=0, MTMSN=0
2021-10-04T17:47:29.978Z,1633369649.978 [NAL9602](INFO): Sent 144 bytes from file Logs/20211004T171403/Express0026.lzma
2021-10-04T17:47:29.978Z,1633369649.978 [NAL9602](INFO): Packets left to send: 0
2021-10-04T17:47:40.420Z,1633369660.420 [NAL9602](INFO): SBD MO Status=0, MOMSN=29696, MT Status=0, MTMSN=0
2021-10-04T17:47:40.504Z,1633369660.504 [Default:CheckIn:Read_Iridium] Stopped
2021-10-04T17:47:40.505Z,1633369660.505 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-04T17:47:40.505Z,1633369660.505 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-04T17:47:53.978Z,1633369673.978 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-04T17:48:11.147Z,1633369691.147 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-04T17:48:25.102Z,1633369705.102 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-04T17:48:56.238Z,1633369736.238 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-04T17:49:27.374Z,1633369767.374 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-04T17:49:58.498Z,1633369798.498 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-04T17:50:29.622Z,1633369829.622 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-04T17:51:00.746Z,1633369860.746 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-04T17:51:31.878Z,1633369891.878 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-04T17:52:03.002Z,1633369923.002 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-04T17:52:34.126Z,1633369954.126 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-04T17:52:41.058Z,1633369961.058 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-04T17:52:41.058Z,1633369961.058 [Default:CheckIn:C.Wait] Stopped
2021-10-04T17:52:41.058Z,1633369961.058 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-04T17:52:41.058Z,1633369961.058 [Default:CheckIn:D] Running Loop=1
2021-10-04T17:52:41.422Z,1633369961.422 [Default:CheckIn:D] Stopped
2021-10-04T17:52:41.422Z,1633369961.422 [Default:CheckIn:E] Running Loop=1
2021-10-04T17:52:41.838Z,1633369961.838 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 35.077816 min 
2021-10-04T17:52:41.838Z,1633369961.838 [Default:CheckIn:E] Stopped
2021-10-04T17:52:41.838Z,1633369961.838 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-04T17:52:41.839Z,1633369961.839 [Default:CheckIn] Stopped
2021-10-04T17:52:41.839Z,1633369961.839 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-04T17:52:41.839Z,1633369961.839 [Default:CheckIn](INFO): Running loop #7
2021-10-04T17:52:41.839Z,1633369961.839 [Default:CheckIn] Running Loop=7
2021-10-04T17:52:41.839Z,1633369961.839 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-04T17:52:41.839Z,1633369961.839 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-04T17:52:43.833Z,1633369963.833 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175243.00,A,3647.82878,N,12150.89401,W,0.389,47.91,041021,,,D*48
2021-10-04T17:52:43.835Z,1633369963.835 [NAL9602](INFO): GPS fix at 20211004T175243: (36.797146, -121.848234)
2021-10-04T17:52:43.874Z,1633369963.874 [Default:CheckIn:Read_GPS] Stopped
2021-10-04T17:52:43.874Z,1633369963.874 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-04T17:52:52.494Z,1633369972.494 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003075
2021-10-04T17:53:01.313Z,1633369981.313 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211004T171403/Courier0028.lzma
2021-10-04T17:53:02.315Z,1633369982.315 [DataOverHttps](INFO): Moved sent file to Logs/20211004T171403/Courier0028.lzma.bak
2021-10-04T17:53:02.315Z,1633369982.315 [DataOverHttps](INFO): SBD MOMSN=15970476
2021-10-04T17:53:18.201Z,1633369998.201 [DataOverHttps](INFO): Sending 141 bytes from file Logs/20211004T171403/Express0029.lzma
2021-10-04T17:53:19.203Z,1633369999.203 [DataOverHttps](INFO): Moved sent file to Logs/20211004T171403/Express0029.lzma.bak
2021-10-04T17:53:19.203Z,1633369999.203 [DataOverHttps](INFO): SBD MOMSN=15970479
2021-10-04T17:53:20.252Z,1633370000.252 [Default:CheckIn:Read_Iridium] Stopped
2021-10-04T17:53:20.252Z,1633370000.252 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-04T17:53:20.252Z,1633370000.252 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-04T17:53:23.447Z,1633370003.447 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-04T17:58:20.841Z,1633370300.841 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-04T17:58:20.841Z,1633370300.841 [Default:CheckIn:C.Wait] Stopped
2021-10-04T17:58:20.841Z,1633370300.841 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-04T17:58:20.841Z,1633370300.841 [Default:CheckIn:D] Running Loop=1
2021-10-04T17:58:21.221Z,1633370301.221 [Default:CheckIn:D] Stopped
2021-10-04T17:58:21.221Z,1633370301.221 [Default:CheckIn:E] Running Loop=1
2021-10-04T17:58:21.642Z,1633370301.642 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 40.741121 min 
2021-10-04T17:58:21.642Z,1633370301.642 [Default:CheckIn:E] Stopped
2021-10-04T17:58:21.642Z,1633370301.642 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-04T17:58:21.642Z,1633370301.642 [Default:CheckIn] Stopped
2021-10-04T17:58:21.642Z,1633370301.642 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-04T17:58:21.642Z,1633370301.642 [Default:CheckIn](INFO): Running loop #8
2021-10-04T17:58:21.642Z,1633370301.642 [Default:CheckIn] Running Loop=8
2021-10-04T17:58:21.643Z,1633370301.643 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-04T17:58:21.643Z,1633370301.643 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-04T17:58:23.637Z,1633370303.637 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175822.00,A,3647.83769,N,12150.87081,W,1.127,62.86,041021,,,D*4F
2021-10-04T17:58:23.640Z,1633370303.640 [NAL9602](INFO): GPS fix at 20211004T175822: (36.797295, -121.847847)
2021-10-04T17:58:23.682Z,1633370303.682 [Default:CheckIn:Read_GPS] Stopped
2021-10-04T17:58:23.682Z,1633370303.682 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-04T17:58:31.141Z,1633370311.141 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211004T171403/Courier0031.lzma
2021-10-04T17:58:32.144Z,1633370312.144 [DataOverHttps](INFO): Moved sent file to Logs/20211004T171403/Courier0031.lzma.bak
2021-10-04T17:58:32.144Z,1633370312.144 [DataOverHttps](INFO): SBD MOMSN=15970509
2021-10-04T17:58:48.482Z,1633370328.482 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20211004T171403/Express0032.lzma
2021-10-04T17:58:49.484Z,1633370329.484 [DataOverHttps](INFO): Moved sent file to Logs/20211004T171403/Express0032.lzma.bak
2021-10-04T17:58:49.484Z,1633370329.484 [DataOverHttps](INFO): SBD MOMSN=15970536
2021-10-04T17:58:50.819Z,1633370330.819 [Default:CheckIn:Read_Iridium] Stopped
2021-10-04T17:58:50.819Z,1633370330.819 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-04T17:58:50.819Z,1633370330.819 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-04T17:58:58.512Z,1633370338.512 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=29697, MT Status=1, MTMSN=2648
2021-10-04T17:58:58.513Z,1633370338.513 [NAL9602](INFO): Data available in MT queue
2021-10-04T17:58:59.006Z,1633370339.006 [NAL9602](INFO): Received command: restart logs