2023-03-22T15:20:39.833Z,1679498439.833 [Supervisor](DEBUG): Initializing supervisor.
2023-03-22T15:20:39.838Z,1679498439.838 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2023-03-22T15:20:39.838Z,1679498439.838 [SyncHandler](INFO): Protected caller Thread ID is 6224
2023-03-22T15:20:39.839Z,1679498439.839 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2023-03-22T15:20:39.840Z,1679498439.840 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2023-03-22T15:20:39.840Z,1679498439.840 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 6225
2023-03-22T15:20:39.844Z,1679498439.844 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2023-03-22T15:20:39.861Z,1679498439.861 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2023-03-22T15:20:39.862Z,1679498439.862 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2023-03-22T15:20:39.863Z,1679498439.863 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 6226
2023-03-22T15:20:39.867Z,1679498439.867 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2023-03-22T15:20:39.868Z,1679498439.868 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2023-03-22T15:20:39.868Z,1679498439.868 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 6227
2023-03-22T15:20:39.870Z,1679498439.870 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2023-03-22T15:20:39.871Z,1679498439.871 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2023-03-22T15:20:39.871Z,1679498439.871 [logger ThreadHandler](INFO): Protected caller Thread ID is 6228
2023-03-22T15:20:39.875Z,1679498439.875 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2023-03-22T15:20:39.875Z,1679498439.875 [Supervisor](INFO): Looking for Config files in directory: Config/
2023-03-22T15:20:39.877Z,1679498439.877 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2023-03-22T15:20:39.970Z,1679498439.970 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2023-03-22T15:20:39.970Z,1679498439.970 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2023-03-22T15:20:40.178Z,1679498440.178 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2023-03-22T15:20:40.179Z,1679498440.179 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2023-03-22T15:20:40.422Z,1679498440.422 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2023-03-22T15:20:40.423Z,1679498440.423 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2023-03-22T15:20:40.527Z,1679498440.527 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2023-03-22T15:20:40.527Z,1679498440.527 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2023-03-22T15:20:41.183Z,1679498441.183 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2023-03-22T15:20:41.183Z,1679498441.183 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2023-03-22T15:20:41.644Z,1679498441.644 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2023-03-22T15:20:41.645Z,1679498441.645 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2023-03-22T15:20:42.112Z,1679498442.112 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2023-03-22T15:20:42.113Z,1679498442.113 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2023-03-22T15:20:42.496Z,1679498442.496 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2023-03-22T15:20:42.496Z,1679498442.496 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2023-03-22T15:20:42.808Z,1679498442.808 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2023-03-22T15:20:42.809Z,1679498442.809 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2023-03-22T15:20:43.164Z,1679498443.164 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2023-03-22T15:20:43.165Z,1679498443.165 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2023-03-22T15:20:43.380Z,1679498443.380 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2023-03-22T15:20:43.381Z,1679498443.381 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2023-03-22T15:20:43.516Z,1679498443.516 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2023-03-22T15:20:43.516Z,1679498443.516 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2023-03-22T15:20:43.595Z,1679498443.595 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2023-03-22T15:20:43.672Z,1679498443.672 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2023-03-22T15:20:43.854Z,1679498443.854 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2023-03-22T15:20:43.854Z,1679498443.854 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2023-03-22T15:20:44.070Z,1679498444.070 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2023-03-22T15:20:44.072Z,1679498444.072 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2023-03-22T15:20:44.073Z,1679498444.073 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2023-03-22T15:20:44.154Z,1679498444.154 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2023-03-22T15:20:44.410Z,1679498444.410 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2023-03-22T15:20:44.411Z,1679498444.411 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2023-03-22T15:20:44.506Z,1679498444.506 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2023-03-22T15:20:44.658Z,1679498444.658 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2023-03-22T15:20:44.854Z,1679498444.854 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2023-03-22T15:20:45.066Z,1679498445.066 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2023-03-22T15:20:45.352Z,1679498445.352 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2023-03-22T15:20:45.476Z,1679498445.476 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2023-03-22T15:20:45.730Z,1679498445.730 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2023-03-22T15:20:46.066Z,1679498446.066 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2023-03-22T15:20:46.161Z,1679498446.161 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2023-03-22T15:20:46.169Z,1679498446.169 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2023-03-22T15:20:46.315Z,1679498446.315 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2023-03-22T15:20:46.316Z,1679498446.316 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2023-03-22T15:20:46.448Z,1679498446.448 [BuoyancyServo] Loaded
2023-03-22T15:20:46.448Z,1679498446.448 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2023-03-22T15:20:46.468Z,1679498446.468 [ElevatorServo] Loaded
2023-03-22T15:20:46.469Z,1679498446.469 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2023-03-22T15:20:46.489Z,1679498446.489 [MassServo] Loaded
2023-03-22T15:20:46.489Z,1679498446.489 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2023-03-22T15:20:46.509Z,1679498446.509 [RudderServo] Loaded
2023-03-22T15:20:46.509Z,1679498446.509 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2023-03-22T15:20:46.524Z,1679498446.524 [ThrusterHE] Loaded
2023-03-22T15:20:46.525Z,1679498446.525 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2023-03-22T15:20:46.525Z,1679498446.525 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2023-03-22T15:20:46.526Z,1679498446.526 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2023-03-22T15:20:46.667Z,1679498446.667 [SBIT](DEBUG): Construct Startup Built In Test.
2023-03-22T15:20:46.682Z,1679498446.682 [SBIT] Loaded
2023-03-22T15:20:46.682Z,1679498446.682 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2023-03-22T15:20:46.685Z,1679498446.685 [IBIT](DEBUG): Construct Initiated Built In Test.
2023-03-22T15:20:46.705Z,1679498446.705 [IBIT] Loaded
2023-03-22T15:20:46.706Z,1679498446.706 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2023-03-22T15:20:46.711Z,1679498446.711 [CBIT](DEBUG): Construct Continuous Built In Test.
2023-03-22T15:20:46.925Z,1679498446.925 [CBIT] Loaded
2023-03-22T15:20:46.926Z,1679498446.926 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2023-03-22T15:20:46.926Z,1679498446.926 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2023-03-22T15:20:46.927Z,1679498446.927 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2023-03-22T15:20:47.092Z,1679498447.092 [CTD_Seabird] Loaded
2023-03-22T15:20:47.092Z,1679498447.092 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2023-03-22T15:20:47.094Z,1679498447.094 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406644E0
2023-03-22T15:20:47.094Z,1679498447.094 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 6311
2023-03-22T15:20:47.125Z,1679498447.125 [ESPComponent] Loaded
2023-03-22T15:20:47.125Z,1679498447.125 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2023-03-22T15:20:47.144Z,1679498447.144 [PAR_Licor] Loaded
2023-03-22T15:20:47.144Z,1679498447.144 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2023-03-22T15:20:47.175Z,1679498447.175 [WetLabsBB2FL] Loaded
2023-03-22T15:20:47.175Z,1679498447.175 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2023-03-22T15:20:47.176Z,1679498447.176 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406944E0
2023-03-22T15:20:47.177Z,1679498447.177 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 6312
2023-03-22T15:20:47.177Z,1679498447.177 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2023-03-22T15:20:47.178Z,1679498447.178 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2023-03-22T15:20:47.228Z,1679498447.228 [DepthRateCalculator] Loaded
2023-03-22T15:20:47.228Z,1679498447.228 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2023-03-22T15:20:47.234Z,1679498447.234 [PitchRateCalculator] Loaded
2023-03-22T15:20:47.234Z,1679498447.234 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2023-03-22T15:20:47.244Z,1679498447.244 [SpeedCalculator] Loaded
2023-03-22T15:20:47.244Z,1679498447.244 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2023-03-22T15:20:47.249Z,1679498447.249 [YawRateCalculator] Loaded
2023-03-22T15:20:47.249Z,1679498447.249 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2023-03-22T15:20:47.268Z,1679498447.268 [ElevatorOffsetCalculator] Loaded
2023-03-22T15:20:47.268Z,1679498447.268 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2023-03-22T15:20:47.269Z,1679498447.269 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2023-03-22T15:20:47.269Z,1679498447.269 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2023-03-22T15:20:47.368Z,1679498447.368 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2023-03-22T15:20:47.368Z,1679498447.368 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2023-03-22T15:20:47.395Z,1679498447.395 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2023-03-22T15:20:47.395Z,1679498447.395 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2023-03-22T15:20:47.507Z,1679498447.507 [DeadReckonUsingMultipleVelocitySources] Loaded
2023-03-22T15:20:47.507Z,1679498447.507 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2023-03-22T15:20:47.521Z,1679498447.521 [NavChart] Loaded
2023-03-22T15:20:47.521Z,1679498447.521 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2023-03-22T15:20:47.527Z,1679498447.527 [UniversalFixResidualReporter] Loaded
2023-03-22T15:20:47.527Z,1679498447.527 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2023-03-22T15:20:47.527Z,1679498447.527 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2023-03-22T15:20:47.528Z,1679498447.528 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2023-03-22T15:20:47.944Z,1679498447.944 [AHRS_M2] Loaded
2023-03-22T15:20:47.944Z,1679498447.944 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2023-03-22T15:20:47.978Z,1679498447.978 [BackseatComponent] Loaded
2023-03-22T15:20:47.979Z,1679498447.979 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2023-03-22T15:20:47.980Z,1679498447.980 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 40A244E0
2023-03-22T15:20:47.980Z,1679498447.980 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 6313
2023-03-22T15:20:47.983Z,1679498447.983 [LcmUniversalReporter] Loaded
2023-03-22T15:20:47.983Z,1679498447.983 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2023-03-22T15:20:48.709Z,1679498448.709 [BPC1] Loaded
2023-03-22T15:20:48.709Z,1679498448.709 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2023-03-22T15:20:48.790Z,1679498448.790 [DataOverHttps] Loaded
2023-03-22T15:20:48.790Z,1679498448.790 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2023-03-22T15:20:48.791Z,1679498448.791 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 40A544E0
2023-03-22T15:20:48.792Z,1679498448.792 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 6314
2023-03-22T15:20:48.812Z,1679498448.812 [Depth_Keller] Loaded
2023-03-22T15:20:48.813Z,1679498448.813 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2023-03-22T15:20:48.818Z,1679498448.818 [DropWeight] Loaded
2023-03-22T15:20:48.818Z,1679498448.818 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2023-03-22T15:20:48.856Z,1679498448.856 [DVL_micro] Loaded
2023-03-22T15:20:48.856Z,1679498448.856 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2023-03-22T15:20:48.875Z,1679498448.875 [MultiRay] Loaded
2023-03-22T15:20:48.875Z,1679498448.875 [ComponentRegistry](DEBUG): SyncComponent "MultiRay" handled in the control thread.
2023-03-22T15:20:48.934Z,1679498448.934 [NAL9602] Loaded
2023-03-22T15:20:48.935Z,1679498448.935 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2023-03-22T15:20:48.960Z,1679498448.960 [Onboard] Loaded
2023-03-22T15:20:48.960Z,1679498448.960 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2023-03-22T15:20:48.961Z,1679498448.961 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40A844E0
2023-03-22T15:20:48.962Z,1679498448.962 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 6315
2023-03-22T15:20:48.975Z,1679498448.975 [Power24vConverter] Loaded
2023-03-22T15:20:48.975Z,1679498448.975 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2023-03-22T15:20:48.988Z,1679498448.988 [Radio_Surface] Loaded
2023-03-22T15:20:48.989Z,1679498448.989 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2023-03-22T15:20:48.990Z,1679498448.990 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40AB44E0
2023-03-22T15:20:48.990Z,1679498448.990 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 6316
2023-03-22T15:20:49.083Z,1679498449.083 [DAT] Loaded
2023-03-22T15:20:49.083Z,1679498449.083 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2023-03-22T15:20:49.084Z,1679498449.084 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40AE44E0
2023-03-22T15:20:49.084Z,1679498449.084 [DAT ThreadHandler](INFO): Protected caller Thread ID is 6317
2023-03-22T15:20:49.085Z,1679498449.085 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2023-03-22T15:20:49.085Z,1679498449.085 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2023-03-22T15:20:49.142Z,1679498449.142 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2023-03-22T15:20:49.143Z,1679498449.143 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2023-03-22T15:20:49.193Z,1679498449.193 [VerticalControl](DEBUG): Construct VerticalControl.
2023-03-22T15:20:49.243Z,1679498449.243 [VerticalControl] Loaded
2023-03-22T15:20:49.243Z,1679498449.243 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2023-03-22T15:20:49.246Z,1679498449.246 [HorizontalControl](DEBUG): Construct HorizontalControl.
2023-03-22T15:20:49.283Z,1679498449.283 [HorizontalControl] Loaded
2023-03-22T15:20:49.283Z,1679498449.283 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2023-03-22T15:20:49.285Z,1679498449.285 [SpeedControl](DEBUG): Construct SpeedControl.
2023-03-22T15:20:49.287Z,1679498449.287 [SpeedControl] Loaded
2023-03-22T15:20:49.287Z,1679498449.287 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2023-03-22T15:20:49.290Z,1679498449.290 [LoopControl](DEBUG): Construct LoopControl.
2023-03-22T15:20:49.290Z,1679498449.290 [LoopControl] Loaded
2023-03-22T15:20:49.291Z,1679498449.291 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2023-03-22T15:20:49.291Z,1679498449.291 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2023-03-22T15:20:49.292Z,1679498449.292 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2023-03-22T15:20:49.302Z,1679498449.302 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2023-03-22T15:20:49.303Z,1679498449.303 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2023-03-22T15:20:49.609Z,1679498449.609 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2023-03-22T15:20:49.615Z,1679498449.615 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2023-03-22T15:20:49.618Z,1679498449.618 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2023-03-22T15:20:49.629Z,1679498449.629 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2023-03-22T15:20:49.630Z,1679498449.630 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BDE4E0
2023-03-22T15:20:49.630Z,1679498449.630 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 6318
2023-03-22T15:20:49.635Z,1679498449.635 [Supervisor](INFO): Main Thread ID is 6223
2023-03-22T15:20:49.635Z,1679498449.635 [Supervisor](DEBUG): Running supervisor.
2023-03-22T15:20:49.636Z,1679498449.636 [CommandExec ThreadHandler](INFO): Handler Thread ID is 6319
2023-03-22T15:20:49.636Z,1679498449.636 [CommandExec](INFO): Initializing the command executive.
2023-03-22T15:20:49.638Z,1679498449.638 [CommandLine ThreadHandler](INFO): Handler Thread ID is 6320
2023-03-22T15:20:49.640Z,1679498449.640 [controlThread ThreadHandler](INFO): Handler Thread ID is 6321
2023-03-22T15:20:49.640Z,1679498449.640 [controlThread](DEBUG): Initializing ControlThread
2023-03-22T15:20:49.642Z,1679498449.642 [SBIT](INFO): Initialize SBIT Component.
2023-03-22T15:20:49.643Z,1679498449.643 [SBIT](IMPORTANT): git: 2023-03-21
2023-03-22T15:20:49.643Z,1679498449.643 [SBIT](INFO): git hash: 28f27c305fcecd3fd8a0a0fe0a8b41600ede02df
2023-03-22T15:20:49.643Z,1679498449.643 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2023-03-22T15:20:49.645Z,1679498449.645 [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-03-22T15:20:49.646Z,1679498449.646 [SBIT](INFO): Beginning SBIT in 160.000000 seconds.
2023-03-22T15:20:49.646Z,1679498449.646 [IBIT](INFO): Initialize IBIT Component.
2023-03-22T15:20:49.647Z,1679498449.647 [CBIT](DEBUG): Initialize CBIT Component.
2023-03-22T15:20:49.648Z,1679498449.648 [logger ThreadHandler](INFO): Handler Thread ID is 6322
2023-03-22T15:20:49.661Z,1679498449.661 [CBIT](DEBUG): Initialized mux pins.
2023-03-22T15:20:49.661Z,1679498449.661 [CBIT](DEBUG): Initializing the watchdog timer.
2023-03-22T15:20:49.673Z,1679498449.673 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 6323
2023-03-22T15:20:49.674Z,1679498449.674 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2023-03-22T15:20:49.679Z,1679498449.679 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 6325
2023-03-22T15:20:49.681Z,1679498449.681 [WetLabsBB2FL](INFO): Powering up
2023-03-22T15:20:49.683Z,1679498449.683 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 6327
2023-03-22T15:20:49.685Z,1679498449.685 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2023-03-22T15:20:49.686Z,1679498449.686 [CBIT](DEBUG): Initializing heartbeat.
2023-03-22T15:20:49.700Z,1679498449.700 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 6328
2023-03-22T15:20:49.701Z,1679498449.701 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2023-03-22T15:20:49.714Z,1679498449.714 [Onboard ThreadHandler](INFO): Handler Thread ID is 6329
2023-03-22T15:20:49.731Z,1679498449.731 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 6330
2023-03-22T15:20:49.749Z,1679498449.749 [DAT ThreadHandler](INFO): Handler Thread ID is 6331
2023-03-22T15:20:49.750Z,1679498449.750 [DAT](INFO): Powering up
2023-03-22T15:20:49.750Z,1679498449.750 [DAT](DEBUG): Initializing DAT.
2023-03-22T15:20:49.754Z,1679498449.754 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 6333
2023-03-22T15:20:49.757Z,1679498449.757 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2023-03-22T15:20:49.757Z,1679498449.757 [CBIT](DEBUG): Deactivating GF circuits.
2023-03-22T15:20:49.757Z,1679498449.757 [CBIT](DEBUG): Deactivating emergency mode.
2023-03-22T15:20:49.758Z,1679498449.758 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2023-03-22T15:20:49.758Z,1679498449.758 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2023-03-22T15:20:49.758Z,1679498449.758 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2023-03-22T15:20:49.758Z,1679498449.758 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2023-03-22T15:20:49.758Z,1679498449.758 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2023-03-22T15:20:49.758Z,1679498449.758 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2023-03-22T15:20:49.759Z,1679498449.759 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2023-03-22T15:20:49.759Z,1679498449.759 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA69M.000
2023-03-22T15:20:49.759Z,1679498449.759 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA69M.000
2023-03-22T15:20:49.797Z,1679498449.797 [CBIT](DEBUG): Backplane powered.
2023-03-22T15:20:49.801Z,1679498449.801 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2023-03-22T15:20:49.802Z,1679498449.802 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2023-03-22T15:20:49.802Z,1679498449.802 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2023-03-22T15:20:49.802Z,1679498449.802 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2023-03-22T15:20:49.803Z,1679498449.803 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2023-03-22T15:20:49.804Z,1679498449.804 [NavChart](DEBUG): Initialize NavChart Navigation.
2023-03-22T15:20:49.804Z,1679498449.804 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2023-03-22T15:20:49.811Z,1679498449.811 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2023-03-22T15:20:49.817Z,1679498449.817 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2023-03-22T15:20:49.818Z,1679498449.818 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2023-03-22T15:20:49.819Z,1679498449.819 [LoopControl](DEBUG): Initialize LoopControlComponent.
2023-03-22T15:20:49.819Z,1679498449.819 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2023-03-22T15:20:49.853Z,1679498449.853 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2023-03-22T15:20:49.904Z,1679498449.904 [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-03-22T15:20:49.905Z,1679498449.905 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2023-03-22T15:20:50.052Z,1679498450.052 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2023-03-22T15:20:50.065Z,1679498450.065 [Default:A.Wait](DEBUG): Construct Wait.
2023-03-22T15:20:50.067Z,1679498450.067 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-03-22T15:20:50.111Z,1679498450.111 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2023-03-22T15:20:50.122Z,1679498450.122 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2023-03-22T15:20:50.137Z,1679498450.137 [Radio_Surface](INFO): Powering up
2023-03-22T15:20:50.161Z,1679498450.161 [Default:E.Execute](DEBUG): Construct Execute.
2023-03-22T15:20:50.173Z,1679498450.173 [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-03-22T15:20:50.178Z,1679498450.178 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,MultiRay,NAL9602,Power24vConverter,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2023-03-22T15:20:50.203Z,1679498450.203 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-03-22T15:20:50.270Z,1679498450.270 [Depth_Keller](ERROR): Pressure or depth reading out of range: 1895.444336 decibar, 0.000000 m
2023-03-22T15:20:50.298Z,1679498450.298 [MultiRay](INFO): Powering up MultiRay Lights
2023-03-22T15:20:50.334Z,1679498450.334 [Power24vConverter](INFO): Powering up.
2023-03-22T15:20:50.344Z,1679498450.344 [DepthRateCalculator](ERROR): Depth measurement is not active
2023-03-22T15:20:50.379Z,1679498450.379 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2023-03-22T15:20:50.385Z,1679498450.385 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2023-03-22T15:20:50.386Z,1679498450.386 [ElevatorServo](DEBUG): Initializing EZServoServo.
2023-03-22T15:20:50.401Z,1679498450.401 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2023-03-22T15:20:50.402Z,1679498450.402 [MassServo](DEBUG): Initializing EZServoServo.
2023-03-22T15:20:50.409Z,1679498450.409 [MassServo](DEBUG): Initializing MassServo.
2023-03-22T15:20:50.410Z,1679498450.410 [RudderServo](DEBUG): Initializing EZServoServo.
2023-03-22T15:20:50.417Z,1679498450.417 [RudderServo](DEBUG): Initializing RudderServo.
2023-03-22T15:20:50.418Z,1679498450.418 [ThrusterHE](DEBUG): Initializing EZServoServo.
2023-03-22T15:20:50.425Z,1679498450.425 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2023-03-22T15:20:50.998Z,1679498450.998 [Depth_Keller](ERROR): Pressure or depth reading out of range: -0.605145 decibar, -0.600682 m
2023-03-22T15:20:51.337Z,1679498451.337 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2023-03-22T15:20:51.337Z,1679498451.337 [RudderServo](FAULT): Rudder failed to initialize
2023-03-22T15:20:51.337Z,1679498451.337 [RudderServo] Communications Fault, FailCount= 1
2023-03-22T15:20:51.337Z,1679498451.337 [RudderServo](ERROR): Communications Fault
2023-03-22T15:20:51.341Z,1679498451.341 [CBIT](ERROR): Communications Fault in component: RudderServo
2023-03-22T15:20:51.785Z,1679498451.785 [WetLabsBB2FL](INFO): Powering down
2023-03-22T15:20:51.794Z,1679498451.794 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2023-03-22T15:20:51.794Z,1679498451.794 [RudderServo](INFO): Powering down
2023-03-22T15:20:52.214Z,1679498452.214 [Depth_Keller](FAULT): Pressure or depth reading out of range for max 3 samples
2023-03-22T15:20:52.214Z,1679498452.214 [Depth_Keller] Data Fault, FailCount= 1
2023-03-22T15:20:52.214Z,1679498452.214 [Depth_Keller](ERROR): Data Fault
2023-03-22T15:20:52.225Z,1679498452.225 [RudderServo](DEBUG): Initializing EZServoServo.
2023-03-22T15:20:52.346Z,1679498452.346 [RudderServo](DEBUG): Initializing RudderServo.
2023-03-22T15:20:52.350Z,1679498452.350 [CBIT](INFO): Clearing failed state for component RudderServo
2023-03-22T15:20:52.350Z,1679498452.350 [RudderServo] No Fault, FailCount= 1
2023-03-22T15:20:52.351Z,1679498452.351 [CBIT](ERROR): Data Fault in component: Depth_Keller
2023-03-22T15:20:52.351Z,1679498452.351 [CBIT](INFO): Clearing failed state for component Depth_Keller
2023-03-22T15:20:52.351Z,1679498452.351 [Depth_Keller] No Fault, FailCount= 0
2023-03-22T15:20:56.074Z,1679498456.074 [ThrusterHE](ERROR): Zero Speed Commanded.
2023-03-22T15:21:01.594Z,1679498461.594 [DAT](INFO): DAT read: 

2023-03-22T15:21:01.596Z,1679498461.596 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series

2023-03-22T15:21:03.106Z,1679498463.106 [DAT](INFO): DAT read: MF Frequency Band

2023-03-22T15:21:03.107Z,1679498463.107 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0

2023-03-22T15:21:03.108Z,1679498463.108 [DAT](INFO): DAT read: Mar 22 2023 15:20:57 

2023-03-22T15:21:03.507Z,1679498463.507 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004661
2023-03-22T15:21:04.114Z,1679498464.114 [DAT](INFO): DAT read: Features enabled [Bearing]

2023-03-22T15:21:04.115Z,1679498464.115 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC

2023-03-22T15:21:04.116Z,1679498464.116 [DAT](INFO): commRate: 1200
2023-03-22T15:21:06.181Z,1679498466.181 [DAT](INFO): entering command mode
2023-03-22T15:21:06.382Z,1679498466.382 [DAT](INFO): DAT read: 

2023-03-22T15:21:06.382Z,1679498466.382 [DAT](INFO): DAT read: user:1>

2023-03-22T15:21:06.382Z,1679498466.382 [DAT](INFO): setting verbose to 3
2023-03-22T15:21:06.634Z,1679498466.634 [DAT](INFO): DAT read: user:1>

2023-03-22T15:21:06.635Z,1679498466.635 [DAT](INFO): DAT read: Verbose         | 3           

2023-03-22T15:21:06.635Z,1679498466.635 [DAT](INFO): set verbose to 3
2023-03-22T15:21:06.635Z,1679498466.635 [DAT](INFO): setting DatVerbose to 27440
2023-03-22T15:21:06.886Z,1679498466.886 [DAT](INFO): DAT read: user:2>

2023-03-22T15:21:06.887Z,1679498466.887 [DAT](INFO): DAT read: DatVerbose      | 27440       

2023-03-22T15:21:06.887Z,1679498466.887 [DAT](INFO): set DatVerbose to 27440
2023-03-22T15:21:06.887Z,1679498466.887 [DAT](INFO): setting transmit power to 8
2023-03-22T15:21:07.138Z,1679498467.138 [DAT](INFO): DAT read: user:3>

2023-03-22T15:21:07.139Z,1679498467.139 [DAT](INFO): DAT read: TxPower         | 8 (Max)     

2023-03-22T15:21:07.139Z,1679498467.139 [DAT](INFO): set transmit power to 8
2023-03-22T15:21:07.139Z,1679498467.139 [DAT](INFO): setting local address to 4
2023-03-22T15:21:07.390Z,1679498467.390 [DAT](INFO): DAT read: user:4>

2023-03-22T15:21:07.391Z,1679498467.391 [DAT](INFO): DAT read: LocalAddr       | 4           

2023-03-22T15:21:07.391Z,1679498467.391 [DAT](INFO): set local address to 4
2023-03-22T15:21:07.392Z,1679498467.392 [DAT](INFO): Setting time to: 15:21:7 And date to:3/22/2023
2023-03-22T15:21:07.648Z,1679498467.648 [DAT](INFO): DAT read: user:5>

2023-03-22T15:21:07.652Z,1679498467.652 [DAT](INFO): DAT read: Wed Mar 22, 2023  15:21:07  

2023-03-22T15:21:07.654Z,1679498467.654 [DAT](INFO): Local DAT time set to Wed Mar 22, 2023  15:21:07  

2023-03-22T15:21:19.292Z,1679498479.292 [NAL9602](INFO): Powering up NAL9602
2023-03-22T15:21:30.192Z,1679498490.192 [NAL9602](INFO): NAL9602 initialized
2023-03-22T15:22:00.994Z,1679498520.994 [DVL_micro](ERROR): only read 1 of 4 data items
2023-03-22T15:22:00.995Z,1679498520.995 [DVL_micro](ERROR): Failed to parse:
:RD,+9999..99,+9999.99,+9999.99
2023-03-22T15:22:10.705Z,1679498530.705 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2023-03-22T15:22:38.583Z,1679498558.583 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2023-03-22T15:23:05.647Z,1679498585.647 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2023-03-22T15:23:25.855Z,1679498605.855 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2023-03-22T15:23:30.249Z,1679498610.249 [SBIT](IMPORTANT): Beginning Startup BIT
2023-03-22T15:23:30.254Z,1679498610.254 [CBIT](IMPORTANT): Beginning ground fault scan
2023-03-22T15:23:41.178Z,1679498621.178 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.034436
CHAN A1 (24V): 0.034911
CHAN A2 (12V): 0.001757
CHAN A3 (5V): -0.002658
CHAN B0 (3.3V): -0.001491
CHAN B1 (3.15aV): -0.001591
CHAN B2 (3.15bV): -0.001724
CHAN B3 (GND): -0.002572
OPEN: 0.007022
Full Scale: +/- 1 mA
2023-03-22T15:23:50.046Z,1679498630.046 [DVL_micro](ERROR): only read 0 of 4 data items
2023-03-22T15:23:50.046Z,1679498630.046 [DVL_micro](ERROR): Failed to parse:
:RD,,+9999.99,+9999.99,+9999.99
2023-03-22T15:23:50.093Z,1679498630.093 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2023-03-22T15:23:50.093Z,1679498630.093 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-03-22T15:23:50.190Z,1679498630.190 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-03-22T15:23:50.554Z,1679498630.554 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-03-22T15:23:50.554Z,1679498630.554 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2023-03-22T15:24:11.071Z,1679498651.071 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadB4
2023-03-22T15:24:13.575Z,1679498653.575 [CommandExec](IMPORTANT): got command gfscan
2023-03-22T15:24:13.602Z,1679498653.602 [CBIT](IMPORTANT): Beginning ground fault scan
2023-03-22T15:24:20.331Z,1679498660.331 [DVL_micro](ERROR): No DVL communication! Re-initializing
2023-03-22T15:24:20.331Z,1679498660.331 [DVL_micro] Communications Fault, FailCount= 1
2023-03-22T15:24:20.331Z,1679498660.331 [DVL_micro](ERROR): Communications Fault
2023-03-22T15:24:20.349Z,1679498660.349 [CBIT](ERROR): Communications Fault in component: DVL_micro
2023-03-22T15:24:20.809Z,1679498660.809 [DVL_micro](INFO): Powering down
2023-03-22T15:24:21.571Z,1679498661.571 [CBIT](INFO): Clearing failed state for component DVL_micro
2023-03-22T15:24:21.571Z,1679498661.571 [DVL_micro] No Fault, FailCount= 1
2023-03-22T15:24:24.412Z,1679498664.412 [SBIT](IMPORTANT): SBIT PASSED
2023-03-22T15:24:24.412Z,1679498664.412 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-03-22T15:24:24.413Z,1679498664.413 [SBIT](IMPORTANT): Depth_Keller.offset=-0.8 decibar;

2023-03-22T15:24:24.413Z,1679498664.413 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=4 minute;

2023-03-22T15:24:24.413Z,1679498664.413 [SBIT](IMPORTANT): ESPComponent.simulateHardware=1 bool;

2023-03-22T15:24:24.413Z,1679498664.413 [SBIT](IMPORTANT): ElevatorServo.offsetAngle=1 degree;

2023-03-22T15:24:24.413Z,1679498664.413 [SBIT](IMPORTANT): Express none WetLabsBB2FL.BackscatteringCoeff470nm;

2023-03-22T15:24:24.414Z,1679498664.414 [SBIT](IMPORTANT): Express none WetLabsBB2FL.BackscatteringCoeff650nm;

2023-03-22T15:24:24.414Z,1679498664.414 [SBIT](IMPORTANT): VerticalControl.massDefault=3.5 centimeter;

2023-03-22T15:24:24.810Z,1679498664.810 [MissionManager](IMPORTANT): Started mission Startup
2023-03-22T15:24:24.810Z,1679498664.810 [Startup] Running Loop=1
2023-03-22T15:24:24.810Z,1679498664.810 [Startup](DEBUG): Aggregate::initialize Startup
2023-03-22T15:24:24.810Z,1679498664.810 [Startup:A.GoToSurface] Running Loop=1
2023-03-22T15:24:24.810Z,1679498664.810 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-03-22T15:24:24.811Z,1679498664.811 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-03-22T15:24:24.811Z,1679498664.811 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-03-22T15:24:24.812Z,1679498664.812 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-03-22T15:24:24.812Z,1679498664.812 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-03-22T15:24:24.813Z,1679498664.813 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-03-22T15:24:24.814Z,1679498664.814 [Startup:StartupSatComms] Running Loop=1
2023-03-22T15:24:24.814Z,1679498664.814 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2023-03-22T15:24:24.814Z,1679498664.814 [Startup:StartupSatComms:A] Running Loop=1
2023-03-22T15:24:24.827Z,1679498664.827 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.022157
CHAN A1 (24V): 0.019038
CHAN A2 (12V): -0.002810
CHAN A3 (5V): -0.002172
CHAN B0 (3.3V): -0.000681
CHAN B1 (3.15aV): -0.005608
CHAN B2 (3.15bV): -0.000348
CHAN B3 (GND): -0.001369
OPEN: 0.006535
Full Scale: +/- 1 mA
2023-03-22T15:24:25.207Z,1679498665.207 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2023-03-22T15:24:39.384Z,1679498679.384 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2023-03-22T15:24:40.597Z,1679498680.597 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2023-03-22T15:25:25.009Z,1679498725.009 [Startup:StartupSatComms:A](INFO): Timed out from 2023-03-22T15:24:24.8Z
2023-03-22T15:25:25.009Z,1679498725.009 [Startup:StartupSatComms:A] Stopped
2023-03-22T15:25:25.010Z,1679498725.010 [Startup:StartupSatComms:B] Running Loop=1
2023-03-22T15:25:25.395Z,1679498725.395 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-03-22T15:25:27.834Z,1679498727.834 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-03-22T15:25:27.834Z,1679498727.834 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+18.5,0000.0,00
2023-03-22T15:25:30.653Z,1679498730.653 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230321T235301/Courier0007.lzma
2023-03-22T15:25:31.655Z,1679498731.655 [DataOverHttps](INFO): Moved sent file to Logs/20230321T235301/Courier0007.lzma.bak
2023-03-22T15:25:31.655Z,1679498731.655 [DataOverHttps](INFO): SBD MOMSN=17540432
2023-03-22T15:25:47.585Z,1679498747.585 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20230322T001314/Courier0000.lzma
2023-03-22T15:25:48.588Z,1679498748.588 [DataOverHttps](INFO): Moved sent file to Logs/20230322T001314/Courier0000.lzma.bak
2023-03-22T15:25:48.588Z,1679498748.588 [DataOverHttps](INFO): SBD MOMSN=17540434
2023-03-22T15:26:04.357Z,1679498764.357 [DataOverHttps](INFO): Sending 229 bytes from file Logs/20230322T001314/Courier0004.lzma
2023-03-22T15:26:05.359Z,1679498765.359 [DataOverHttps](INFO): Moved sent file to Logs/20230322T001314/Courier0004.lzma.bak
2023-03-22T15:26:05.359Z,1679498765.359 [DataOverHttps](INFO): SBD MOMSN=17540437
2023-03-22T15:26:21.021Z,1679498781.021 [DataOverHttps](INFO): Sending 103 bytes from file Logs/20230322T001314/Courier0007.lzma
2023-03-22T15:26:22.023Z,1679498782.023 [DataOverHttps](INFO): Moved sent file to Logs/20230322T001314/Courier0007.lzma.bak
2023-03-22T15:26:22.023Z,1679498782.023 [DataOverHttps](INFO): SBD MOMSN=17540442
2023-03-22T15:26:25.319Z,1679498785.319 [Startup:StartupSatComms:B](INFO): Timed out from 2023-03-22T15:25:25.0Z
2023-03-22T15:26:25.319Z,1679498785.319 [Startup:StartupSatComms:B] Stopped
2023-03-22T15:26:25.319Z,1679498785.319 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2023-03-22T15:26:25.319Z,1679498785.319 [Startup:StartupSatComms] Stopped
2023-03-22T15:26:25.319Z,1679498785.319 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2023-03-22T15:26:25.320Z,1679498785.320 [Startup](INFO): Completed Startup
2023-03-22T15:26:25.320Z,1679498785.320 [MissionManager](INFO): Startup is completed.
2023-03-22T15:26:25.320Z,1679498785.320 [MissionManager](INFO): Uninitializing Mission Startup
2023-03-22T15:26:25.320Z,1679498785.320 [Startup] Stopped
2023-03-22T15:26:25.320Z,1679498785.320 [Startup](DEBUG): Aggregate::uninitialize Startup
2023-03-22T15:26:25.321Z,1679498785.321 [Startup:A.GoToSurface] Stopped
2023-03-22T15:26:25.321Z,1679498785.321 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-03-22T15:26:25.639Z,1679498785.639 [MissionManager](IMPORTANT): Started mission Default
2023-03-22T15:26:25.639Z,1679498785.639 [Default] Running Loop=1
2023-03-22T15:26:25.639Z,1679498785.639 [Default](DEBUG): Aggregate::initialize Default
2023-03-22T15:26:25.639Z,1679498785.639 [Default:B.GoToSurface] Running Loop=1
2023-03-22T15:26:25.639Z,1679498785.639 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-03-22T15:26:25.640Z,1679498785.640 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-03-22T15:26:25.640Z,1679498785.640 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-03-22T15:26:25.640Z,1679498785.640 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-03-22T15:26:25.641Z,1679498785.641 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-03-22T15:26:25.645Z,1679498785.645 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-03-22T15:26:25.645Z,1679498785.645 [Default:A.Wait] Running Loop=1
2023-03-22T15:26:25.646Z,1679498785.646 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-03-22T15:26:33.246Z,1679498793.246 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-03-22T15:26:38.016Z,1679498798.016 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20230322T152039/Courier0000.lzma
2023-03-22T15:26:38.979Z,1679498798.979 [Default:A.Wait](INFO): Done Waiting.
2023-03-22T15:26:38.979Z,1679498798.979 [Default:A.Wait] Stopped
2023-03-22T15:26:38.979Z,1679498798.979 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T15:26:39.019Z,1679498799.019 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Courier0000.lzma.bak
2023-03-22T15:26:39.019Z,1679498799.019 [DataOverHttps](INFO): SBD MOMSN=17540453
2023-03-22T15:26:39.359Z,1679498799.359 [Default:CheckIn] Running Loop=1
2023-03-22T15:26:39.359Z,1679498799.359 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T15:26:39.359Z,1679498799.359 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T15:26:39.759Z,1679498799.759 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-03-22T15:26:51.030Z,1679498811.030 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2023-03-22T15:26:51.030Z,1679498811.030 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-03-22T15:26:51.040Z,1679498811.040 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-03-22T15:26:51.494Z,1679498811.494 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-03-22T15:26:51.495Z,1679498811.495 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2023-03-22T15:28:45.382Z,1679498925.382 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-03-22T15:28:45.383Z,1679498925.383 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+1.0,1489.0,000
2023-03-22T15:28:56.689Z,1679498936.689 [BPC1](ERROR): Battery stick #61 (s/n: 04A4) reported OVER_TEMP_ALARM. Status code: 0x1717.
2023-03-22T15:28:56.689Z,1679498936.689 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 6.
2023-03-22T15:28:56.693Z,1679498936.693 [BPC1](INFO): Received data from all battery sticks.
2023-03-22T15:29:52.052Z,1679498992.052 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2023-03-22T15:29:52.053Z,1679498992.053 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-03-22T15:29:52.063Z,1679498992.063 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-03-22T15:29:52.472Z,1679498992.472 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-03-22T15:29:52.472Z,1679498992.472 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2023-03-22T15:31:32.260Z,1679499092.260 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-03-22T15:31:32.260Z,1679499092.260 [NAL9602] Data Fault, FailCount= 1
2023-03-22T15:31:32.260Z,1679499092.260 [NAL9602](ERROR): Data Fault
2023-03-22T15:31:32.277Z,1679499092.277 [CBIT](ERROR): Data Fault in component: NAL9602
2023-03-22T15:31:32.673Z,1679499092.673 [NAL9602](INFO): Powering down
2023-03-22T15:31:33.496Z,1679499093.496 [CBIT](INFO): Clearing failed state for component NAL9602
2023-03-22T15:31:33.496Z,1679499093.496 [NAL9602] No Fault, FailCount= 1
2023-03-22T15:31:39.571Z,1679499099.571 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-03-22T15:26:39.4Z
2023-03-22T15:31:39.571Z,1679499099.571 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T15:31:39.571Z,1679499099.571 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T15:31:39.962Z,1679499099.962 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-03-22T15:31:41.510Z,1679499101.510 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20230322T152039/Courier0004.lzma
2023-03-22T15:31:42.499Z,1679499102.499 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Courier0004.lzma.bak
2023-03-22T15:31:42.499Z,1679499102.499 [DataOverHttps](INFO): SBD MOMSN=17540461
2023-03-22T15:31:58.083Z,1679499118.083 [DataOverHttps](INFO): Sending 723 bytes from file Logs/20230321T232704/Express0008.lzma
2023-03-22T15:31:59.083Z,1679499119.083 [DataOverHttps](INFO): Moved sent file to Logs/20230321T232704/Express0008.lzma.bak
2023-03-22T15:31:59.083Z,1679499119.083 [DataOverHttps](INFO): SBD MOMSN=17540463
2023-03-22T15:32:03.058Z,1679499123.058 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-03-22T15:32:03.058Z,1679499123.058 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+18.6,0000.0000
2023-03-22T15:32:03.059Z,1679499123.059 [NAL9602](INFO): Powering up NAL9602
2023-03-22T15:32:13.968Z,1679499133.968 [NAL9602](INFO): NAL9602 initialized
2023-03-22T15:32:14.725Z,1679499134.725 [DataOverHttps](INFO): Sending 355 bytes from file Logs/20230321T235238/Express0001.lzma
2023-03-22T15:32:15.727Z,1679499135.727 [DataOverHttps](INFO): Moved sent file to Logs/20230321T235238/Express0001.lzma.bak
2023-03-22T15:32:15.728Z,1679499135.728 [DataOverHttps](INFO): SBD MOMSN=17540507
2023-03-22T15:32:31.322Z,1679499151.322 [DataOverHttps](INFO): Sending 1126 bytes from file Logs/20230321T235301/Express0001.lzma
2023-03-22T15:32:32.323Z,1679499152.323 [DataOverHttps](INFO): Moved sent file to Logs/20230321T235301/Express0001.lzma.bak
2023-03-22T15:32:32.323Z,1679499152.323 [DataOverHttps](INFO): SBD MOMSN=17540514
2023-03-22T15:32:48.149Z,1679499168.149 [DataOverHttps](INFO): Sending 477 bytes from file Logs/20230321T235301/Express0005.lzma
2023-03-22T15:32:49.151Z,1679499169.151 [DataOverHttps](INFO): Moved sent file to Logs/20230321T235301/Express0005.lzma.bak
2023-03-22T15:32:49.151Z,1679499169.151 [DataOverHttps](INFO): SBD MOMSN=17540562
2023-03-22T15:32:53.180Z,1679499173.180 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2023-03-22T15:32:53.180Z,1679499173.180 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-03-22T15:32:53.198Z,1679499173.198 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-03-22T15:32:53.603Z,1679499173.603 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-03-22T15:32:53.604Z,1679499173.604 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2023-03-22T15:32:56.379Z,1679499176.379 [DVL_micro](ERROR): No DVL communication! Re-initializing
2023-03-22T15:32:56.379Z,1679499176.379 [DVL_micro] Communications Fault, FailCount= 1
2023-03-22T15:32:56.379Z,1679499176.379 [DVL_micro](ERROR): Communications Fault
2023-03-22T15:32:56.397Z,1679499176.397 [CBIT](ERROR): Communications Fault in component: DVL_micro
2023-03-22T15:32:56.857Z,1679499176.857 [DVL_micro](INFO): Powering down
2023-03-22T15:32:57.634Z,1679499177.634 [CBIT](INFO): Clearing failed state for component DVL_micro
2023-03-22T15:32:57.635Z,1679499177.635 [DVL_micro] No Fault, FailCount= 1
2023-03-22T15:33:03.701Z,1679499183.701 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20230321T235301/Express0008.lzma
2023-03-22T15:33:04.703Z,1679499184.703 [DataOverHttps](INFO): Moved sent file to Logs/20230321T235301/Express0008.lzma.bak
2023-03-22T15:33:04.703Z,1679499184.703 [DataOverHttps](INFO): SBD MOMSN=17540573
2023-03-22T15:33:15.363Z,1679499195.363 [DVL_micro](FAULT): Failed to initialize within timeout.
2023-03-22T15:33:15.363Z,1679499195.363 [DVL_micro] Communications Fault, FailCount= 2
2023-03-22T15:33:15.364Z,1679499195.364 [DVL_micro](ERROR): Communications Fault
2023-03-22T15:33:15.392Z,1679499195.392 [CBIT](ERROR): Communications Fault in component: DVL_micro
2023-03-22T15:33:15.849Z,1679499195.849 [DVL_micro](INFO): Powering down
2023-03-22T15:33:16.634Z,1679499196.634 [CBIT](INFO): Clearing failed state for component DVL_micro
2023-03-22T15:33:16.634Z,1679499196.634 [DVL_micro] No Fault, FailCount= 2
2023-03-22T15:33:20.230Z,1679499200.230 [DataOverHttps](INFO): Sending 1081 bytes from file Logs/20230322T001314/Express0001.lzma
2023-03-22T15:33:21.231Z,1679499201.231 [DataOverHttps](INFO): Moved sent file to Logs/20230322T001314/Express0001.lzma.bak
2023-03-22T15:33:21.231Z,1679499201.231 [DataOverHttps](INFO): SBD MOMSN=17540577
2023-03-22T15:33:34.366Z,1679499214.366 [DVL_micro](FAULT): Failed to initialize within timeout.
2023-03-22T15:33:34.366Z,1679499214.366 [DVL_micro] Communications Fault, FailCount= 3
2023-03-22T15:33:34.366Z,1679499214.366 [DVL_micro](ERROR): Communications Fault
2023-03-22T15:33:34.416Z,1679499214.416 [CBIT](ERROR): Communications Fault in component: DVL_micro
2023-03-22T15:33:34.416Z,1679499214.416 [CBIT](CRITICAL): Communications Fault in component: DVL_micro
2023-03-22T15:33:34.837Z,1679499214.837 [DVL_micro](INFO): Powering down
2023-03-22T15:33:34.869Z,1679499214.869 [CommandExec](FAULT): Scheduling is paused
2023-03-22T15:33:34.870Z,1679499214.870 [CBIT](INFO): Critical error at 20230322T153334
2023-03-22T15:33:34.870Z,1679499214.870 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2023-03-22T15:33:35.802Z,1679499215.802 [DataOverHttps](INFO): Sending 1068 bytes from file Logs/20230322T001314/Express0005.lzma
2023-03-22T15:33:36.803Z,1679499216.803 [DataOverHttps](INFO): Moved sent file to Logs/20230322T001314/Express0005.lzma.bak
2023-03-22T15:33:36.803Z,1679499216.803 [DataOverHttps](INFO): SBD MOMSN=17540614
2023-03-22T15:33:52.310Z,1679499232.310 [DataOverHttps](INFO): Sending 884 bytes from file Logs/20230322T001314/Express0008.lzma
2023-03-22T15:33:53.311Z,1679499233.311 [DataOverHttps](INFO): Moved sent file to Logs/20230322T001314/Express0008.lzma.bak
2023-03-22T15:33:53.311Z,1679499233.311 [DataOverHttps](INFO): SBD MOMSN=17540660
2023-03-22T15:34:08.835Z,1679499248.835 [DataOverHttps](INFO): Sending 979 bytes from file Logs/20230322T152039/Express0001.lzma
2023-03-22T15:34:09.835Z,1679499249.835 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Express0001.lzma.bak
2023-03-22T15:34:09.835Z,1679499249.835 [DataOverHttps](INFO): SBD MOMSN=17540708
2023-03-22T15:34:25.361Z,1679499265.361 [DataOverHttps](INFO): Sending 203 bytes from file Logs/20230322T152039/Express0005.lzma
2023-03-22T15:34:26.363Z,1679499266.363 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Express0005.lzma.bak
2023-03-22T15:34:26.363Z,1679499266.363 [DataOverHttps](INFO): SBD MOMSN=17540732
2023-03-22T15:34:27.693Z,1679499267.693 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T15:34:27.693Z,1679499267.693 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T15:34:27.693Z,1679499267.693 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T15:35:41.118Z,1679499341.118 [CommandExec](IMPORTANT): got command ! echo 1 > /dev/loadB4
2023-03-22T15:35:42.886Z,1679499342.886 [CommandExec](IMPORTANT): got command gfscan
2023-03-22T15:35:43.255Z,1679499343.255 [CBIT](IMPORTANT): Beginning ground fault scan
2023-03-22T15:35:54.166Z,1679499354.166 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2023-03-22T15:35:54.166Z,1679499354.166 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-03-22T15:35:54.202Z,1679499354.202 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-03-22T15:35:54.206Z,1679499354.206 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.024235
CHAN A1 (24V): 0.017278
CHAN A2 (12V): -0.002539
CHAN A3 (5V): -0.002149
CHAN B0 (3.3V): -0.000766
CHAN B1 (3.15aV): -0.000894
CHAN B2 (3.15bV): -0.001238
CHAN B3 (GND): 0.000077
OPEN: 0.006889
Full Scale: +/- 1 mA
2023-03-22T15:35:54.579Z,1679499354.579 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-03-22T15:35:54.579Z,1679499354.579 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2023-03-22T15:36:34.584Z,1679499394.584 [CBIT](INFO): Clearing failed state for component DVL_micro
2023-03-22T15:36:34.584Z,1679499394.584 [DVL_micro] No Fault, FailCount= 3
2023-03-22T15:36:35.406Z,1679499395.406 [CommandExec](IMPORTANT): got command gfscan
2023-03-22T15:36:35.778Z,1679499395.778 [CBIT](IMPORTANT): Beginning ground fault scan
2023-03-22T15:36:46.681Z,1679499406.681 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.023007
CHAN A1 (24V): 0.017266
CHAN A2 (12V): -0.003013
CHAN A3 (5V): -0.002616
CHAN B0 (3.3V): -0.001201
CHAN B1 (3.15aV): -0.001359
CHAN B2 (3.15bV): -0.000843
CHAN B3 (GND): 0.000215
OPEN: 0.006772
Full Scale: +/- 1 mA
2023-03-22T15:36:49.888Z,1679499409.888 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2023-03-22T15:36:49.888Z,1679499409.888 [DVL_micro] Data Fault, FailCount= 1
2023-03-22T15:36:49.888Z,1679499409.888 [DVL_micro](ERROR): Data Fault
2023-03-22T15:36:49.934Z,1679499409.934 [CBIT](ERROR): Data Fault in component: DVL_micro
2023-03-22T15:36:50.369Z,1679499410.369 [DVL_micro](INFO): Powering down
2023-03-22T15:36:51.122Z,1679499411.122 [CBIT](INFO): Clearing failed state for component DVL_micro
2023-03-22T15:36:51.123Z,1679499411.123 [DVL_micro] No Fault, FailCount= 1
2023-03-22T15:37:09.300Z,1679499429.300 [DVL_micro](INFO): Failure count cleared after critical for DVL_micro
2023-03-22T15:38:55.156Z,1679499535.156 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2023-03-22T15:38:55.156Z,1679499535.156 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-03-22T15:38:55.167Z,1679499535.167 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-03-22T15:38:55.585Z,1679499535.585 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-03-22T15:38:55.585Z,1679499535.585 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2023-03-22T15:39:20.997Z,1679499560.997 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-03-22T15:39:20.998Z,1679499560.998 [DVL_micro](ERROR): Failed to parse:
:TS,000000,35.0,00.0,1489.0,000
2023-03-22T15:39:28.272Z,1679499568.272 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T15:39:28.272Z,1679499568.272 [Default:CheckIn:C.Wait] Stopped
2023-03-22T15:39:28.272Z,1679499568.272 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T15:39:28.272Z,1679499568.272 [Default:CheckIn:D] Running Loop=1
2023-03-22T15:39:28.712Z,1679499568.712 [Default:CheckIn:D] Stopped
2023-03-22T15:39:28.712Z,1679499568.712 [Default:CheckIn:E] Running Loop=1
2023-03-22T15:39:29.103Z,1679499569.103 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 13.051206 min 
2023-03-22T15:39:29.103Z,1679499569.103 [Default:CheckIn:E] Stopped
2023-03-22T15:39:29.103Z,1679499569.103 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T15:39:29.103Z,1679499569.103 [Default:CheckIn] Stopped
2023-03-22T15:39:29.103Z,1679499569.103 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T15:39:29.103Z,1679499569.103 [Default:CheckIn](INFO): Running loop #2
2023-03-22T15:39:29.103Z,1679499569.103 [Default:CheckIn] Running Loop=2
2023-03-22T15:39:29.104Z,1679499569.104 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T15:39:29.104Z,1679499569.104 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T15:41:56.169Z,1679499716.169 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2023-03-22T15:41:56.169Z,1679499716.169 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-03-22T15:41:56.202Z,1679499716.202 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-03-22T15:41:56.575Z,1679499716.575 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-03-22T15:41:56.576Z,1679499716.576 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2023-03-22T15:42:15.139Z,1679499735.139 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-03-22T15:42:15.139Z,1679499735.139 [NAL9602] Data Fault, FailCount= 2
2023-03-22T15:42:15.139Z,1679499735.139 [NAL9602](ERROR): Data Fault
2023-03-22T15:42:15.155Z,1679499735.155 [CBIT](ERROR): Data Fault in component: NAL9602
2023-03-22T15:42:15.544Z,1679499735.544 [NAL9602](INFO): Powering down
2023-03-22T15:42:16.381Z,1679499736.381 [CBIT](INFO): Clearing failed state for component NAL9602
2023-03-22T15:42:16.381Z,1679499736.381 [NAL9602] No Fault, FailCount= 2
2023-03-22T15:42:36.157Z,1679499756.157 [DVL_micro](ERROR): only read 3 of 4 data items
2023-03-22T15:42:36.157Z,1679499756.157 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.999,+9999.99
2023-03-22T15:42:45.840Z,1679499765.840 [NAL9602](INFO): Powering up NAL9602
2023-03-22T15:42:56.751Z,1679499776.751 [NAL9602](INFO): NAL9602 initialized
2023-03-22T15:42:58.518Z,1679499778.518 [CommandExec](IMPORTANT): got command gfscan
2023-03-22T15:42:58.802Z,1679499778.802 [CBIT](IMPORTANT): Beginning ground fault scan
2023-03-22T15:43:09.739Z,1679499789.739 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.002489
CHAN A1 (24V): 0.017071
CHAN A2 (12V): -0.002956
CHAN A3 (5V): -0.002063
CHAN B0 (3.3V): -0.000483
CHAN B1 (3.15aV): -0.000295
CHAN B2 (3.15bV): -0.000596
CHAN B3 (GND): -0.000300
OPEN: 0.007183
Full Scale: +/- 1 mA
2023-03-22T15:43:29.974Z,1679499809.974 [CommandExec](IMPORTANT): got command strobe off
2023-03-22T15:43:29.974Z,1679499809.974 [CommandExec](IMPORTANT): Deactivating strobe
2023-03-22T15:44:29.284Z,1679499869.284 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-03-22T15:39:29.1Z
2023-03-22T15:44:29.284Z,1679499869.284 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T15:44:29.284Z,1679499869.284 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T15:44:30.122Z,1679499870.122 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T15:44:30.122Z,1679499870.122 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T15:44:30.123Z,1679499870.123 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T15:44:57.189Z,1679499897.189 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2023-03-22T15:44:57.189Z,1679499897.189 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-03-22T15:44:57.200Z,1679499897.200 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-03-22T15:44:57.609Z,1679499897.609 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-03-22T15:44:57.609Z,1679499897.609 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2023-03-22T15:46:01.411Z,1679499961.411 [DVL_micro](ERROR): Failed to parse:00000000000,35.0,+18.8,0000.0,1489.0,000
2023-03-22T15:47:58.173Z,1679500078.173 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2023-03-22T15:47:58.173Z,1679500078.173 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-03-22T15:47:58.185Z,1679500078.185 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-03-22T15:47:58.594Z,1679500078.594 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-03-22T15:47:58.595Z,1679500078.595 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2023-03-22T15:49:30.729Z,1679500170.729 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T15:49:30.729Z,1679500170.729 [Default:CheckIn:C.Wait] Stopped
2023-03-22T15:49:30.729Z,1679500170.729 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T15:49:30.729Z,1679500170.729 [Default:CheckIn:D] Running Loop=1
2023-03-22T15:49:31.111Z,1679500171.111 [Default:CheckIn:D] Stopped
2023-03-22T15:49:31.111Z,1679500171.111 [Default:CheckIn:E] Running Loop=1
2023-03-22T15:49:31.535Z,1679500171.535 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 23.091199 min 
2023-03-22T15:49:31.535Z,1679500171.535 [Default:CheckIn:E] Stopped
2023-03-22T15:49:31.535Z,1679500171.535 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T15:49:31.535Z,1679500171.535 [Default:CheckIn] Stopped
2023-03-22T15:49:31.535Z,1679500171.535 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T15:49:31.536Z,1679500171.536 [Default:CheckIn](INFO): Running loop #3
2023-03-22T15:49:31.536Z,1679500171.536 [Default:CheckIn] Running Loop=3
2023-03-22T15:49:31.536Z,1679500171.536 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T15:49:31.536Z,1679500171.536 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T15:50:59.204Z,1679500259.204 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2023-03-22T15:50:59.204Z,1679500259.204 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-03-22T15:50:59.215Z,1679500259.215 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-03-22T15:50:59.630Z,1679500259.630 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-03-22T15:50:59.630Z,1679500259.630 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2023-03-22T15:51:08.954Z,1679500268.954 [CommandExec](IMPORTANT): got command strobe off
2023-03-22T15:51:08.955Z,1679500268.955 [CommandExec](IMPORTANT): Deactivating strobe
2023-03-22T15:51:10.314Z,1679500270.314 [CommandExec](IMPORTANT): got command failComponent
2023-03-22T15:51:10.314Z,1679500270.314 [CommandExec](IMPORTANT): Failed components:
2023-03-22T15:51:10.314Z,1679500270.314 [CommandExec](IMPORTANT): No failed Components.
2023-03-22T15:51:15.934Z,1679500275.934 [CommandExec](IMPORTANT): got command maintain 
2023-03-22T15:51:17.914Z,1679500277.914 [CommandExec](IMPORTANT): got command burn off
2023-03-22T15:51:17.914Z,1679500277.914 [CommandExec](IMPORTANT): Deactivating dropweight wire
2023-03-22T15:52:57.971Z,1679500377.971 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-03-22T15:52:57.972Z,1679500377.972 [NAL9602] Data Fault, FailCount= 3
2023-03-22T15:52:57.972Z,1679500377.972 [NAL9602](ERROR): Data Fault
2023-03-22T15:52:57.988Z,1679500377.988 [CBIT](ERROR): Data Fault in component: NAL9602
2023-03-22T15:52:58.376Z,1679500378.376 [NAL9602](INFO): Powering down
2023-03-22T15:52:59.228Z,1679500379.228 [CBIT](INFO): Clearing failed state for component NAL9602
2023-03-22T15:52:59.228Z,1679500379.228 [NAL9602] No Fault, FailCount= 3
2023-03-22T15:53:28.674Z,1679500408.674 [NAL9602](INFO): Powering up NAL9602
2023-03-22T15:53:39.593Z,1679500419.593 [NAL9602](INFO): NAL9602 initialized
2023-03-22T15:54:00.188Z,1679500440.188 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11
2023-03-22T15:54:00.188Z,1679500440.188 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-03-22T15:54:00.198Z,1679500440.198 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-03-22T15:54:00.616Z,1679500440.616 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-03-22T15:54:00.616Z,1679500440.616 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11
2023-03-22T15:54:31.715Z,1679500471.715 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-03-22T15:49:31.5Z
2023-03-22T15:54:31.715Z,1679500471.715 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T15:54:31.715Z,1679500471.715 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T15:54:41.514Z,1679500481.514 [DataOverHttps](INFO): Sending 114 bytes from file Logs/20230322T152039/Courier0007.lzma
2023-03-22T15:54:42.507Z,1679500482.507 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Courier0007.lzma.bak
2023-03-22T15:54:42.508Z,1679500482.508 [DataOverHttps](INFO): SBD MOMSN=17540776
2023-03-22T15:54:58.304Z,1679500498.304 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230322T152039/Courier0010.lzma
2023-03-22T15:54:59.307Z,1679500499.307 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Courier0010.lzma.bak
2023-03-22T15:54:59.307Z,1679500499.307 [DataOverHttps](INFO): SBD MOMSN=17540779
2023-03-22T15:55:14.998Z,1679500514.998 [DataOverHttps](INFO): Sending 631 bytes from file Logs/20230322T152039/Express0008.lzma
2023-03-22T15:55:15.999Z,1679500515.999 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Express0008.lzma.bak
2023-03-22T15:55:15.999Z,1679500515.999 [DataOverHttps](INFO): SBD MOMSN=17540781
2023-03-22T15:55:19.506Z,1679500519.506 [CommandExec](IMPORTANT): got command burn on
2023-03-22T15:55:19.506Z,1679500519.506 [CommandExec](IMPORTANT): Activating dropweight wire
2023-03-22T15:55:32.849Z,1679500532.849 [DataOverHttps](INFO): Sending 274 bytes from file Logs/20230322T152039/Express0011.lzma
2023-03-22T15:55:33.851Z,1679500533.851 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Express0011.lzma.bak
2023-03-22T15:55:33.851Z,1679500533.851 [DataOverHttps](INFO): SBD MOMSN=17540801
2023-03-22T15:55:35.018Z,1679500535.018 [CommandExec](IMPORTANT): got command burn off
2023-03-22T15:55:35.018Z,1679500535.018 [CommandExec](IMPORTANT): Deactivating dropweight wire
2023-03-22T15:55:35.242Z,1679500535.242 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T15:55:35.243Z,1679500535.243 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T15:55:35.243Z,1679500535.243 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T15:55:44.102Z,1679500544.102 [CommandExec](IMPORTANT): got command burn on
2023-03-22T15:55:44.102Z,1679500544.102 [CommandExec](IMPORTANT): Activating dropweight wire
2023-03-22T15:56:02.302Z,1679500562.302 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155600.00,A,3648.16692,N,12147.27693,W,0.175,0.00,220323,,,A*71
2023-03-22T15:56:02.325Z,1679500562.325 [NAL9602](INFO): GPS fix at 20230322T155600: (36.802782, -121.787949)
2023-03-22T15:56:34.623Z,1679500594.623 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T15:57:30.751Z,1679500650.751 [CommandExec](IMPORTANT): got command burn off
2023-03-22T15:57:30.751Z,1679500650.751 [CommandExec](IMPORTANT): Deactivating dropweight wire
2023-03-22T15:59:20.494Z,1679500760.494 [CommandExec](IMPORTANT): got command get height_above_sea_floor
2023-03-22T15:59:20.494Z,1679500760.494 [CommandExec](FAULT): Element has no value
2023-03-22T15:59:22.677Z,1679500762.677 [CommandExec](IMPORTANT): got command failComponent
2023-03-22T15:59:22.678Z,1679500762.678 [CommandExec](IMPORTANT): Failed components:
2023-03-22T15:59:22.678Z,1679500762.678 [CommandExec](IMPORTANT): No failed Components.
2023-03-22T15:59:26.559Z,1679500766.559 [CommandExec](IMPORTANT): got command burn off
2023-03-22T15:59:26.559Z,1679500766.559 [CommandExec](IMPORTANT): Deactivating dropweight wire
2023-03-22T15:59:31.893Z,1679500771.893 [CommandExec](IMPORTANT): got command get height_above_sea_floor
2023-03-22T15:59:31.894Z,1679500771.894 [CommandExec](FAULT): Element has no value
2023-03-22T15:59:34.714Z,1679500774.714 [CommandExec](IMPORTANT): got command gfscan
2023-03-22T15:59:34.879Z,1679500774.879 [CBIT](IMPORTANT): Beginning ground fault scan
2023-03-22T15:59:45.764Z,1679500785.764 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.002372
CHAN A1 (24V): 0.014847
CHAN A2 (12V): -0.003889
CHAN A3 (5V): -0.003540
CHAN B0 (3.3V): -0.001672
CHAN B1 (3.15aV): -0.000304
CHAN B2 (3.15bV): -0.001279
CHAN B3 (GND): -0.000868
OPEN: 0.012369
Full Scale: +/- 1 mA
2023-03-22T15:59:56.851Z,1679500796.851 [CommandExec](IMPORTANT): got command get height_above_sea_floor
2023-03-22T15:59:56.852Z,1679500796.852 [CommandExec](IMPORTANT): height_above_sea_floor 1.200000 m
2023-03-22T16:00:35.888Z,1679500835.888 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T16:00:35.888Z,1679500835.888 [Default:CheckIn:C.Wait] Stopped
2023-03-22T16:00:35.888Z,1679500835.888 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T16:00:35.888Z,1679500835.888 [Default:CheckIn:D] Running Loop=1
2023-03-22T16:00:36.260Z,1679500836.260 [Default:CheckIn:D] Stopped
2023-03-22T16:00:36.260Z,1679500836.260 [Default:CheckIn:E] Running Loop=1
2023-03-22T16:00:36.686Z,1679500836.686 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 34.177018 min 
2023-03-22T16:00:36.686Z,1679500836.686 [Default:CheckIn:E] Stopped
2023-03-22T16:00:36.686Z,1679500836.686 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T16:00:36.686Z,1679500836.686 [Default:CheckIn] Stopped
2023-03-22T16:00:36.686Z,1679500836.686 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T16:00:36.686Z,1679500836.686 [Default:CheckIn](INFO): Running loop #4
2023-03-22T16:00:36.686Z,1679500836.686 [Default:CheckIn] Running Loop=4
2023-03-22T16:00:36.686Z,1679500836.686 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T16:00:36.687Z,1679500836.687 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T16:00:38.688Z,1679500838.688 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160036.00,A,3648.16323,N,12147.27197,W,0.447,0.00,220323,,,A*7C
2023-03-22T16:00:38.690Z,1679500838.690 [NAL9602](INFO): GPS fix at 20230322T160036: (36.802720, -121.787866)
2023-03-22T16:00:38.700Z,1679500838.700 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T16:00:38.700Z,1679500838.700 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T16:00:46.025Z,1679500846.025 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20230322T152039/Courier0013.lzma
2023-03-22T16:00:47.028Z,1679500847.028 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Courier0013.lzma.bak
2023-03-22T16:00:47.028Z,1679500847.028 [DataOverHttps](INFO): SBD MOMSN=17540829
2023-03-22T16:01:03.161Z,1679500863.161 [DataOverHttps](INFO): Sending 683 bytes from file Logs/20230322T152039/Express0014.lzma
2023-03-22T16:01:04.163Z,1679500864.163 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Express0014.lzma.bak
2023-03-22T16:01:04.163Z,1679500864.163 [DataOverHttps](INFO): SBD MOMSN=17540832
2023-03-22T16:01:05.561Z,1679500865.561 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T16:01:05.561Z,1679500865.561 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T16:01:05.561Z,1679500865.561 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T16:01:47.162Z,1679500907.162 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-03-22T16:01:47.162Z,1679500907.162 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+18.5,009.0,000
2023-03-22T16:03:17.256Z,1679500997.256 [DVL_micro](ERROR): Failed to parse:498,+00831,+00583,+00000,A
2023-03-22T16:03:39.463Z,1679501019.463 [NAL9602](INFO): SBD MO Status=2, MOMSN=47454, MT Status=2, MTMSN=0
2023-03-22T16:03:39.463Z,1679501019.463 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-03-22T16:04:00.926Z,1679501040.926 [NAL9602](INFO): SBD MO Status=2, MOMSN=47454, MT Status=2, MTMSN=0
2023-03-22T16:04:00.927Z,1679501040.927 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-03-22T16:05:40.727Z,1679501140.727 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-03-22T16:06:06.196Z,1679501166.196 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T16:06:06.196Z,1679501166.196 [Default:CheckIn:C.Wait] Stopped
2023-03-22T16:06:06.196Z,1679501166.196 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T16:06:06.197Z,1679501166.197 [Default:CheckIn:D] Running Loop=1
2023-03-22T16:06:06.581Z,1679501166.581 [Default:CheckIn:D] Stopped
2023-03-22T16:06:06.581Z,1679501166.581 [Default:CheckIn:E] Running Loop=1
2023-03-22T16:06:06.980Z,1679501166.980 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.682361 min 
2023-03-22T16:06:06.980Z,1679501166.980 [Default:CheckIn:E] Stopped
2023-03-22T16:06:06.980Z,1679501166.980 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T16:06:06.981Z,1679501166.981 [Default:CheckIn] Stopped
2023-03-22T16:06:06.981Z,1679501166.981 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T16:06:06.981Z,1679501166.981 [Default:CheckIn](INFO): Running loop #5
2023-03-22T16:06:06.981Z,1679501166.981 [Default:CheckIn] Running Loop=5
2023-03-22T16:06:06.981Z,1679501166.981 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T16:06:06.981Z,1679501166.981 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T16:06:08.999Z,1679501168.999 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160609.00,A,3648.16667,N,12147.27908,W,0.350,111.03,220323,,,A*7E
2023-03-22T16:06:09.002Z,1679501169.002 [NAL9602](INFO): GPS fix at 20230322T160609: (36.802778, -121.787985)
2023-03-22T16:06:09.011Z,1679501169.011 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T16:06:09.011Z,1679501169.011 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T16:06:16.764Z,1679501176.764 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230322T152039/Courier0016.lzma
2023-03-22T16:06:17.767Z,1679501177.767 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Courier0016.lzma.bak
2023-03-22T16:06:17.767Z,1679501177.767 [DataOverHttps](INFO): SBD MOMSN=17540857
2023-03-22T16:06:36.069Z,1679501196.069 [DataOverHttps](INFO): Sending 248 bytes from file Logs/20230322T152039/Express0017.lzma
2023-03-22T16:06:37.071Z,1679501197.071 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Express0017.lzma.bak
2023-03-22T16:06:37.071Z,1679501197.071 [DataOverHttps](INFO): SBD MOMSN=17540860
2023-03-22T16:06:38.162Z,1679501198.162 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T16:06:38.162Z,1679501198.162 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T16:06:38.162Z,1679501198.162 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T16:06:41.764Z,1679501201.764 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T16:07:52.474Z,1679501272.474 [DVL_micro](ERROR): only read 3 of 4 data items
2023-03-22T16:07:52.475Z,1679501272.475 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.99,+9999.999
2023-03-22T16:11:32.644Z,1679501492.644 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-03-22T16:11:32.645Z,1679501492.645 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+18.4,489.0,000
2023-03-22T16:11:38.725Z,1679501498.725 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T16:11:38.725Z,1679501498.725 [Default:CheckIn:C.Wait] Stopped
2023-03-22T16:11:38.725Z,1679501498.725 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T16:11:38.725Z,1679501498.725 [Default:CheckIn:D] Running Loop=1
2023-03-22T16:11:39.142Z,1679501499.142 [Default:CheckIn:D] Stopped
2023-03-22T16:11:39.142Z,1679501499.142 [Default:CheckIn:E] Running Loop=1
2023-03-22T16:11:39.522Z,1679501499.522 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.225041 min 
2023-03-22T16:11:39.522Z,1679501499.522 [Default:CheckIn:E] Stopped
2023-03-22T16:11:39.522Z,1679501499.522 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T16:11:39.522Z,1679501499.522 [Default:CheckIn] Stopped
2023-03-22T16:11:39.522Z,1679501499.522 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T16:11:39.523Z,1679501499.523 [Default:CheckIn](INFO): Running loop #6
2023-03-22T16:11:39.523Z,1679501499.523 [Default:CheckIn] Running Loop=6
2023-03-22T16:11:39.523Z,1679501499.523 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T16:11:39.523Z,1679501499.523 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T16:11:41.544Z,1679501501.544 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161142.00,A,3648.17483,N,12147.27691,W,0.039,171.74,220323,,,A*7B
2023-03-22T16:11:41.546Z,1679501501.546 [NAL9602](INFO): GPS fix at 20230322T161142: (36.802914, -121.787948)
2023-03-22T16:11:41.555Z,1679501501.555 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T16:11:41.556Z,1679501501.556 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T16:11:49.576Z,1679501509.576 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230322T152039/Courier0019.lzma
2023-03-22T16:11:50.579Z,1679501510.579 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Courier0019.lzma.bak
2023-03-22T16:11:50.579Z,1679501510.579 [DataOverHttps](INFO): SBD MOMSN=17540877
2023-03-22T16:12:06.585Z,1679501526.585 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230322T152039/Express0020.lzma
2023-03-22T16:12:07.587Z,1679501527.587 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Express0020.lzma.bak
2023-03-22T16:12:07.587Z,1679501527.587 [DataOverHttps](INFO): SBD MOMSN=17540880
2023-03-22T16:12:08.628Z,1679501528.628 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T16:12:08.628Z,1679501528.628 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T16:12:08.628Z,1679501528.628 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T16:12:12.235Z,1679501532.235 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-03-22T16:12:12.313Z,1679501532.313 [NAL9602](ERROR): received: 
+CSQ:0

OK454, 2, 0, 0, 0

OK
2023-03-22T16:12:23.159Z,1679501543.159 [NAL9602](INFO): SBD MO Status=0, MOMSN=47454, MT Status=0, MTMSN=0
2023-03-22T16:12:23.159Z,1679501543.159 [NAL9602](INFO): No messages in MT queue
2023-03-22T16:12:53.853Z,1679501573.853 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T16:17:09.216Z,1679501829.216 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T16:17:09.216Z,1679501829.216 [Default:CheckIn:C.Wait] Stopped
2023-03-22T16:17:09.216Z,1679501829.216 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T16:17:09.216Z,1679501829.216 [Default:CheckIn:D] Running Loop=1
2023-03-22T16:17:09.603Z,1679501829.603 [Default:CheckIn:D] Stopped
2023-03-22T16:17:09.603Z,1679501829.603 [Default:CheckIn:E] Running Loop=1
2023-03-22T16:17:10.006Z,1679501830.006 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 50.732727 min 
2023-03-22T16:17:10.006Z,1679501830.006 [Default:CheckIn:E] Stopped
2023-03-22T16:17:10.006Z,1679501830.006 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T16:17:10.006Z,1679501830.006 [Default:CheckIn] Stopped
2023-03-22T16:17:10.006Z,1679501830.006 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T16:17:10.006Z,1679501830.006 [Default:CheckIn](INFO): Running loop #7
2023-03-22T16:17:10.006Z,1679501830.006 [Default:CheckIn] Running Loop=7
2023-03-22T16:17:10.006Z,1679501830.006 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T16:17:10.006Z,1679501830.006 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T16:17:12.021Z,1679501832.021 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161712.00,A,3648.17329,N,12147.27897,W,0.039,171.74,220323,,,A*77
2023-03-22T16:17:12.033Z,1679501832.033 [NAL9602](INFO): GPS fix at 20230322T161712: (36.802888, -121.787983)
2023-03-22T16:17:12.043Z,1679501832.043 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T16:17:12.043Z,1679501832.043 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T16:17:19.316Z,1679501839.316 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230322T152039/Courier0022.lzma
2023-03-22T16:17:20.319Z,1679501840.319 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Courier0022.lzma.bak
2023-03-22T16:17:20.319Z,1679501840.319 [DataOverHttps](INFO): SBD MOMSN=17540884
2023-03-22T16:17:39.265Z,1679501859.265 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230322T152039/Express0023.lzma
2023-03-22T16:17:40.267Z,1679501860.267 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Express0023.lzma.bak
2023-03-22T16:17:40.267Z,1679501860.267 [DataOverHttps](IMPORTANT): SBD MOMSN=17540888, MTMSN=20230322T161740
2023-03-22T16:17:41.606Z,1679501861.606 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T16:17:41.606Z,1679501861.606 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T16:17:41.606Z,1679501861.606 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T16:17:47.770Z,1679501867.770 [DataOverHttps](INFO): Received command: ibit
2023-03-22T16:17:47.874Z,1679501867.874 [CommandExec](IMPORTANT): got command ibit
2023-03-22T16:17:48.050Z,1679501868.050 [IBIT](IMPORTANT): Beginning Initiated BIT
2023-03-22T16:17:48.050Z,1679501868.050 [IBIT](IMPORTANT): Beginning control surface checks.
2023-03-22T16:17:48.056Z,1679501868.056 [CBIT](IMPORTANT): Beginning ground fault scan
2023-03-22T16:17:58.960Z,1679501878.960 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.032084
CHAN A1 (24V): 0.043006
CHAN A2 (12V): -0.016743
CHAN A3 (5V): -0.023022
CHAN B0 (3.3V): -0.012906
CHAN B1 (3.15aV): -0.008591
CHAN B2 (3.15bV): -0.005316
CHAN B3 (GND): -0.016629
OPEN: 0.009007
Full Scale: +/- 1 mA
2023-03-22T16:18:42.960Z,1679501922.960 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-03-22T16:18:42.961Z,1679501922.961 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+17.9,0000.0,1489:WI,+00963-01512,+00000,A
2023-03-22T16:19:39.140Z,1679501979.140 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired.
2023-03-22T16:19:39.557Z,1679501979.557 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 15.858000
2023-03-22T16:19:39.558Z,1679501979.558 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2023-03-22T16:19:39.558Z,1679501979.558 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2023-03-22T16:19:39.936Z,1679501979.936 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2023-03-22T16:19:39.936Z,1679501979.936 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2023-03-22T16:19:39.937Z,1679501979.937 [IBIT](IMPORTANT): Pressure:9.858553 PSI
2023-03-22T16:19:39.937Z,1679501979.937 [IBIT](IMPORTANT): Humidity:8.704676 %
2023-03-22T16:19:40.347Z,1679501980.347 [IBIT](IMPORTANT): Vehicle Pitch:-0.990538 degrees
2023-03-22T16:19:40.347Z,1679501980.347 [IBIT](IMPORTANT): Vehicle  Roll:-3.562969 degrees
2023-03-22T16:19:40.347Z,1679501980.347 [IBIT](IMPORTANT): Vehicle  Heading:343.879730 degrees
2023-03-22T16:19:40.767Z,1679501980.767 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2023-03-22T16:19:40.768Z,1679501980.768 [IBIT](IMPORTANT): buoyancyNeutral: 223.000000 cc
2023-03-22T16:19:40.768Z,1679501980.768 [IBIT](IMPORTANT): massDefault: 3.500000 cm
2023-03-22T16:19:40.768Z,1679501980.768 [IBIT](IMPORTANT): stopDepth: 215.000000 m
2023-03-22T16:19:40.768Z,1679501980.768 [IBIT](IMPORTANT): abortDepth: 250.000000 m
2023-03-22T16:19:40.769Z,1679501980.769 [IBIT](IMPORTANT): IBIT FAILED
2023-03-22T16:20:27.197Z,1679502027.197 [NAL9602](INFO): SBD MO Status=0, MOMSN=47455, MT Status=0, MTMSN=0
2023-03-22T16:20:27.198Z,1679502027.198 [NAL9602](INFO): No messages in MT queue
2023-03-22T16:20:57.893Z,1679502057.893 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T16:22:13.061Z,1679502133.061 [DVL_micro](ERROR): only read 0 of 4 data items
2023-03-22T16:22:13.061Z,1679502133.061 [DVL_micro](ERROR): Failed to parse:
:RD,,+9999.99,+9999.99,+9999.99
2023-03-22T16:22:42.147Z,1679502162.147 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T16:22:42.147Z,1679502162.147 [Default:CheckIn:C.Wait] Stopped
2023-03-22T16:22:42.147Z,1679502162.147 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T16:22:42.147Z,1679502162.147 [Default:CheckIn:D] Running Loop=1
2023-03-22T16:22:42.547Z,1679502162.547 [Default:CheckIn:D] Stopped
2023-03-22T16:22:42.547Z,1679502162.547 [Default:CheckIn:E] Running Loop=1
2023-03-22T16:22:42.956Z,1679502162.956 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 56.281799 min 
2023-03-22T16:22:42.956Z,1679502162.956 [Default:CheckIn:E] Stopped
2023-03-22T16:22:42.956Z,1679502162.956 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T16:22:42.956Z,1679502162.956 [Default:CheckIn] Stopped
2023-03-22T16:22:42.957Z,1679502162.957 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T16:22:42.957Z,1679502162.957 [Default:CheckIn](INFO): Running loop #8
2023-03-22T16:22:42.957Z,1679502162.957 [Default:CheckIn] Running Loop=8
2023-03-22T16:22:42.957Z,1679502162.957 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T16:22:42.957Z,1679502162.957 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T16:22:44.959Z,1679502164.959 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162245.00,A,3648.17846,N,12147.27902,W,0.078,171.74,220323,,,A*79
2023-03-22T16:22:44.971Z,1679502164.971 [NAL9602](INFO): GPS fix at 20230322T162245: (36.802974, -121.787984)
2023-03-22T16:22:44.981Z,1679502164.981 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T16:22:44.981Z,1679502164.981 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T16:22:52.748Z,1679502172.748 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230322T152039/Courier0025.lzma
2023-03-22T16:22:53.751Z,1679502173.751 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Courier0025.lzma.bak
2023-03-22T16:22:53.751Z,1679502173.751 [DataOverHttps](INFO): SBD MOMSN=17540911
2023-03-22T16:23:09.646Z,1679502189.646 [DataOverHttps](INFO): Sending 801 bytes from file Logs/20230322T152039/Express0026.lzma
2023-03-22T16:23:10.647Z,1679502190.647 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Express0026.lzma.bak
2023-03-22T16:23:10.647Z,1679502190.647 [DataOverHttps](INFO): SBD MOMSN=17540914
2023-03-22T16:23:18.907Z,1679502198.907 [NAL9602](INFO): SBD MO Status=2, MOMSN=47456, MT Status=2, MTMSN=0
2023-03-22T16:23:18.907Z,1679502198.907 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-03-22T16:23:26.692Z,1679502206.692 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20230322T152039/Express0029.lzma
2023-03-22T16:23:27.695Z,1679502207.695 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Express0029.lzma.bak
2023-03-22T16:23:27.695Z,1679502207.695 [DataOverHttps](INFO): SBD MOMSN=17540940
2023-03-22T16:23:29.020Z,1679502209.020 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T16:23:29.020Z,1679502209.020 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T16:23:29.020Z,1679502209.020 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T16:23:54.116Z,1679502234.116 [NAL9602](INFO): SBD MO Status=0, MOMSN=47456, MT Status=0, MTMSN=0
2023-03-22T16:23:54.116Z,1679502234.116 [NAL9602](INFO): No messages in MT queue
2023-03-22T16:24:24.828Z,1679502264.828 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T16:25:48.163Z,1679502348.163 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-03-22T16:25:48.163Z,1679502348.163 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+17.3,0000.0,1489.0,,+01249,+01163,-01515,+00000,A
2023-03-22T16:28:29.467Z,1679502509.467 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T16:28:29.467Z,1679502509.467 [Default:CheckIn:C.Wait] Stopped
2023-03-22T16:28:29.468Z,1679502509.468 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T16:28:29.468Z,1679502509.468 [Default:CheckIn:D] Running Loop=1
2023-03-22T16:28:29.892Z,1679502509.892 [Default:CheckIn:D] Stopped
2023-03-22T16:28:29.892Z,1679502509.892 [Default:CheckIn:E] Running Loop=1
2023-03-22T16:28:30.311Z,1679502510.311 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 62.070886 min 
2023-03-22T16:28:30.311Z,1679502510.311 [Default:CheckIn:E] Stopped
2023-03-22T16:28:30.312Z,1679502510.312 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T16:28:30.312Z,1679502510.312 [Default:CheckIn] Stopped
2023-03-22T16:28:30.312Z,1679502510.312 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T16:28:30.312Z,1679502510.312 [Default:CheckIn](INFO): Running loop #9
2023-03-22T16:28:30.312Z,1679502510.312 [Default:CheckIn] Running Loop=9
2023-03-22T16:28:30.312Z,1679502510.312 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T16:28:30.312Z,1679502510.312 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T16:28:32.292Z,1679502512.292 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162833.00,A,3648.18125,N,12147.27527,W,0.272,171.74,220323,,,A*72
2023-03-22T16:28:32.294Z,1679502512.294 [NAL9602](INFO): GPS fix at 20230322T162833: (36.803021, -121.787921)
2023-03-22T16:28:32.303Z,1679502512.303 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T16:28:32.304Z,1679502512.304 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T16:28:42.960Z,1679502522.960 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230322T152039/Courier0031.lzma
2023-03-22T16:28:43.963Z,1679502523.963 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Courier0031.lzma.bak
2023-03-22T16:28:43.963Z,1679502523.963 [DataOverHttps](INFO): SBD MOMSN=17540943
2023-03-22T16:28:58.181Z,1679502538.181 [DVL_micro](ERROR): only read 3 of 4 data items
2023-03-22T16:28:58.181Z,1679502538.181 [DVL_micro](ERROR): Failed to parse:
:BI,-00956,+0090,+00000,I
2023-03-22T16:29:00.100Z,1679502540.100 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230322T152039/Express0032.lzma
2023-03-22T16:29:01.103Z,1679502541.103 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Express0032.lzma.bak
2023-03-22T16:29:01.103Z,1679502541.103 [DataOverHttps](INFO): SBD MOMSN=17540946
2023-03-22T16:29:02.232Z,1679502542.232 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T16:29:02.232Z,1679502542.232 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T16:29:02.232Z,1679502542.232 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T16:29:13.531Z,1679502553.531 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-03-22T16:29:13.532Z,1679502553.532 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+17.0,0000.0000
2023-03-22T16:29:43.046Z,1679502583.046 [DataOverHttps](IMPORTANT): SBD MTMSN=20230322T162943
2023-03-22T16:29:50.649Z,1679502590.649 [DataOverHttps](INFO): Received command: ibit
2023-03-22T16:29:50.710Z,1679502590.710 [CommandExec](IMPORTANT): got command ibit
2023-03-22T16:29:50.812Z,1679502590.812 [IBIT](IMPORTANT): Beginning Initiated BIT
2023-03-22T16:29:50.812Z,1679502590.812 [IBIT](IMPORTANT): Beginning control surface checks.
2023-03-22T16:29:50.815Z,1679502590.815 [CBIT](IMPORTANT): Beginning ground fault scan
2023-03-22T16:30:01.714Z,1679502601.714 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.070529
CHAN A1 (24V): 0.106987
CHAN A2 (12V): 0.010816
CHAN A3 (5V): -0.018930
CHAN B0 (3.3V): -0.010642
CHAN B1 (3.15aV): -0.006035
CHAN B2 (3.15bV): -0.001578
CHAN B3 (GND): -0.020796
OPEN: 0.009681
Full Scale: +/- 1 mA
2023-03-22T16:31:16.063Z,1679502676.063 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 1
Latitude: 36.803020 Longitude: -121.787918
2023-03-22T16:31:16.455Z,1679502676.455 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 283.036987
Voltage: 15.858000
2023-03-22T16:31:16.456Z,1679502676.456 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2023-03-22T16:31:16.456Z,1679502676.456 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2023-03-22T16:31:16.861Z,1679502676.861 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2023-03-22T16:31:16.862Z,1679502676.862 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2023-03-22T16:31:16.862Z,1679502676.862 [IBIT](IMPORTANT): Pressure:9.856807 PSI
2023-03-22T16:31:16.862Z,1679502676.862 [IBIT](IMPORTANT): Humidity:8.753510 %
2023-03-22T16:31:17.250Z,1679502677.250 [IBIT](IMPORTANT): Vehicle Pitch:-0.979827 degrees
2023-03-22T16:31:17.251Z,1679502677.251 [IBIT](IMPORTANT): Vehicle  Roll:-3.580043 degrees
2023-03-22T16:31:17.251Z,1679502677.251 [IBIT](IMPORTANT): Vehicle  Heading:343.768280 degrees
2023-03-22T16:31:17.664Z,1679502677.664 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2023-03-22T16:31:17.665Z,1679502677.665 [IBIT](IMPORTANT): buoyancyNeutral: 223.000000 cc
2023-03-22T16:31:17.665Z,1679502677.665 [IBIT](IMPORTANT): massDefault: 3.500000 cm
2023-03-22T16:31:17.666Z,1679502677.666 [IBIT](IMPORTANT): stopDepth: 215.000000 m
2023-03-22T16:31:17.666Z,1679502677.666 [IBIT](IMPORTANT): abortDepth: 250.000000 m
2023-03-22T16:31:17.666Z,1679502677.666 [IBIT](IMPORTANT): IBIT PASSED
2023-03-22T16:31:40.676Z,1679502700.676 [NAL9602](INFO): SBD MO Status=0, MOMSN=47457, MT Status=0, MTMSN=0
2023-03-22T16:31:40.676Z,1679502700.676 [NAL9602](INFO): No messages in MT queue
2023-03-22T16:32:11.379Z,1679502731.379 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T16:34:02.891Z,1679502842.891 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T16:34:02.891Z,1679502842.891 [Default:CheckIn:C.Wait] Stopped
2023-03-22T16:34:02.891Z,1679502842.891 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T16:34:02.891Z,1679502842.891 [Default:CheckIn:D] Running Loop=1
2023-03-22T16:34:03.296Z,1679502843.296 [Default:CheckIn:D] Stopped
2023-03-22T16:34:03.296Z,1679502843.296 [Default:CheckIn:E] Running Loop=1
2023-03-22T16:34:03.709Z,1679502843.709 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 67.627620 min 
2023-03-22T16:34:03.710Z,1679502843.710 [Default:CheckIn:E] Stopped
2023-03-22T16:34:03.710Z,1679502843.710 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T16:34:03.710Z,1679502843.710 [Default:CheckIn] Stopped
2023-03-22T16:34:03.710Z,1679502843.710 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T16:34:03.710Z,1679502843.710 [Default:CheckIn](INFO): Running loop #10
2023-03-22T16:34:03.710Z,1679502843.710 [Default:CheckIn] Running Loop=10
2023-03-22T16:34:03.710Z,1679502843.710 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T16:34:03.710Z,1679502843.710 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T16:34:05.740Z,1679502845.740 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163406.00,A,3648.17752,N,12147.27453,W,0.136,160.44,220323,,,A*72
2023-03-22T16:34:05.743Z,1679502845.743 [NAL9602](INFO): GPS fix at 20230322T163406: (36.802959, -121.787909)
2023-03-22T16:34:05.757Z,1679502845.757 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T16:34:05.757Z,1679502845.757 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T16:34:13.780Z,1679502853.780 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230322T152039/Courier0034.lzma
2023-03-22T16:34:14.783Z,1679502854.783 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Courier0034.lzma.bak
2023-03-22T16:34:14.783Z,1679502854.783 [DataOverHttps](INFO): SBD MOMSN=17540968
2023-03-22T16:34:30.998Z,1679502870.998 [DataOverHttps](INFO): Sending 774 bytes from file Logs/20230322T152039/Express0035.lzma
2023-03-22T16:34:32.007Z,1679502872.007 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Express0035.lzma.bak
2023-03-22T16:34:32.007Z,1679502872.007 [DataOverHttps](INFO): SBD MOMSN=17540971
2023-03-22T16:34:51.398Z,1679502891.398 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20230322T152039/Express0038.lzma
2023-03-22T16:34:52.399Z,1679502892.399 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Express0038.lzma.bak
2023-03-22T16:34:52.399Z,1679502892.399 [DataOverHttps](INFO): SBD MOMSN=17540997
2023-03-22T16:34:53.463Z,1679502893.463 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T16:34:53.463Z,1679502893.463 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T16:34:53.464Z,1679502893.464 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T16:35:58.911Z,1679502958.911 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-03-22T16:35:58.912Z,1679502958.912 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+16.6,0000.0,1489.0I,+00116,-00021,-01469,+00000,A
2023-03-22T16:39:07.627Z,1679503147.627 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-03-22T16:39:16.504Z,1679503156.504 [DVL_micro](ERROR): Failed to parse:
:.99,+9999..99,+9999.99
2023-03-22T16:39:38.390Z,1679503178.390 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T16:39:54.164Z,1679503194.164 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T16:39:54.164Z,1679503194.164 [Default:CheckIn:C.Wait] Stopped
2023-03-22T16:39:54.164Z,1679503194.164 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T16:39:54.164Z,1679503194.164 [Default:CheckIn:D] Running Loop=1
2023-03-22T16:39:54.587Z,1679503194.587 [Default:CheckIn:D] Stopped
2023-03-22T16:39:54.588Z,1679503194.588 [Default:CheckIn:E] Running Loop=1
2023-03-22T16:39:54.971Z,1679503194.971 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 73.482471 min 
2023-03-22T16:39:54.971Z,1679503194.971 [Default:CheckIn:E] Stopped
2023-03-22T16:39:54.972Z,1679503194.972 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T16:39:54.972Z,1679503194.972 [Default:CheckIn] Stopped
2023-03-22T16:39:54.972Z,1679503194.972 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T16:39:54.972Z,1679503194.972 [Default:CheckIn](INFO): Running loop #11
2023-03-22T16:39:54.972Z,1679503194.972 [Default:CheckIn] Running Loop=11
2023-03-22T16:39:54.972Z,1679503194.972 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T16:39:54.972Z,1679503194.972 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T16:39:56.993Z,1679503196.993 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163957.00,A,3648.17463,N,12147.27589,W,0.039,160.44,220323,,,A*72
2023-03-22T16:39:56.996Z,1679503196.996 [NAL9602](INFO): GPS fix at 20230322T163957: (36.802911, -121.787931)
2023-03-22T16:39:57.005Z,1679503197.005 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T16:39:57.005Z,1679503197.005 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T16:40:04.192Z,1679503204.192 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230322T152039/Courier0040.lzma
2023-03-22T16:40:05.195Z,1679503205.195 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Courier0040.lzma.bak
2023-03-22T16:40:05.195Z,1679503205.195 [DataOverHttps](INFO): SBD MOMSN=17541009
2023-03-22T16:40:20.009Z,1679503220.009 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-03-22T16:40:20.009Z,1679503220.009 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+14.8,089.0,000
2023-03-22T16:40:21.301Z,1679503221.301 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20230322T152039/Express0041.lzma
2023-03-22T16:40:22.303Z,1679503222.303 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Express0041.lzma.bak
2023-03-22T16:40:22.303Z,1679503222.303 [DataOverHttps](INFO): SBD MOMSN=17541012
2023-03-22T16:40:23.655Z,1679503223.655 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T16:40:23.655Z,1679503223.655 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T16:40:23.655Z,1679503223.655 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T16:40:27.699Z,1679503227.699 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-03-22T16:40:27.781Z,1679503227.781 [NAL9602](ERROR): received: 
+CSQ:0

OK457, 0, 0, 0, 0

OK
2023-03-22T16:41:11.333Z,1679503271.333 [NAL9602](INFO): SBD MO Status=0, MOMSN=47458, MT Status=0, MTMSN=0
2023-03-22T16:41:11.333Z,1679503271.333 [NAL9602](INFO): No messages in MT queue
2023-03-22T16:41:42.019Z,1679503302.019 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T16:42:34.194Z,1679503354.194 [DVL_micro](ERROR): Failed to parse:
:WI,-05665,+00651,-01092,+00000,A
2023-03-22T16:45:24.387Z,1679503524.387 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T16:45:24.388Z,1679503524.388 [Default:CheckIn:C.Wait] Stopped
2023-03-22T16:45:24.388Z,1679503524.388 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T16:45:24.388Z,1679503524.388 [Default:CheckIn:D] Running Loop=1
2023-03-22T16:45:24.791Z,1679503524.791 [Default:CheckIn:D] Stopped
2023-03-22T16:45:24.791Z,1679503524.791 [Default:CheckIn:E] Running Loop=1
2023-03-22T16:45:25.197Z,1679503525.197 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 78.985864 min 
2023-03-22T16:45:25.197Z,1679503525.197 [Default:CheckIn:E] Stopped
2023-03-22T16:45:25.197Z,1679503525.197 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T16:45:25.197Z,1679503525.197 [Default:CheckIn] Stopped
2023-03-22T16:45:25.197Z,1679503525.197 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T16:45:25.198Z,1679503525.198 [Default:CheckIn](INFO): Running loop #12
2023-03-22T16:45:25.198Z,1679503525.198 [Default:CheckIn] Running Loop=12
2023-03-22T16:45:25.198Z,1679503525.198 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T16:45:25.198Z,1679503525.198 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T16:45:27.225Z,1679503527.225 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164528.00,A,3648.17957,N,12147.27717,W,0.078,160.44,220323,,,A*7B
2023-03-22T16:45:27.227Z,1679503527.227 [NAL9602](INFO): GPS fix at 20230322T164528: (36.802993, -121.787953)
2023-03-22T16:45:27.236Z,1679503527.236 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T16:45:27.236Z,1679503527.236 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T16:45:28.015Z,1679503528.015 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T16:45:28.015Z,1679503528.015 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T16:45:28.015Z,1679503528.015 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T16:45:51.904Z,1679503551.904 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-03-22T16:45:51.904Z,1679503551.904 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+13.3,0000.0,1489:WI,-10000,+00190,-00987,+00000,A
2023-03-22T16:50:28.509Z,1679503828.509 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T16:50:28.509Z,1679503828.509 [Default:CheckIn:C.Wait] Stopped
2023-03-22T16:50:28.510Z,1679503828.510 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T16:50:28.510Z,1679503828.510 [Default:CheckIn:D] Running Loop=1
2023-03-22T16:50:28.924Z,1679503828.924 [Default:CheckIn:D] Stopped
2023-03-22T16:50:28.924Z,1679503828.924 [Default:CheckIn:E] Running Loop=1
2023-03-22T16:50:29.351Z,1679503829.351 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 84.054744 min 
2023-03-22T16:50:29.353Z,1679503829.353 [Default:CheckIn:E] Stopped
2023-03-22T16:50:29.355Z,1679503829.355 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T16:50:29.355Z,1679503829.355 [Default:CheckIn] Stopped
2023-03-22T16:50:29.355Z,1679503829.355 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T16:50:29.355Z,1679503829.355 [Default:CheckIn](INFO): Running loop #13
2023-03-22T16:50:29.355Z,1679503829.355 [Default:CheckIn] Running Loop=13
2023-03-22T16:50:29.355Z,1679503829.355 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T16:50:29.355Z,1679503829.355 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T16:50:29.699Z,1679503829.699 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-03-22T16:50:33.352Z,1679503833.352 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165034.00,A,3648.18108,N,12147.27691,W,0.019,160.44,220323,,,A*77
2023-03-22T16:50:33.354Z,1679503833.354 [NAL9602](INFO): GPS fix at 20230322T165034: (36.803018, -121.787948)
2023-03-22T16:50:33.396Z,1679503833.396 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T16:50:33.397Z,1679503833.397 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T16:50:43.516Z,1679503843.516 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230322T152039/Courier0043.lzma
2023-03-22T16:50:44.519Z,1679503844.519 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Courier0043.lzma.bak
2023-03-22T16:50:44.519Z,1679503844.519 [DataOverHttps](INFO): SBD MOMSN=17541029
2023-03-22T16:51:00.585Z,1679503860.585 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230322T152039/Courier0046.lzma
2023-03-22T16:51:01.587Z,1679503861.587 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Courier0046.lzma.bak
2023-03-22T16:51:01.587Z,1679503861.587 [DataOverHttps](INFO): SBD MOMSN=17541032
2023-03-22T16:51:05.679Z,1679503865.679 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T16:51:17.944Z,1679503877.944 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230322T152039/Express0044.lzma
2023-03-22T16:51:18.947Z,1679503878.947 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Express0044.lzma.bak
2023-03-22T16:51:18.947Z,1679503878.947 [DataOverHttps](INFO): SBD MOMSN=17541035
2023-03-22T16:51:38.193Z,1679503898.193 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20230322T152039/Express0047.lzma
2023-03-22T16:51:39.195Z,1679503899.195 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Express0047.lzma.bak
2023-03-22T16:51:39.195Z,1679503899.195 [DataOverHttps](INFO): SBD MOMSN=17541046
2023-03-22T16:51:40.545Z,1679503900.545 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T16:51:40.545Z,1679503900.545 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T16:51:40.545Z,1679503900.545 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T16:55:32.417Z,1679504132.417 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-03-22T16:55:32.417Z,1679504132.417 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+13.0,0000.0,10
2023-03-22T16:56:41.106Z,1679504201.106 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T16:56:41.106Z,1679504201.106 [Default:CheckIn:C.Wait] Stopped
2023-03-22T16:56:41.106Z,1679504201.106 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T16:56:41.106Z,1679504201.106 [Default:CheckIn:D] Running Loop=1
2023-03-22T16:56:41.552Z,1679504201.552 [Default:CheckIn:D] Stopped
2023-03-22T16:56:41.553Z,1679504201.553 [Default:CheckIn:E] Running Loop=1
2023-03-22T16:56:41.910Z,1679504201.910 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 90.265218 min 
2023-03-22T16:56:41.910Z,1679504201.910 [Default:CheckIn:E] Stopped
2023-03-22T16:56:41.910Z,1679504201.910 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T16:56:41.910Z,1679504201.910 [Default:CheckIn] Stopped
2023-03-22T16:56:41.910Z,1679504201.910 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T16:56:41.910Z,1679504201.910 [Default:CheckIn](INFO): Running loop #14
2023-03-22T16:56:41.910Z,1679504201.910 [Default:CheckIn] Running Loop=14
2023-03-22T16:56:41.910Z,1679504201.910 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T16:56:41.910Z,1679504201.910 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T16:56:43.919Z,1679504203.919 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165644.00,A,3648.17899,N,12147.27484,W,0.019,160.44,220323,,,A*7E
2023-03-22T16:56:43.921Z,1679504203.921 [NAL9602](INFO): GPS fix at 20230322T165644: (36.802983, -121.787914)
2023-03-22T16:56:43.931Z,1679504203.931 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T16:56:43.931Z,1679504203.931 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T16:56:51.756Z,1679504211.756 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230322T152039/Courier0049.lzma
2023-03-22T16:56:52.759Z,1679504212.759 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Courier0049.lzma.bak
2023-03-22T16:56:52.759Z,1679504212.759 [DataOverHttps](INFO): SBD MOMSN=17541076
2023-03-22T16:57:08.925Z,1679504228.925 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230322T152039/Express0050.lzma
2023-03-22T16:57:09.927Z,1679504229.927 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Express0050.lzma.bak
2023-03-22T16:57:09.927Z,1679504229.927 [DataOverHttps](INFO): SBD MOMSN=17541079
2023-03-22T16:57:11.007Z,1679504231.007 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T16:57:11.008Z,1679504231.008 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T16:57:11.008Z,1679504231.008 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T16:57:14.615Z,1679504234.615 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-03-22T16:57:14.698Z,1679504234.698 [NAL9602](ERROR): received: 
+CSQ:0

OK458, 0, 0, 0, 0

OK
2023-03-22T16:59:01.272Z,1679504341.272 [NAL9602](INFO): SBD MO Status=2, MOMSN=47459, MT Status=2, MTMSN=0
2023-03-22T16:59:01.273Z,1679504341.273 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-03-22T16:59:19.472Z,1679504359.472 [NAL9602](INFO): SBD MO Status=0, MOMSN=47459, MT Status=0, MTMSN=0
2023-03-22T16:59:19.473Z,1679504359.473 [NAL9602](INFO): No messages in MT queue
2023-03-22T16:59:50.176Z,1679504390.176 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T16:59:57.831Z,1679504397.831 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2023-03-22T16:59:57.835Z,1679504397.835 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle.
2023-03-22T17:02:11.571Z,1679504531.571 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T17:02:11.571Z,1679504531.571 [Default:CheckIn:C.Wait] Stopped
2023-03-22T17:02:11.571Z,1679504531.571 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T17:02:11.572Z,1679504531.572 [Default:CheckIn:D] Running Loop=1
2023-03-22T17:02:11.980Z,1679504531.980 [Default:CheckIn:D] Stopped
2023-03-22T17:02:11.980Z,1679504531.980 [Default:CheckIn:E] Running Loop=1
2023-03-22T17:02:12.388Z,1679504532.388 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 95.772339 min 
2023-03-22T17:02:12.388Z,1679504532.388 [Default:CheckIn:E] Stopped
2023-03-22T17:02:12.388Z,1679504532.388 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T17:02:12.388Z,1679504532.388 [Default:CheckIn] Stopped
2023-03-22T17:02:12.388Z,1679504532.388 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T17:02:12.388Z,1679504532.388 [Default:CheckIn](INFO): Running loop #15
2023-03-22T17:02:12.388Z,1679504532.388 [Default:CheckIn] Running Loop=15
2023-03-22T17:02:12.388Z,1679504532.388 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T17:02:12.388Z,1679504532.388 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T17:02:14.388Z,1679504534.388 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170215.00,A,3648.17554,N,12147.27680,W,0.058,160.44,220323,,,A*75
2023-03-22T17:02:14.390Z,1679504534.390 [NAL9602](INFO): GPS fix at 20230322T170215: (36.802926, -121.787947)
2023-03-22T17:02:14.400Z,1679504534.400 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T17:02:14.400Z,1679504534.400 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T17:02:22.157Z,1679504542.157 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20230322T152039/Courier0052.lzma
2023-03-22T17:02:23.164Z,1679504543.164 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Courier0052.lzma.bak
2023-03-22T17:02:23.164Z,1679504543.164 [DataOverHttps](INFO): SBD MOMSN=17541095
2023-03-22T17:02:42.089Z,1679504562.089 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20230322T152039/Express0053.lzma
2023-03-22T17:02:43.091Z,1679504563.091 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Express0053.lzma.bak
2023-03-22T17:02:43.091Z,1679504563.091 [DataOverHttps](INFO): SBD MOMSN=17541123
2023-03-22T17:02:44.390Z,1679504564.390 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T17:02:44.390Z,1679504564.390 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T17:02:44.390Z,1679504564.390 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T17:04:35.102Z,1679504675.102 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.99,+9999.99,+9999.99
2023-03-22T17:07:16.642Z,1679504836.642 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-03-22T17:07:44.936Z,1679504864.936 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T17:07:44.936Z,1679504864.936 [Default:CheckIn:C.Wait] Stopped
2023-03-22T17:07:44.936Z,1679504864.936 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T17:07:44.936Z,1679504864.936 [Default:CheckIn:D] Running Loop=1
2023-03-22T17:07:45.356Z,1679504865.356 [Default:CheckIn:D] Stopped
2023-03-22T17:07:45.356Z,1679504865.356 [Default:CheckIn:E] Running Loop=1
2023-03-22T17:07:45.739Z,1679504865.739 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 101.328613 min 
2023-03-22T17:07:45.739Z,1679504865.739 [Default:CheckIn:E] Stopped
2023-03-22T17:07:45.739Z,1679504865.739 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T17:07:45.739Z,1679504865.739 [Default:CheckIn] Stopped
2023-03-22T17:07:45.739Z,1679504865.739 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T17:07:45.739Z,1679504865.739 [Default:CheckIn](INFO): Running loop #16
2023-03-22T17:07:45.740Z,1679504865.740 [Default:CheckIn] Running Loop=16
2023-03-22T17:07:45.740Z,1679504865.740 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T17:07:45.740Z,1679504865.740 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T17:07:47.756Z,1679504867.756 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170748.00,A,3648.17617,N,12147.27860,W,0.019,0.00,220323,,,A*7E
2023-03-22T17:07:47.758Z,1679504867.758 [NAL9602](INFO): GPS fix at 20230322T170748: (36.802936, -121.787977)
2023-03-22T17:07:47.768Z,1679504867.768 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T17:07:47.768Z,1679504867.768 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T17:07:55.384Z,1679504875.384 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20230322T152039/Courier0055.lzma
2023-03-22T17:07:56.387Z,1679504876.387 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Courier0055.lzma.bak
2023-03-22T17:07:56.387Z,1679504876.387 [DataOverHttps](INFO): SBD MOMSN=17541126
2023-03-22T17:08:12.381Z,1679504892.381 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20230322T152039/Express0056.lzma
2023-03-22T17:08:13.383Z,1679504893.383 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Express0056.lzma.bak
2023-03-22T17:08:13.383Z,1679504893.383 [DataOverHttps](INFO): SBD MOMSN=17541129
2023-03-22T17:08:14.438Z,1679504894.438 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T17:08:14.438Z,1679504894.438 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T17:08:14.438Z,1679504894.438 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T17:08:19.671Z,1679504899.671 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T17:08:43.908Z,1679504923.908 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-03-22T17:08:43.908Z,1679504923.908 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,39,0000.0,1489.0,000
2023-03-22T17:13:15.022Z,1679505195.022 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T17:13:15.022Z,1679505195.022 [Default:CheckIn:C.Wait] Stopped
2023-03-22T17:13:15.022Z,1679505195.022 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T17:13:15.022Z,1679505195.022 [Default:CheckIn:D] Running Loop=1
2023-03-22T17:13:15.406Z,1679505195.406 [Default:CheckIn:D] Stopped
2023-03-22T17:13:15.406Z,1679505195.406 [Default:CheckIn:E] Running Loop=1
2023-03-22T17:13:15.807Z,1679505195.807 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 106.829451 min 
2023-03-22T17:13:15.807Z,1679505195.807 [Default:CheckIn:E] Stopped
2023-03-22T17:13:15.807Z,1679505195.807 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T17:13:15.808Z,1679505195.808 [Default:CheckIn] Stopped
2023-03-22T17:13:15.808Z,1679505195.808 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T17:13:15.808Z,1679505195.808 [Default:CheckIn](INFO): Running loop #17
2023-03-22T17:13:15.808Z,1679505195.808 [Default:CheckIn] Running Loop=17
2023-03-22T17:13:15.808Z,1679505195.808 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T17:13:15.808Z,1679505195.808 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T17:13:17.836Z,1679505197.836 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171318.00,A,3648.17926,N,12147.27988,W,0.039,0.00,220323,,,A*76
2023-03-22T17:13:17.839Z,1679505197.839 [NAL9602](INFO): GPS fix at 20230322T171318: (36.802988, -121.787998)
2023-03-22T17:13:17.848Z,1679505197.848 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T17:13:17.848Z,1679505197.848 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T17:13:25.636Z,1679505205.636 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230322T152039/Courier0058.lzma
2023-03-22T17:13:26.639Z,1679505206.639 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Courier0058.lzma.bak
2023-03-22T17:13:26.639Z,1679505206.639 [DataOverHttps](INFO): SBD MOMSN=17541173
2023-03-22T17:13:46.184Z,1679505226.184 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230322T152039/Express0059.lzma
2023-03-22T17:13:47.187Z,1679505227.187 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Express0059.lzma.bak
2023-03-22T17:13:47.187Z,1679505227.187 [DataOverHttps](INFO): SBD MOMSN=17541176
2023-03-22T17:13:48.218Z,1679505228.218 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T17:13:48.218Z,1679505228.218 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T17:13:48.218Z,1679505228.218 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T17:13:48.566Z,1679505228.566 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-03-22T17:13:48.641Z,1679505228.641 [NAL9602](ERROR): received: 
+CSQ:0

OK459, 0, 0, 0, 0

OK
2023-03-22T17:16:20.489Z,1679505380.489 [NAL9602](INFO): SBD MO Status=0, MOMSN=47460, MT Status=0, MTMSN=0
2023-03-22T17:16:20.489Z,1679505380.489 [NAL9602](INFO): No messages in MT queue
2023-03-22T17:16:51.175Z,1679505411.175 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T17:18:48.762Z,1679505528.762 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T17:18:48.762Z,1679505528.762 [Default:CheckIn:C.Wait] Stopped
2023-03-22T17:18:48.762Z,1679505528.762 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T17:18:48.762Z,1679505528.762 [Default:CheckIn:D] Running Loop=1
2023-03-22T17:18:49.178Z,1679505529.178 [Default:CheckIn:D] Stopped
2023-03-22T17:18:49.178Z,1679505529.178 [Default:CheckIn:E] Running Loop=1
2023-03-22T17:18:49.564Z,1679505529.564 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 112.392318 min 
2023-03-22T17:18:49.564Z,1679505529.564 [Default:CheckIn:E] Stopped
2023-03-22T17:18:49.564Z,1679505529.564 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T17:18:49.564Z,1679505529.564 [Default:CheckIn] Stopped
2023-03-22T17:18:49.565Z,1679505529.565 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T17:18:49.565Z,1679505529.565 [Default:CheckIn](INFO): Running loop #18
2023-03-22T17:18:49.565Z,1679505529.565 [Default:CheckIn] Running Loop=18
2023-03-22T17:18:49.565Z,1679505529.565 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T17:18:49.565Z,1679505529.565 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T17:18:51.581Z,1679505531.581 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171852.00,A,3648.17410,N,12147.27971,W,0.058,40.82,220323,,,A*44
2023-03-22T17:18:51.583Z,1679505531.583 [NAL9602](INFO): GPS fix at 20230322T171852: (36.802902, -121.787995)
2023-03-22T17:18:51.593Z,1679505531.593 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T17:18:51.593Z,1679505531.593 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T17:18:59.564Z,1679505539.564 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230322T152039/Courier0061.lzma
2023-03-22T17:19:00.567Z,1679505540.567 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Courier0061.lzma.bak
2023-03-22T17:19:00.567Z,1679505540.567 [DataOverHttps](INFO): SBD MOMSN=17541182
2023-03-22T17:19:16.600Z,1679505556.600 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230322T152039/Express0062.lzma
2023-03-22T17:19:17.603Z,1679505557.603 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Express0062.lzma.bak
2023-03-22T17:19:17.604Z,1679505557.604 [DataOverHttps](INFO): SBD MOMSN=17541185
2023-03-22T17:19:18.662Z,1679505558.662 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T17:19:18.662Z,1679505558.662 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T17:19:18.662Z,1679505558.662 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T17:21:40.463Z,1679505700.463 [NAL9602](INFO): SBD MO Status=0, MOMSN=47461, MT Status=0, MTMSN=0
2023-03-22T17:21:40.463Z,1679505700.463 [NAL9602](INFO): No messages in MT queue
2023-03-22T17:22:11.167Z,1679505731.167 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T17:23:23.893Z,1679505803.893 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-03-22T17:23:23.893Z,1679505803.893 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+12.9,0000.0,1489.0I,+00345,-00229,-03033,+00000,A
2023-03-22T17:24:19.244Z,1679505859.244 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T17:24:19.245Z,1679505859.245 [Default:CheckIn:C.Wait] Stopped
2023-03-22T17:24:19.245Z,1679505859.245 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T17:24:19.245Z,1679505859.245 [Default:CheckIn:D] Running Loop=1
2023-03-22T17:24:19.663Z,1679505859.663 [Default:CheckIn:D] Stopped
2023-03-22T17:24:19.663Z,1679505859.663 [Default:CheckIn:E] Running Loop=1
2023-03-22T17:24:20.050Z,1679505860.050 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 117.900407 min 
2023-03-22T17:24:20.050Z,1679505860.050 [Default:CheckIn:E] Stopped
2023-03-22T17:24:20.050Z,1679505860.050 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T17:24:20.050Z,1679505860.050 [Default:CheckIn] Stopped
2023-03-22T17:24:20.051Z,1679505860.051 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T17:24:20.051Z,1679505860.051 [Default:CheckIn](INFO): Running loop #19
2023-03-22T17:24:20.051Z,1679505860.051 [Default:CheckIn] Running Loop=19
2023-03-22T17:24:20.051Z,1679505860.051 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T17:24:20.051Z,1679505860.051 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T17:24:22.075Z,1679505862.075 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172422.00,A,3648.17609,N,12147.27942,W,0.117,40.82,220323,,,A*4C
2023-03-22T17:24:22.077Z,1679505862.077 [NAL9602](INFO): GPS fix at 20230322T172422: (36.802935, -121.787990)
2023-03-22T17:24:22.087Z,1679505862.087 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T17:24:22.087Z,1679505862.087 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T17:24:29.316Z,1679505869.316 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230322T152039/Courier0064.lzma
2023-03-22T17:24:30.319Z,1679505870.319 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Courier0064.lzma.bak
2023-03-22T17:24:30.319Z,1679505870.319 [DataOverHttps](INFO): SBD MOMSN=17541231
2023-03-22T17:24:49.265Z,1679505889.265 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230322T152039/Express0065.lzma
2023-03-22T17:24:50.267Z,1679505890.267 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Express0065.lzma.bak
2023-03-22T17:24:50.267Z,1679505890.267 [DataOverHttps](INFO): SBD MOMSN=17541234
2023-03-22T17:24:51.639Z,1679505891.639 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T17:24:51.639Z,1679505891.639 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T17:24:51.639Z,1679505891.639 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T17:26:31.442Z,1679505991.442 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-03-22T17:26:31.442Z,1679505991.442 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+12.9,489.0,000
2023-03-22T17:29:24.780Z,1679506164.780 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-03-22T17:29:52.302Z,1679506192.302 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T17:29:52.303Z,1679506192.303 [Default:CheckIn:C.Wait] Stopped
2023-03-22T17:29:52.303Z,1679506192.303 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T17:29:52.303Z,1679506192.303 [Default:CheckIn:D] Running Loop=1
2023-03-22T17:29:52.713Z,1679506192.713 [Default:CheckIn:D] Stopped
2023-03-22T17:29:52.713Z,1679506192.713 [Default:CheckIn:E] Running Loop=1
2023-03-22T17:29:53.117Z,1679506193.117 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 123.451229 min 
2023-03-22T17:29:53.117Z,1679506193.117 [Default:CheckIn:E] Stopped
2023-03-22T17:29:53.117Z,1679506193.117 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T17:29:53.117Z,1679506193.117 [Default:CheckIn] Stopped
2023-03-22T17:29:53.118Z,1679506193.118 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T17:29:53.118Z,1679506193.118 [Default:CheckIn](INFO): Running loop #20
2023-03-22T17:29:53.118Z,1679506193.118 [Default:CheckIn] Running Loop=20
2023-03-22T17:29:53.118Z,1679506193.118 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T17:29:53.118Z,1679506193.118 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T17:29:55.134Z,1679506195.134 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172956.00,A,3648.17521,N,12147.28089,W,0.019,40.82,220323,,,A*45
2023-03-22T17:29:55.137Z,1679506195.137 [NAL9602](INFO): GPS fix at 20230322T172956: (36.802920, -121.788015)
2023-03-22T17:29:55.146Z,1679506195.146 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T17:29:55.146Z,1679506195.146 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T17:30:02.961Z,1679506202.961 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20230322T152039/Courier0067.lzma
2023-03-22T17:30:03.963Z,1679506203.963 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Courier0067.lzma.bak
2023-03-22T17:30:03.963Z,1679506203.963 [DataOverHttps](INFO): SBD MOMSN=17541237
2023-03-22T17:30:19.742Z,1679506219.742 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20230322T152039/Express0068.lzma
2023-03-22T17:30:20.743Z,1679506220.743 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Express0068.lzma.bak
2023-03-22T17:30:20.744Z,1679506220.744 [DataOverHttps](INFO): SBD MOMSN=17541240
2023-03-22T17:30:21.801Z,1679506221.801 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T17:30:21.801Z,1679506221.801 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T17:30:21.801Z,1679506221.801 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T17:30:27.849Z,1679506227.849 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T17:30:52.522Z,1679506252.522 [DVL_micro](ERROR): only read 3 of 4 data items
2023-03-22T17:30:52.522Z,1679506252.522 [DVL_micro](ERROR): Failed to parse:
:BI,+0015,-02535,+00000,I
2023-03-22T17:32:46.832Z,1679506366.832 [DVL_micro](ERROR): Failed to parse:
0000000000,35.0,+12.9,009.0,000
2023-03-22T17:35:22.427Z,1679506522.427 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T17:35:22.427Z,1679506522.427 [Default:CheckIn:C.Wait] Stopped
2023-03-22T17:35:22.428Z,1679506522.428 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T17:35:22.428Z,1679506522.428 [Default:CheckIn:D] Running Loop=1
2023-03-22T17:35:22.810Z,1679506522.810 [Default:CheckIn:D] Stopped
2023-03-22T17:35:22.810Z,1679506522.810 [Default:CheckIn:E] Running Loop=1
2023-03-22T17:35:23.215Z,1679506523.215 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 128.952848 min 
2023-03-22T17:35:23.216Z,1679506523.216 [Default:CheckIn:E] Stopped
2023-03-22T17:35:23.216Z,1679506523.216 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T17:35:23.216Z,1679506523.216 [Default:CheckIn] Stopped
2023-03-22T17:35:23.216Z,1679506523.216 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T17:35:23.216Z,1679506523.216 [Default:CheckIn](INFO): Running loop #21
2023-03-22T17:35:23.216Z,1679506523.216 [Default:CheckIn] Running Loop=21
2023-03-22T17:35:23.216Z,1679506523.216 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T17:35:23.216Z,1679506523.216 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T17:35:25.241Z,1679506525.241 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173526.00,A,3648.17334,N,12147.28018,W,0.058,40.82,220323,,,A*40
2023-03-22T17:35:25.243Z,1679506525.243 [NAL9602](INFO): GPS fix at 20230322T173526: (36.802889, -121.788003)
2023-03-22T17:35:25.252Z,1679506525.252 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T17:35:25.253Z,1679506525.253 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T17:35:34.220Z,1679506534.220 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230322T152039/Courier0070.lzma
2023-03-22T17:35:35.223Z,1679506535.223 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Courier0070.lzma.bak
2023-03-22T17:35:35.223Z,1679506535.223 [DataOverHttps](INFO): SBD MOMSN=17541284
2023-03-22T17:35:51.940Z,1679506551.940 [DVL_micro](ERROR): only read 3 of 4 data items
2023-03-22T17:35:51.940Z,1679506551.940 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,9,+9999.99
2023-03-22T17:35:53.180Z,1679506553.180 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230322T152039/Express0071.lzma
2023-03-22T17:35:54.183Z,1679506554.183 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Express0071.lzma.bak
2023-03-22T17:35:54.183Z,1679506554.183 [DataOverHttps](INFO): SBD MOMSN=17541287
2023-03-22T17:35:55.567Z,1679506555.567 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T17:35:55.567Z,1679506555.567 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T17:35:55.567Z,1679506555.567 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T17:35:55.965Z,1679506555.965 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-03-22T17:35:56.045Z,1679506556.045 [NAL9602](ERROR): received: 
+CSQ:0

OK461, 0, 0, 0, 0

OK
2023-03-22T17:36:43.646Z,1679506603.646 [NAL9602](INFO): SBD MO Status=0, MOMSN=47462, MT Status=0, MTMSN=0
2023-03-22T17:36:43.646Z,1679506603.646 [NAL9602](INFO): No messages in MT queue
2023-03-22T17:37:14.349Z,1679506634.349 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T17:38:57.020Z,1679506737.020 [DVL_micro](ERROR): Failed to parse:
:BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00
2023-03-22T17:40:56.313Z,1679506856.313 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T17:40:56.314Z,1679506856.314 [Default:CheckIn:C.Wait] Stopped
2023-03-22T17:40:56.314Z,1679506856.314 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T17:40:56.314Z,1679506856.314 [Default:CheckIn:D] Running Loop=1
2023-03-22T17:40:56.716Z,1679506856.716 [Default:CheckIn:D] Stopped
2023-03-22T17:40:56.716Z,1679506856.716 [Default:CheckIn:E] Running Loop=1
2023-03-22T17:40:57.127Z,1679506857.127 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 134.517952 min 
2023-03-22T17:40:57.127Z,1679506857.127 [Default:CheckIn:E] Stopped
2023-03-22T17:40:57.127Z,1679506857.127 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T17:40:57.127Z,1679506857.127 [Default:CheckIn] Stopped
2023-03-22T17:40:57.127Z,1679506857.127 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T17:40:57.128Z,1679506857.128 [Default:CheckIn](INFO): Running loop #22
2023-03-22T17:40:57.128Z,1679506857.128 [Default:CheckIn] Running Loop=22
2023-03-22T17:40:57.128Z,1679506857.128 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T17:40:57.128Z,1679506857.128 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T17:40:59.127Z,1679506859.127 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174100.00,A,3648.17603,N,12147.27665,W,0.078,40.82,220323,,,A*47
2023-03-22T17:40:59.130Z,1679506859.130 [NAL9602](INFO): GPS fix at 20230322T174100: (36.802934, -121.787944)
2023-03-22T17:40:59.140Z,1679506859.140 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T17:40:59.140Z,1679506859.140 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T17:41:06.536Z,1679506866.536 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20230322T152039/Courier0073.lzma
2023-03-22T17:41:07.539Z,1679506867.539 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Courier0073.lzma.bak
2023-03-22T17:41:07.539Z,1679506867.539 [DataOverHttps](INFO): SBD MOMSN=17541295
2023-03-22T17:41:23.449Z,1679506883.449 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20230322T152039/Express0074.lzma
2023-03-22T17:41:24.451Z,1679506884.451 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Express0074.lzma.bak
2023-03-22T17:41:24.451Z,1679506884.451 [DataOverHttps](INFO): SBD MOMSN=17541298
2023-03-22T17:41:25.801Z,1679506885.801 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T17:41:25.801Z,1679506885.801 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T17:41:25.801Z,1679506885.801 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T17:44:24.440Z,1679507064.440 [DVL_micro](ERROR): only read 3 of 4 data items
2023-03-22T17:44:24.440Z,1679507064.440 [DVL_micro](ERROR): Failed to parse:
:BI,-00189,+00859,.99
2023-03-22T17:46:01.911Z,1679507161.911 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-03-22T17:46:26.564Z,1679507186.564 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T17:46:26.564Z,1679507186.564 [Default:CheckIn:C.Wait] Stopped
2023-03-22T17:46:26.564Z,1679507186.564 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T17:46:26.564Z,1679507186.564 [Default:CheckIn:D] Running Loop=1
2023-03-22T17:46:26.980Z,1679507186.980 [Default:CheckIn:D] Stopped
2023-03-22T17:46:26.980Z,1679507186.980 [Default:CheckIn:E] Running Loop=1
2023-03-22T17:46:27.377Z,1679507187.377 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 140.022347 min 
2023-03-22T17:46:27.378Z,1679507187.378 [Default:CheckIn:E] Stopped
2023-03-22T17:46:27.378Z,1679507187.378 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T17:46:27.378Z,1679507187.378 [Default:CheckIn] Stopped
2023-03-22T17:46:27.378Z,1679507187.378 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T17:46:27.378Z,1679507187.378 [Default:CheckIn](INFO): Running loop #23
2023-03-22T17:46:27.378Z,1679507187.378 [Default:CheckIn] Running Loop=23
2023-03-22T17:46:27.378Z,1679507187.378 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T17:46:27.378Z,1679507187.378 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T17:46:29.385Z,1679507189.385 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174630.00,A,3648.17379,N,12147.28070,W,0.136,0.00,220323,,,A*73
2023-03-22T17:46:29.387Z,1679507189.387 [NAL9602](INFO): GPS fix at 20230322T174630: (36.802897, -121.788012)
2023-03-22T17:46:29.396Z,1679507189.396 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T17:46:29.397Z,1679507189.397 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T17:46:39.673Z,1679507199.673 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230322T152039/Courier0076.lzma
2023-03-22T17:46:40.675Z,1679507200.675 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Courier0076.lzma.bak
2023-03-22T17:46:40.675Z,1679507200.675 [DataOverHttps](INFO): SBD MOMSN=17541341
2023-03-22T17:46:56.673Z,1679507216.673 [DataOverHttps](INFO): Sending 210 bytes from file Logs/20230322T152039/Express0077.lzma
2023-03-22T17:46:57.675Z,1679507217.675 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Express0077.lzma.bak
2023-03-22T17:46:57.675Z,1679507217.675 [DataOverHttps](INFO): SBD MOMSN=17541344
2023-03-22T17:46:58.744Z,1679507218.744 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T17:46:58.744Z,1679507218.744 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T17:46:58.744Z,1679507218.744 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T17:47:01.939Z,1679507221.939 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T17:48:07.454Z,1679507287.454 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-03-22T17:48:07.454Z,1679507287.454 [DVL_micro](ERROR): Failed to parse:
:TS,000000000.0,+12.8,0000.0,1489.0,000
2023-03-22T17:51:59.246Z,1679507519.246 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T17:51:59.246Z,1679507519.246 [Default:CheckIn:C.Wait] Stopped
2023-03-22T17:51:59.246Z,1679507519.246 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T17:51:59.246Z,1679507519.246 [Default:CheckIn:D] Running Loop=1
2023-03-22T17:51:59.655Z,1679507519.655 [Default:CheckIn:D] Stopped
2023-03-22T17:51:59.655Z,1679507519.655 [Default:CheckIn:E] Running Loop=1
2023-03-22T17:52:00.051Z,1679507520.051 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 145.566927 min 
2023-03-22T17:52:00.051Z,1679507520.051 [Default:CheckIn:E] Stopped
2023-03-22T17:52:00.051Z,1679507520.051 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T17:52:00.051Z,1679507520.051 [Default:CheckIn] Stopped
2023-03-22T17:52:00.051Z,1679507520.051 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T17:52:00.052Z,1679507520.052 [Default:CheckIn](INFO): Running loop #24
2023-03-22T17:52:00.052Z,1679507520.052 [Default:CheckIn] Running Loop=24
2023-03-22T17:52:00.052Z,1679507520.052 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T17:52:00.052Z,1679507520.052 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T17:52:02.073Z,1679507522.073 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175202.00,A,3648.17410,N,12147.27854,W,0.039,0.00,220323,,,A*70
2023-03-22T17:52:02.075Z,1679507522.075 [NAL9602](INFO): GPS fix at 20230322T175202: (36.802902, -121.787976)
2023-03-22T17:52:02.084Z,1679507522.084 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T17:52:02.084Z,1679507522.084 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T17:52:08.972Z,1679507528.972 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230322T152039/Courier0079.lzma
2023-03-22T17:52:09.975Z,1679507529.975 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Courier0079.lzma.bak
2023-03-22T17:52:09.975Z,1679507529.975 [DataOverHttps](INFO): SBD MOMSN=17541348
2023-03-22T17:52:25.945Z,1679507545.945 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230322T152039/Express0080.lzma
2023-03-22T17:52:26.947Z,1679507546.947 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Express0080.lzma.bak
2023-03-22T17:52:26.947Z,1679507546.947 [DataOverHttps](INFO): SBD MOMSN=17541351
2023-03-22T17:52:28.330Z,1679507548.330 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T17:52:28.330Z,1679507548.330 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T17:52:28.331Z,1679507548.331 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T17:52:31.225Z,1679507551.225 [DVL_micro](ERROR): only read 3 of 4 data items
2023-03-22T17:52:31.233Z,1679507551.233 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.99,+9999..99
2023-03-22T17:52:32.811Z,1679507552.811 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-03-22T17:52:32.894Z,1679507552.894 [NAL9602](ERROR): received: 
+CSQ:0

OK462, 0, 0, 0, 0

OK
2023-03-22T17:55:30.711Z,1679507730.711 [NAL9602](INFO): SBD MO Status=2, MOMSN=47463, MT Status=2, MTMSN=0
2023-03-22T17:55:30.711Z,1679507730.711 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-03-22T17:56:20.052Z,1679507780.052 [NAL9602](INFO): SBD MO Status=0, MOMSN=47463, MT Status=0, MTMSN=0
2023-03-22T17:56:20.052Z,1679507780.052 [NAL9602](INFO): No messages in MT queue
2023-03-22T17:56:50.818Z,1679507810.818 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T17:57:28.802Z,1679507848.802 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T17:57:28.802Z,1679507848.802 [Default:CheckIn:C.Wait] Stopped
2023-03-22T17:57:28.802Z,1679507848.802 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T17:57:28.802Z,1679507848.802 [Default:CheckIn:D] Running Loop=1
2023-03-22T17:57:29.206Z,1679507849.206 [Default:CheckIn:D] Stopped
2023-03-22T17:57:29.206Z,1679507849.206 [Default:CheckIn:E] Running Loop=1
2023-03-22T17:57:29.620Z,1679507849.620 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 151.059456 min 
2023-03-22T17:57:29.620Z,1679507849.620 [Default:CheckIn:E] Stopped
2023-03-22T17:57:29.620Z,1679507849.620 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T17:57:29.620Z,1679507849.620 [Default:CheckIn] Stopped
2023-03-22T17:57:29.620Z,1679507849.620 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T17:57:29.620Z,1679507849.620 [Default:CheckIn](INFO): Running loop #25
2023-03-22T17:57:29.620Z,1679507849.620 [Default:CheckIn] Running Loop=25
2023-03-22T17:57:29.620Z,1679507849.620 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T17:57:29.621Z,1679507849.621 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T17:57:31.620Z,1679507851.620 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175732.00,A,3648.17385,N,12147.27969,W,0.078,0.00,220323,,,A*77
2023-03-22T17:57:31.631Z,1679507851.631 [NAL9602](INFO): GPS fix at 20230322T175732: (36.802898, -121.787995)
2023-03-22T17:57:31.640Z,1679507851.640 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T17:57:31.640Z,1679507851.640 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T17:57:42.248Z,1679507862.248 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230322T152039/Courier0082.lzma
2023-03-22T17:57:43.251Z,1679507863.251 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Courier0082.lzma.bak
2023-03-22T17:57:43.251Z,1679507863.251 [DataOverHttps](INFO): SBD MOMSN=17541396
2023-03-22T17:57:59.193Z,1679507879.193 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230322T152039/Express0083.lzma
2023-03-22T17:58:00.195Z,1679507880.195 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Express0083.lzma.bak
2023-03-22T17:58:00.195Z,1679507880.195 [DataOverHttps](INFO): SBD MOMSN=17541399
2023-03-22T17:58:01.594Z,1679507881.594 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T17:58:01.594Z,1679507881.594 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T17:58:01.594Z,1679507881.594 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T17:58:18.965Z,1679507898.965 [NAL9602](INFO): SBD MO Status=2, MOMSN=47464, MT Status=2, MTMSN=0
2023-03-22T17:58:18.965Z,1679507898.965 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-03-22T17:58:38.441Z,1679507918.441 [NAL9602](INFO): SBD MO Status=0, MOMSN=47464, MT Status=0, MTMSN=0
2023-03-22T17:58:38.441Z,1679507918.441 [NAL9602](INFO): No messages in MT queue
2023-03-22T17:59:09.109Z,1679507949.109 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T18:01:43.826Z,1679508103.826 [DataOverHttps](IMPORTANT): SBD MTMSN=20230322T180144
2023-03-22T18:01:51.213Z,1679508111.213 [DataOverHttps](INFO): Received command: failc
2023-03-22T18:01:51.222Z,1679508111.222 [CommandExec](IMPORTANT): got command failComponent
2023-03-22T18:01:51.222Z,1679508111.222 [CommandExec](IMPORTANT): Failed components:
2023-03-22T18:01:51.222Z,1679508111.222 [CommandExec](IMPORTANT): No failed Components.
2023-03-22T18:03:02.304Z,1679508182.304 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T18:03:02.304Z,1679508182.304 [Default:CheckIn:C.Wait] Stopped
2023-03-22T18:03:02.304Z,1679508182.304 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T18:03:02.304Z,1679508182.304 [Default:CheckIn:D] Running Loop=1
2023-03-22T18:03:02.709Z,1679508182.709 [Default:CheckIn:D] Stopped
2023-03-22T18:03:02.709Z,1679508182.709 [Default:CheckIn:E] Running Loop=1
2023-03-22T18:03:03.132Z,1679508183.132 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 156.617839 min 
2023-03-22T18:03:03.132Z,1679508183.132 [Default:CheckIn:E] Stopped
2023-03-22T18:03:03.132Z,1679508183.132 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T18:03:03.132Z,1679508183.132 [Default:CheckIn] Stopped
2023-03-22T18:03:03.132Z,1679508183.132 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T18:03:03.133Z,1679508183.133 [Default:CheckIn](INFO): Running loop #26
2023-03-22T18:03:03.133Z,1679508183.133 [Default:CheckIn] Running Loop=26
2023-03-22T18:03:03.133Z,1679508183.133 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T18:03:03.133Z,1679508183.133 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T18:03:05.136Z,1679508185.136 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180306.00,A,3648.17414,N,12147.27974,W,0.039,0.00,220323,,,A*78
2023-03-22T18:03:05.138Z,1679508185.138 [NAL9602](INFO): GPS fix at 20230322T180306: (36.802902, -121.787996)
2023-03-22T18:03:05.168Z,1679508185.168 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T18:03:05.168Z,1679508185.168 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T18:03:13.072Z,1679508193.072 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230322T152039/Courier0085.lzma
2023-03-22T18:03:14.075Z,1679508194.075 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Courier0085.lzma.bak
2023-03-22T18:03:14.075Z,1679508194.075 [DataOverHttps](INFO): SBD MOMSN=17541407
2023-03-22T18:03:23.319Z,1679508203.319 [DVL_micro](ERROR): only read 3 of 4 data items
2023-03-22T18:03:23.319Z,1679508203.319 [DVL_micro](ERROR): Failed to parse:
:RD,+99999.99,+9999.99,+9999.99
2023-03-22T18:03:30.221Z,1679508210.221 [DataOverHttps](INFO): Sending 218 bytes from file Logs/20230322T152039/Express0086.lzma
2023-03-22T18:03:31.223Z,1679508211.223 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Express0086.lzma.bak
2023-03-22T18:03:31.223Z,1679508211.223 [DataOverHttps](INFO): SBD MOMSN=17541410
2023-03-22T18:03:50.660Z,1679508230.660 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20230322T152039/Express0089.lzma
2023-03-22T18:03:51.663Z,1679508231.663 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Express0089.lzma.bak
2023-03-22T18:03:51.663Z,1679508231.663 [DataOverHttps](INFO): SBD MOMSN=17541421
2023-03-22T18:03:52.859Z,1679508232.859 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T18:03:52.859Z,1679508232.859 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T18:03:52.859Z,1679508232.859 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T18:04:25.590Z,1679508265.590 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-03-22T18:05:18.529Z,1679508318.529 [NAL9602](INFO): SBD MO Status=2, MOMSN=47465, MT Status=2, MTMSN=0
2023-03-22T18:05:18.529Z,1679508318.529 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-03-22T18:06:24.769Z,1679508384.769 [NAL9602](INFO): SBD MO Status=2, MOMSN=47465, MT Status=2, MTMSN=0
2023-03-22T18:06:24.769Z,1679508384.769 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-03-22T18:06:31.511Z,1679508391.511 [DVL_micro](ERROR): Failed to parse:
:T00000000,35.0,+12.8,0000.0,1489.0,000
2023-03-22T18:07:11.254Z,1679508431.254 [NAL9602](INFO): SBD MO Status=0, MOMSN=47465, MT Status=0, MTMSN=0
2023-03-22T18:07:11.254Z,1679508431.254 [NAL9602](INFO): No messages in MT queue
2023-03-22T18:07:38.369Z,1679508458.369 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2023-03-22T18:07:38.372Z,1679508458.372 [BPC1](INFO): Received data from all battery sticks.
2023-03-22T18:07:42.011Z,1679508462.011 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T18:08:53.556Z,1679508533.556 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T18:08:53.556Z,1679508533.556 [Default:CheckIn:C.Wait] Stopped
2023-03-22T18:08:53.556Z,1679508533.556 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T18:08:53.556Z,1679508533.556 [Default:CheckIn:D] Running Loop=1
2023-03-22T18:08:53.959Z,1679508533.959 [Default:CheckIn:D] Stopped
2023-03-22T18:08:53.959Z,1679508533.959 [Default:CheckIn:E] Running Loop=1
2023-03-22T18:08:54.370Z,1679508534.370 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 162.471989 min 
2023-03-22T18:08:54.370Z,1679508534.370 [Default:CheckIn:E] Stopped
2023-03-22T18:08:54.370Z,1679508534.370 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T18:08:54.370Z,1679508534.370 [Default:CheckIn] Stopped
2023-03-22T18:08:54.370Z,1679508534.370 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T18:08:54.370Z,1679508534.370 [Default:CheckIn](INFO): Running loop #27
2023-03-22T18:08:54.370Z,1679508534.370 [Default:CheckIn] Running Loop=27
2023-03-22T18:08:54.371Z,1679508534.371 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T18:08:54.371Z,1679508534.371 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T18:08:56.383Z,1679508536.383 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180857.00,A,3648.17456,N,12147.27765,W,0.000,0.00,220323,,,A*75
2023-03-22T18:08:56.386Z,1679508536.386 [NAL9602](INFO): GPS fix at 20230322T180857: (36.802909, -121.787961)
2023-03-22T18:08:56.395Z,1679508536.395 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T18:08:56.395Z,1679508536.395 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T18:09:03.896Z,1679508543.896 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20230322T152039/Courier0091.lzma
2023-03-22T18:09:04.899Z,1679508544.899 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Courier0091.lzma.bak
2023-03-22T18:09:04.899Z,1679508544.899 [DataOverHttps](INFO): SBD MOMSN=17541507
2023-03-22T18:09:20.860Z,1679508560.860 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230322T152039/Express0092.lzma
2023-03-22T18:09:21.877Z,1679508561.877 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Express0092.lzma.bak
2023-03-22T18:09:21.877Z,1679508561.877 [DataOverHttps](INFO): SBD MOMSN=17541510
2023-03-22T18:09:23.047Z,1679508563.047 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T18:09:23.047Z,1679508563.047 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T18:09:23.047Z,1679508563.047 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T18:09:28.703Z,1679508568.703 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.99,+9999.99,+9999.99
2023-03-22T18:11:23.078Z,1679508683.078 [CommandExec](IMPORTANT): got command gfscan
2023-03-22T18:11:23.134Z,1679508683.134 [CBIT](IMPORTANT): Beginning ground fault scan
2023-03-22T18:11:34.022Z,1679508694.022 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.082831
CHAN A1 (24V): 0.117519
CHAN A2 (12V): 0.016489
CHAN A3 (5V): -0.015834
CHAN B0 (3.3V): -0.010238
CHAN B1 (3.15aV): -0.006369
CHAN B2 (3.15bV): -0.003550
CHAN B3 (GND): -0.016907
OPEN: 0.008142
Full Scale: +/- 1 mA
2023-03-22T18:12:07.235Z,1679508727.235 [CommandExec](IMPORTANT): got command show variable dvl_micro.loadcontrol
2023-03-22T18:12:07.295Z,1679508727.295 [CommandExec](IMPORTANT): DVL_micro.loadControl (none)
2023-03-22T18:12:28.909Z,1679508748.909 [DVL_micro](ERROR): only read 0 of 4 data items
2023-03-22T18:12:28.909Z,1679508748.909 [DVL_micro](ERROR): Failed to parse:
:RD,,+9999.99,+99999.99
2023-03-22T18:12:40.801Z,1679508760.801 [CommandExec](IMPORTANT): got command get DVL_micro.loadControl
2023-03-22T18:12:40.807Z,1679508760.807 [CommandExec](IMPORTANT): DVL_micro.loadControl /dev/loadB4
2023-03-22T18:13:33.987Z,1679508813.987 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadB4
2023-03-22T18:13:42.536Z,1679508822.536 [DVL_micro](ERROR): No DVL communication! Re-initializing
2023-03-22T18:13:42.536Z,1679508822.536 [DVL_micro] Communications Fault, FailCount= 1
2023-03-22T18:13:42.536Z,1679508822.536 [DVL_micro](ERROR): Communications Fault
2023-03-22T18:13:42.556Z,1679508822.556 [CBIT](ERROR): Communications Fault in component: DVL_micro
2023-03-22T18:13:43.021Z,1679508823.021 [DVL_micro](INFO): Powering down
2023-03-22T18:13:43.769Z,1679508823.769 [CBIT](INFO): Clearing failed state for component DVL_micro
2023-03-22T18:13:43.769Z,1679508823.769 [DVL_micro] No Fault, FailCount= 1
2023-03-22T18:13:49.662Z,1679508829.662 [CommandExec](IMPORTANT): got command gfscan
2023-03-22T18:13:49.836Z,1679508829.836 [CBIT](IMPORTANT): Beginning ground fault scan
2023-03-22T18:14:00.720Z,1679508840.720 [NAL9602](INFO): SBD MO Status=2, MOMSN=47466, MT Status=2, MTMSN=0
2023-03-22T18:14:00.721Z,1679508840.721 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-03-22T18:14:00.743Z,1679508840.743 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.072754
CHAN A1 (24V): 0.120853
CHAN A2 (12V): 0.017860
CHAN A3 (5V): -0.015681
CHAN B0 (3.3V): -0.010646
CHAN B1 (3.15aV): -0.006720
CHAN B2 (3.15bV): -0.003659
CHAN B3 (GND): -0.017496
OPEN: 0.008016
Full Scale: +/- 1 mA
2023-03-22T18:14:01.144Z,1679508841.144 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-03-22T18:14:23.779Z,1679508863.779 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T18:14:23.779Z,1679508863.779 [Default:CheckIn:C.Wait] Stopped
2023-03-22T18:14:23.779Z,1679508863.779 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T18:14:23.779Z,1679508863.779 [Default:CheckIn:D] Running Loop=1
2023-03-22T18:14:24.154Z,1679508864.154 [Default:CheckIn:D] Stopped
2023-03-22T18:14:24.154Z,1679508864.154 [Default:CheckIn:E] Running Loop=1
2023-03-22T18:14:24.589Z,1679508864.589 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 167.975260 min 
2023-03-22T18:14:24.589Z,1679508864.589 [Default:CheckIn:E] Stopped
2023-03-22T18:14:24.590Z,1679508864.590 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T18:14:24.590Z,1679508864.590 [Default:CheckIn] Stopped
2023-03-22T18:14:24.590Z,1679508864.590 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T18:14:24.590Z,1679508864.590 [Default:CheckIn](INFO): Running loop #28
2023-03-22T18:14:24.590Z,1679508864.590 [Default:CheckIn] Running Loop=28
2023-03-22T18:14:24.590Z,1679508864.590 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T18:14:24.590Z,1679508864.590 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T18:14:26.576Z,1679508866.576 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181427.00,A,3648.17536,N,12147.28016,W,0.019,0.00,220323,,,A*7C
2023-03-22T18:14:26.578Z,1679508866.578 [NAL9602](INFO): GPS fix at 20230322T181427: (36.802923, -121.788003)
2023-03-22T18:14:26.588Z,1679508866.588 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T18:14:26.588Z,1679508866.588 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T18:14:36.792Z,1679508876.792 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230322T152039/Courier0094.lzma
2023-03-22T18:14:37.795Z,1679508877.795 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Courier0094.lzma.bak
2023-03-22T18:14:37.795Z,1679508877.795 [DataOverHttps](INFO): SBD MOMSN=17541520
2023-03-22T18:14:51.703Z,1679508891.703 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadB4
2023-03-22T18:14:53.798Z,1679508893.798 [CommandExec](IMPORTANT): got command gfscan
2023-03-22T18:14:53.815Z,1679508893.815 [CBIT](IMPORTANT): Beginning ground fault scan
2023-03-22T18:14:54.978Z,1679508894.978 [DataOverHttps](INFO): Sending 560 bytes from file Logs/20230322T152039/Express0095.lzma
2023-03-22T18:14:55.979Z,1679508895.979 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Express0095.lzma.bak
2023-03-22T18:14:55.979Z,1679508895.979 [DataOverHttps](INFO): SBD MOMSN=17541523
2023-03-22T18:14:57.352Z,1679508897.352 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T18:14:57.353Z,1679508897.353 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T18:14:57.353Z,1679508897.353 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T18:14:58.956Z,1679508898.956 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T18:15:00.186Z,1679508900.186 [DVL_micro](ERROR): No DVL communication! Re-initializing
2023-03-22T18:15:00.186Z,1679508900.186 [DVL_micro] Communications Fault, FailCount= 1
2023-03-22T18:15:00.186Z,1679508900.186 [DVL_micro](ERROR): Communications Fault
2023-03-22T18:15:00.328Z,1679508900.328 [CBIT](ERROR): Communications Fault in component: DVL_micro
2023-03-22T18:15:00.657Z,1679508900.657 [DVL_micro](INFO): Powering down
2023-03-22T18:15:01.453Z,1679508901.453 [CBIT](INFO): Clearing failed state for component DVL_micro
2023-03-22T18:15:01.453Z,1679508901.453 [DVL_micro] No Fault, FailCount= 1
2023-03-22T18:15:05.036Z,1679508905.036 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.038105
CHAN A1 (24V): 0.079296
CHAN A2 (12V): 0.028773
CHAN A3 (5V): 0.006583
CHAN B0 (3.3V): 0.003542
CHAN B1 (3.15aV): 0.008682
CHAN B2 (3.15bV): 0.006099
CHAN B3 (GND): -0.010762
OPEN: 0.007228
Full Scale: +/- 1 mA
2023-03-22T18:15:22.914Z,1679508922.914 [CommandExec](IMPORTANT): got command help failComponent
2023-03-22T18:16:15.800Z,1679508975.800 [CommandExec](IMPORTANT): got command failComponent software DVL_micro
2023-03-22T18:16:15.800Z,1679508975.800 [DVL_micro] Software Fault, FailCount= 1
2023-03-22T18:16:15.800Z,1679508975.800 [DVL_micro](ERROR): Software Fault
2023-03-22T18:16:15.801Z,1679508975.801 [CommandExec](IMPORTANT): DVL_micro failureMode is Software Fault
2023-03-22T18:16:16.209Z,1679508976.209 [DVL_micro](INFO): Powering down
2023-03-22T18:16:16.234Z,1679508976.234 [CBIT](ERROR): Software Fault in component: DVL_micro
2023-03-22T18:16:16.972Z,1679508976.972 [CBIT](INFO): Clearing failed state for component DVL_micro
2023-03-22T18:16:16.972Z,1679508976.972 [DVL_micro] No Fault, FailCount= 1
2023-03-22T18:16:58.118Z,1679509018.118 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadB4
2023-03-22T18:17:07.913Z,1679509027.913 [DVL_micro](ERROR): No DVL communication! Re-initializing
2023-03-22T18:17:07.914Z,1679509027.914 [DVL_micro] Communications Fault, FailCount= 1
2023-03-22T18:17:07.914Z,1679509027.914 [DVL_micro](ERROR): Communications Fault
2023-03-22T18:17:07.957Z,1679509027.957 [CBIT](ERROR): Communications Fault in component: DVL_micro
2023-03-22T18:17:08.393Z,1679509028.393 [DVL_micro](INFO): Powering down
2023-03-22T18:17:09.139Z,1679509029.139 [CBIT](INFO): Clearing failed state for component DVL_micro
2023-03-22T18:17:09.139Z,1679509029.139 [DVL_micro] No Fault, FailCount= 1
2023-03-22T18:17:13.427Z,1679509033.427 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadB4
2023-03-22T18:17:26.900Z,1679509046.900 [DVL_micro](FAULT): Failed to initialize within timeout.
2023-03-22T18:17:26.901Z,1679509046.901 [DVL_micro] Communications Fault, FailCount= 2
2023-03-22T18:17:26.901Z,1679509046.901 [DVL_micro](ERROR): Communications Fault
2023-03-22T18:17:26.919Z,1679509046.919 [CBIT](ERROR): Communications Fault in component: DVL_micro
2023-03-22T18:17:27.378Z,1679509047.378 [DVL_micro](INFO): Powering down
2023-03-22T18:17:28.149Z,1679509048.149 [CBIT](INFO): Clearing failed state for component DVL_micro
2023-03-22T18:17:28.149Z,1679509048.149 [DVL_micro] No Fault, FailCount= 2
2023-03-22T18:17:29.803Z,1679509049.803 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadB4
2023-03-22T18:17:45.934Z,1679509065.934 [DVL_micro](FAULT): Failed to initialize within timeout.
2023-03-22T18:17:45.934Z,1679509065.934 [DVL_micro] Communications Fault, FailCount= 3
2023-03-22T18:17:45.934Z,1679509065.934 [DVL_micro](ERROR): Communications Fault
2023-03-22T18:17:45.953Z,1679509065.953 [CBIT](ERROR): Communications Fault in component: DVL_micro
2023-03-22T18:17:45.953Z,1679509065.953 [CBIT](CRITICAL): Communications Fault in component: DVL_micro
2023-03-22T18:17:46.409Z,1679509066.409 [DVL_micro](INFO): Powering down
2023-03-22T18:17:46.436Z,1679509066.436 [CBIT](INFO): Critical error at 20230322T181745
2023-03-22T18:17:51.627Z,1679509071.627 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadB4
2023-03-22T18:19:28.814Z,1679509168.814 [CommandExec](IMPORTANT): got command gfscan
2023-03-22T18:19:29.083Z,1679509169.083 [CBIT](IMPORTANT): Beginning ground fault scan
2023-03-22T18:19:36.421Z,1679509176.421 [CommandExec](IMPORTANT): got command failComponent
2023-03-22T18:19:36.421Z,1679509176.421 [CommandExec](IMPORTANT): Failed components:
2023-03-22T18:19:36.422Z,1679509176.422 [CommandExec](IMPORTANT): DVL_micro: Communications Fault
2023-03-22T18:19:40.092Z,1679509180.092 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.040703
CHAN A1 (24V): 0.082442
CHAN A2 (12V): 0.029713
CHAN A3 (5V): 0.007021
CHAN B0 (3.3V): 0.003833
CHAN B1 (3.15aV): 0.003197
CHAN B2 (3.15bV): 0.003583
CHAN B3 (GND): -0.003649
OPEN: 0.007919
Full Scale: +/- 1 mA
2023-03-22T18:19:48.686Z,1679509188.686 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadB4
2023-03-22T18:19:57.774Z,1679509197.774 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T18:19:57.774Z,1679509197.774 [Default:CheckIn:C.Wait] Stopped
2023-03-22T18:19:57.774Z,1679509197.774 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T18:19:57.775Z,1679509197.775 [Default:CheckIn:D] Running Loop=1
2023-03-22T18:19:58.157Z,1679509198.157 [Default:CheckIn:D] Stopped
2023-03-22T18:19:58.157Z,1679509198.157 [Default:CheckIn:E] Running Loop=1
2023-03-22T18:19:58.569Z,1679509198.569 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 173.541960 min 
2023-03-22T18:19:58.569Z,1679509198.569 [Default:CheckIn:E] Stopped
2023-03-22T18:19:58.569Z,1679509198.569 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T18:19:58.569Z,1679509198.569 [Default:CheckIn] Stopped
2023-03-22T18:19:58.569Z,1679509198.569 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T18:19:58.570Z,1679509198.570 [Default:CheckIn](INFO): Running loop #29
2023-03-22T18:19:58.570Z,1679509198.570 [Default:CheckIn] Running Loop=29
2023-03-22T18:19:58.570Z,1679509198.570 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T18:19:58.570Z,1679509198.570 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T18:20:00.582Z,1679509200.582 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182001.00,A,3648.17630,N,12147.27834,W,0.019,0.00,220323,,,A*7D
2023-03-22T18:20:00.584Z,1679509200.584 [NAL9602](INFO): GPS fix at 20230322T182001: (36.802938, -121.787972)
2023-03-22T18:20:00.594Z,1679509200.594 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T18:20:00.594Z,1679509200.594 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T18:20:01.286Z,1679509201.286 [CommandExec](IMPORTANT): got command gfscan
2023-03-22T18:20:01.426Z,1679509201.426 [CBIT](IMPORTANT): Beginning ground fault scan
2023-03-22T18:20:07.724Z,1679509207.724 [DataOverHttps](INFO): Sending 125 bytes from file Logs/20230322T152039/Courier0097.lzma
2023-03-22T18:20:08.727Z,1679509208.727 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Courier0097.lzma.bak
2023-03-22T18:20:08.727Z,1679509208.727 [DataOverHttps](INFO): SBD MOMSN=17541576
2023-03-22T18:20:12.339Z,1679509212.339 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.043503
CHAN A1 (24V): 0.084390
CHAN A2 (12V): 0.031074
CHAN A3 (5V): 0.007907
CHAN B0 (3.3V): 0.004080
CHAN B1 (3.15aV): 0.003470
CHAN B2 (3.15bV): 0.003833
CHAN B3 (GND): -0.004471
OPEN: 0.007686
Full Scale: +/- 1 mA
2023-03-22T18:20:24.555Z,1679509224.555 [DataOverHttps](INFO): Sending 591 bytes from file Logs/20230322T152039/Express0098.lzma
2023-03-22T18:20:25.555Z,1679509225.555 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Express0098.lzma.bak
2023-03-22T18:20:25.555Z,1679509225.555 [DataOverHttps](INFO): SBD MOMSN=17541580
2023-03-22T18:20:26.852Z,1679509226.852 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T18:20:26.852Z,1679509226.852 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T18:20:26.853Z,1679509226.853 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T18:20:46.262Z,1679509246.262 [CBIT](INFO): Clearing failed state for component DVL_micro
2023-03-22T18:20:46.262Z,1679509246.262 [DVL_micro] No Fault, FailCount= 3
2023-03-22T18:20:57.394Z,1679509257.394 [CommandExec](IMPORTANT): got command gfscan
2023-03-22T18:20:57.590Z,1679509257.590 [CBIT](IMPORTANT): Beginning ground fault scan
2023-03-22T18:21:01.594Z,1679509261.594 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2023-03-22T18:21:01.594Z,1679509261.594 [DVL_micro] Data Fault, FailCount= 1
2023-03-22T18:21:01.594Z,1679509261.594 [DVL_micro](ERROR): Data Fault
2023-03-22T18:21:01.676Z,1679509261.676 [CBIT](ERROR): Data Fault in component: DVL_micro
2023-03-22T18:21:02.069Z,1679509262.069 [DVL_micro](INFO): Powering down
2023-03-22T18:21:02.894Z,1679509262.894 [CBIT](INFO): Clearing failed state for component DVL_micro
2023-03-22T18:21:02.894Z,1679509262.894 [DVL_micro] No Fault, FailCount= 1
2023-03-22T18:21:08.508Z,1679509268.508 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.090603
CHAN A1 (24V): 0.142010
CHAN A2 (12V): 0.027769
CHAN A3 (5V): -0.012112
CHAN B0 (3.3V): -0.009506
CHAN B1 (3.15aV): -0.005308
CHAN B2 (3.15bV): -0.001812
CHAN B3 (GND): -0.019226
OPEN: 0.008581
Full Scale: +/- 1 mA
2023-03-22T18:21:14.990Z,1679509274.990 [CommandExec](IMPORTANT): got command gfscan
2023-03-22T18:21:15.370Z,1679509275.370 [CBIT](IMPORTANT): Beginning ground fault scan
2023-03-22T18:21:18.574Z,1679509278.574 [DVL_micro](INFO): Failure count cleared after critical for DVL_micro
2023-03-22T18:21:26.308Z,1679509286.308 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.091662
CHAN A1 (24V): 0.142128
CHAN A2 (12V): 0.027275
CHAN A3 (5V): -0.012013
CHAN B0 (3.3V): -0.009095
CHAN B1 (3.15aV): -0.004655
CHAN B2 (3.15bV): -0.001475
CHAN B3 (GND): -0.019553
OPEN: 0.008198
Full Scale: +/- 1 mA
2023-03-22T18:22:26.910Z,1679509346.910 [DVL_micro](ERROR): Failed to parse:
:SA,-03.36,-06.17,356.1
2023-03-22T18:23:00.085Z,1679509380.085 [NAL9602](INFO): SBD MO Status=0, MOMSN=47466, MT Status=0, MTMSN=0
2023-03-22T18:23:00.086Z,1679509380.086 [NAL9602](INFO): No messages in MT queue
2023-03-22T18:23:25.958Z,1679509405.958 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadB3
2023-03-22T18:23:30.790Z,1679509410.790 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T18:23:43.018Z,1679509423.018 [CommandExec](IMPORTANT): got command gfscan
2023-03-22T18:23:43.047Z,1679509423.047 [CBIT](IMPORTANT): Beginning ground fault scan
2023-03-22T18:23:53.899Z,1679509433.899 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.099600
CHAN A1 (24V): 0.150994
CHAN A2 (12V): 0.031176
CHAN A3 (5V): -0.010229
CHAN B0 (3.3V): -0.008126
CHAN B1 (3.15aV): -0.003666
CHAN B2 (3.15bV): -0.000714
CHAN B3 (GND): -0.019711
OPEN: 0.007945
Full Scale: +/- 1 mA
2023-03-22T18:24:00.622Z,1679509440.622 [CommandExec](IMPORTANT): got command failComponent
2023-03-22T18:24:00.622Z,1679509440.622 [CommandExec](IMPORTANT): Failed components:
2023-03-22T18:24:00.622Z,1679509440.622 [CommandExec](IMPORTANT): No failed Components.
2023-03-22T18:24:06.008Z,1679509446.008 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-03-22T18:24:06.013Z,1679509446.013 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0000.0,1489.0,000
2023-03-22T18:24:20.000Z,1679509461.000 [CommandExec](IMPORTANT): got command failComponent hardware DVL_micro
2023-03-22T18:24:20.000Z,1679509461.000 [DVL_micro] Hardware Fault, FailCount= 1
2023-03-22T18:24:20.000Z,1679509461.000 [DVL_micro](ERROR): Hardware Fault
2023-03-22T18:24:21.000Z,1679509461.000 [CommandExec](IMPORTANT): DVL_micro failureMode is Hardware Fault
2023-03-22T18:24:21.417Z,1679509461.417 [DVL_micro](INFO): Powering down
2023-03-22T18:24:21.442Z,1679509461.442 [CBIT](ERROR): Hardware Fault in component: DVL_micro
2023-03-22T18:24:22.169Z,1679509462.169 [CBIT](INFO): Clearing failed state for component DVL_micro
2023-03-22T18:24:22.169Z,1679509462.169 [DVL_micro] No Fault, FailCount= 1
2023-03-22T18:24:22.580Z,1679509462.580 [CommandExec](IMPORTANT): got command failComponent hardware DVL_micro
2023-03-22T18:24:22.580Z,1679509462.580 [DVL_micro] Hardware Fault, FailCount= 2
2023-03-22T18:24:22.580Z,1679509462.580 [DVL_micro](ERROR): Hardware Fault
2023-03-22T18:24:22.581Z,1679509462.581 [CommandExec](IMPORTANT): DVL_micro failureMode is Hardware Fault
2023-03-22T18:24:22.591Z,1679509462.591 [CBIT](ERROR): Hardware Fault in component: DVL_micro
2023-03-22T18:24:23.030Z,1679509463.030 [DVL_micro](INFO): Powering down
2023-03-22T18:24:23.785Z,1679509463.785 [CBIT](INFO): Clearing failed state for component DVL_micro
2023-03-22T18:24:23.785Z,1679509463.785 [DVL_micro] No Fault, FailCount= 2
2023-03-22T18:24:23.932Z,1679509463.932 [CommandExec](IMPORTANT): got command failComponent hardware DVL_micro
2023-03-22T18:24:23.932Z,1679509463.932 [DVL_micro] Hardware Fault, FailCount= 3
2023-03-22T18:24:23.932Z,1679509463.932 [DVL_micro](ERROR): Hardware Fault
2023-03-22T18:24:23.932Z,1679509463.932 [CommandExec](IMPORTANT): DVL_micro failureMode is Hardware Fault
2023-03-22T18:24:24.198Z,1679509464.198 [CBIT](ERROR): Hardware Fault in component: DVL_micro
2023-03-22T18:24:24.198Z,1679509464.198 [CBIT](CRITICAL): Hardware Fault in component: DVL_micro
2023-03-22T18:24:24.586Z,1679509464.586 [CBIT](INFO): Critical error at 20230322T182424
2023-03-22T18:24:25.076Z,1679509465.076 [CommandExec](IMPORTANT): got command failComponent hardware DVL_micro
2023-03-22T18:24:25.076Z,1679509465.076 [CommandExec](IMPORTANT): DVL_micro failureMode is Hardware Fault
2023-03-22T18:24:36.007Z,1679509476.007 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadB4
2023-03-22T18:24:39.566Z,1679509479.566 [CommandExec](IMPORTANT): got command gfscan
2023-03-22T18:24:39.710Z,1679509479.710 [CBIT](IMPORTANT): Beginning ground fault scan
2023-03-22T18:24:50.516Z,1679509490.516 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.058993
CHAN A1 (24V): 0.099767
CHAN A2 (12V): 0.039060
CHAN A3 (5V): 0.009961
CHAN B0 (3.3V): 0.005273
CHAN B1 (3.15aV): 0.004895
CHAN B2 (3.15bV): 0.005224
CHAN B3 (GND): -0.005579
OPEN: 0.006707
Full Scale: +/- 1 mA
2023-03-22T18:24:57.526Z,1679509497.526 [CommandExec](IMPORTANT): got command gfscan
2023-03-22T18:24:57.799Z,1679509497.799 [CBIT](IMPORTANT): Beginning ground fault scan
2023-03-22T18:25:08.696Z,1679509508.696 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.057571
CHAN A1 (24V): 0.100914
CHAN A2 (12V): 0.039136
CHAN A3 (5V): 0.009929
CHAN B0 (3.3V): 0.005634
CHAN B1 (3.15aV): 0.005128
CHAN B2 (3.15bV): 0.005495
CHAN B3 (GND): -0.005082
OPEN: 0.006400
Full Scale: +/- 1 mA
2023-03-22T18:25:27.274Z,1679509527.274 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T18:25:27.274Z,1679509527.274 [Default:CheckIn:C.Wait] Stopped
2023-03-22T18:25:27.274Z,1679509527.274 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T18:25:27.274Z,1679509527.274 [Default:CheckIn:D] Running Loop=1
2023-03-22T18:25:27.666Z,1679509527.666 [Default:CheckIn:D] Stopped
2023-03-22T18:25:27.666Z,1679509527.666 [Default:CheckIn:E] Running Loop=1
2023-03-22T18:25:28.070Z,1679509528.070 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 179.033789 min 
2023-03-22T18:25:28.070Z,1679509528.070 [Default:CheckIn:E] Stopped
2023-03-22T18:25:28.071Z,1679509528.071 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T18:25:28.071Z,1679509528.071 [Default:CheckIn] Stopped
2023-03-22T18:25:28.071Z,1679509528.071 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T18:25:28.071Z,1679509528.071 [Default:CheckIn](INFO): Running loop #30
2023-03-22T18:25:28.071Z,1679509528.071 [Default:CheckIn] Running Loop=30
2023-03-22T18:25:28.071Z,1679509528.071 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T18:25:28.071Z,1679509528.071 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T18:25:30.092Z,1679509530.092 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182531.00,A,3648.17470,N,12147.27751,W,0.039,0.00,220323,,,A*73
2023-03-22T18:25:30.095Z,1679509530.095 [NAL9602](INFO): GPS fix at 20230322T182531: (36.802912, -121.787959)
2023-03-22T18:25:30.104Z,1679509530.104 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T18:25:30.104Z,1679509530.104 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T18:25:40.844Z,1679509540.844 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20230322T152039/Courier0100.lzma
2023-03-22T18:25:41.847Z,1679509541.847 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Courier0100.lzma.bak
2023-03-22T18:25:41.847Z,1679509541.847 [DataOverHttps](INFO): SBD MOMSN=17541612
2023-03-22T18:25:57.698Z,1679509557.698 [DataOverHttps](INFO): Sending 780 bytes from file Logs/20230322T152039/Express0101.lzma
2023-03-22T18:25:58.699Z,1679509558.699 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Express0101.lzma.bak
2023-03-22T18:25:58.699Z,1679509558.699 [DataOverHttps](INFO): SBD MOMSN=17541616
2023-03-22T18:25:59.782Z,1679509559.782 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T18:25:59.782Z,1679509559.782 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T18:25:59.782Z,1679509559.782 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T18:26:33.339Z,1679509593.339 [NAL9602](INFO): SBD MO Status=2, MOMSN=47467, MT Status=2, MTMSN=0
2023-03-22T18:26:33.339Z,1679509593.339 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-03-22T18:27:24.292Z,1679509644.292 [CBIT](INFO): Clearing failed state for component DVL_micro
2023-03-22T18:27:24.292Z,1679509644.292 [DVL_micro] No Fault, FailCount= 3
2023-03-22T18:27:31.145Z,1679509651.145 [NAL9602](INFO): SBD MO Status=2, MOMSN=47467, MT Status=2, MTMSN=0
2023-03-22T18:27:31.145Z,1679509651.145 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-03-22T18:27:39.756Z,1679509659.756 [DVL_micro](INFO): Failure count cleared after critical for DVL_micro
2023-03-22T18:27:51.594Z,1679509671.594 [CommandExec](IMPORTANT): got command failComponent
2023-03-22T18:27:51.594Z,1679509671.594 [CommandExec](IMPORTANT): Failed components:
2023-03-22T18:27:51.594Z,1679509671.594 [CommandExec](IMPORTANT): No failed Components.
2023-03-22T18:28:12.378Z,1679509692.378 [CommandExec](IMPORTANT): got command failComponent hardware DVL_micro
2023-03-22T18:28:12.378Z,1679509692.378 [DVL_micro] Hardware Fault, FailCount= 1
2023-03-22T18:28:12.378Z,1679509692.378 [DVL_micro](ERROR): Hardware Fault
2023-03-22T18:28:12.378Z,1679509692.378 [CommandExec](IMPORTANT): DVL_micro failureMode is Hardware Fault
2023-03-22T18:28:12.497Z,1679509692.497 [DVL_micro](INFO): Powering down
2023-03-22T18:28:12.539Z,1679509692.539 [CBIT](ERROR): Hardware Fault in component: DVL_micro
2023-03-22T18:28:13.245Z,1679509693.245 [CBIT](INFO): Clearing failed state for component DVL_micro
2023-03-22T18:28:13.246Z,1679509693.246 [DVL_micro] No Fault, FailCount= 1
2023-03-22T18:28:15.072Z,1679509695.072 [CommandExec](IMPORTANT): got command failComponent hardware DVL_micro
2023-03-22T18:28:15.072Z,1679509695.072 [DVL_micro] Hardware Fault, FailCount= 2
2023-03-22T18:28:15.072Z,1679509695.072 [DVL_micro](ERROR): Hardware Fault
2023-03-22T18:28:15.072Z,1679509695.072 [CommandExec](IMPORTANT): DVL_micro failureMode is Hardware Fault
2023-03-22T18:28:15.281Z,1679509695.281 [DVL_micro](INFO): Powering down
2023-03-22T18:28:15.331Z,1679509695.331 [CBIT](ERROR): Hardware Fault in component: DVL_micro
2023-03-22T18:28:16.044Z,1679509696.044 [CBIT](INFO): Clearing failed state for component DVL_micro
2023-03-22T18:28:16.044Z,1679509696.044 [DVL_micro] No Fault, FailCount= 2
2023-03-22T18:28:17.268Z,1679509697.268 [CommandExec](IMPORTANT): got command failComponent hardware DVL_micro
2023-03-22T18:28:17.268Z,1679509697.268 [DVL_micro] Hardware Fault, FailCount= 3
2023-03-22T18:28:17.268Z,1679509697.268 [DVL_micro](ERROR): Hardware Fault
2023-03-22T18:28:17.268Z,1679509697.268 [CommandExec](IMPORTANT): DVL_micro failureMode is Hardware Fault
2023-03-22T18:28:17.284Z,1679509697.284 [CBIT](ERROR): Hardware Fault in component: DVL_micro
2023-03-22T18:28:17.284Z,1679509697.284 [CBIT](CRITICAL): Hardware Fault in component: DVL_micro
2023-03-22T18:28:17.709Z,1679509697.709 [DVL_micro](INFO): Powering down
2023-03-22T18:28:17.752Z,1679509697.752 [CBIT](INFO): Critical error at 20230322T182817
2023-03-22T18:28:34.047Z,1679509714.047 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadB4
2023-03-22T18:28:47.183Z,1679509727.183 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadA0
2023-03-22T18:28:50.266Z,1679509730.266 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadA1
2023-03-22T18:28:53.295Z,1679509733.295 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadA2
2023-03-22T18:28:56.015Z,1679509736.015 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadA3
2023-03-22T18:28:58.107Z,1679509738.107 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadA4
2023-03-22T18:29:00.299Z,1679509740.299 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadA5
2023-03-22T18:29:02.275Z,1679509742.275 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadA6
2023-03-22T18:29:04.463Z,1679509744.463 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadA7
2023-03-22T18:29:07.511Z,1679509747.511 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadB0
2023-03-22T18:29:09.694Z,1679509749.694 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadB1
2023-03-22T18:29:11.055Z,1679509751.055 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch 30.00 deg, mass-position -15.00 mm (1 active estimators).
2023-03-22T18:29:14.103Z,1679509754.103 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadB2
2023-03-22T18:29:16.083Z,1679509756.083 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadB3
2023-03-22T18:29:16.705Z,1679509756.705 [VerticalControl](CRITICAL): Excessive depth excursion=12.946836 m, failToGoUpDepth_=1.083980 m, depthRate=0.479777 m/s, pitch=-3.784930 deg.
2023-03-22T18:29:16.891Z,1679509756.891 [CBIT](INFO): Critical error at 20230322T182916
2023-03-22T18:29:18.066Z,1679509758.066 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadB4
2023-03-22T18:29:20.880Z,1679509760.880 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadB5
2023-03-22T18:29:31.083Z,1679509771.083 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadC0
2023-03-22T18:29:33.791Z,1679509773.791 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadC1
2023-03-22T18:29:36.554Z,1679509776.554 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadC2
2023-03-22T18:29:39.120Z,1679509779.120 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadC3
2023-03-22T18:29:41.862Z,1679509781.862 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadC4
2023-03-22T18:29:43.903Z,1679509783.903 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadC5
2023-03-22T18:29:45.755Z,1679509785.755 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadC6
2023-03-22T18:29:47.235Z,1679509787.235 [VerticalControl](CRITICAL): Dropping drop weight at excessive depth excursion=21.525106, failToGoUpDepth_=1.083980, depthRate=0.283410 m/s, pitch=-3.792695 deg.
2023-03-22T18:29:47.342Z,1679509787.342 [CBIT](INFO): Critical error at 20230322T182947
2023-03-22T18:29:48.363Z,1679509788.363 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadC7
2023-03-22T18:29:49.209Z,1679509789.209 [AHRS_M2](FAULT): Failed to acquire valid data within timeout.
2023-03-22T18:29:49.209Z,1679509789.209 [AHRS_M2] Data Fault, FailCount= 1
2023-03-22T18:29:49.209Z,1679509789.209 [AHRS_M2](ERROR): Data Fault
2023-03-22T18:29:49.288Z,1679509789.288 [CBIT](ERROR): Data Fault in component: AHRS_M2
2023-03-22T18:29:49.590Z,1679509789.590 [AHRS_M2](INFO): Powering down
2023-03-22T18:29:49.998Z,1679509789.998 [AHRS_M2](FAULT): LCB fault: LCB Watchdog Reset. Invalid Command. Hardware Overcurrent Shutdown. Current Limiter Activated.
2023-03-22T18:29:49.998Z,1679509789.998 [AHRS_M2] Hardware Fault, FailCount= 1
2023-03-22T18:29:49.998Z,1679509789.998 [AHRS_M2](ERROR): Hardware Fault
2023-03-22T18:29:50.509Z,1679509790.509 [CBIT](INFO): Clearing failed state for component AHRS_M2
2023-03-22T18:29:50.509Z,1679509790.509 [AHRS_M2] No Fault, FailCount= 1
2023-03-22T18:29:50.808Z,1679509790.808 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-03-22T18:30:00.480Z,1679509800.480 [CommandExec](IMPORTANT): got command failComponent hardware DVL_micro
2023-03-22T18:30:00.481Z,1679509800.481 [CommandExec](IMPORTANT): DVL_micro failureMode is Hardware Fault
2023-03-22T18:30:02.765Z,1679509802.765 [CommandExec](IMPORTANT): got command failComponent hardware DVL_micro
2023-03-22T18:30:02.765Z,1679509802.765 [CommandExec](IMPORTANT): DVL_micro failureMode is Hardware Fault
2023-03-22T18:30:04.324Z,1679509804.324 [CommandExec](IMPORTANT): got command failComponent hardware DVL_micro
2023-03-22T18:30:04.324Z,1679509804.324 [CommandExec](IMPORTANT): DVL_micro failureMode is Hardware Fault
2023-03-22T18:30:10.630Z,1679509810.630 [Default:B.GoToSurface](ERROR): Pitch down timeout. Pitch: -3.79
2023-03-22T18:30:12.330Z,1679509812.330 [CommandExec](IMPORTANT): got command ! echo i > dev/loadB4
2023-03-22T18:30:24.615Z,1679509824.615 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadB4
2023-03-22T18:30:27.430Z,1679509827.430 [CommandExec](IMPORTANT): got command gfscan
2023-03-22T18:30:27.598Z,1679509827.598 [CBIT](IMPORTANT): Beginning ground fault scan
2023-03-22T18:30:30.009Z,1679509830.009 [Depth_Keller](ERROR): Pressure or depth reading out of range: -0.518794 decibar, -0.514967 m
2023-03-22T18:30:32.427Z,1679509832.427 [Depth_Keller](ERROR): Pressure or depth reading out of range: -0.527384 decibar, -0.523494 m
2023-03-22T18:30:32.831Z,1679509832.831 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-03-22T18:30:34.040Z,1679509834.040 [Depth_Keller](ERROR): Pressure or depth reading out of range: -0.641313 decibar, -0.636583 m
2023-03-22T18:30:35.252Z,1679509835.252 [Depth_Keller](FAULT): Pressure or depth reading out of range for max 3 samples
2023-03-22T18:30:35.252Z,1679509835.252 [Depth_Keller] Data Fault, FailCount= 1
2023-03-22T18:30:35.252Z,1679509835.252 [Depth_Keller](ERROR): Data Fault
2023-03-22T18:30:35.413Z,1679509835.413 [CBIT](ERROR): Data Fault in component: Depth_Keller
2023-03-22T18:30:35.414Z,1679509835.414 [CBIT](INFO): Clearing failed state for component Depth_Keller
2023-03-22T18:30:35.414Z,1679509835.414 [Depth_Keller] No Fault, FailCount= 0
2023-03-22T18:30:36.062Z,1679509836.062 [Depth_Keller](FAULT): Pressure or depth reading out of range for max 3 samples
2023-03-22T18:30:36.062Z,1679509836.062 [Depth_Keller] Data Fault, FailCount= 1
2023-03-22T18:30:36.062Z,1679509836.062 [Depth_Keller](ERROR): Data Fault
2023-03-22T18:30:36.277Z,1679509836.277 [CBIT](ERROR): Data Fault in component: Depth_Keller
2023-03-22T18:30:36.277Z,1679509836.277 [CBIT](INFO): Clearing failed state for component Depth_Keller
2023-03-22T18:30:36.277Z,1679509836.277 [Depth_Keller] No Fault, FailCount= 1
2023-03-22T18:30:39.106Z,1679509839.106 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.056097
CHAN A1 (24V): -0.052451
CHAN A2 (12V): 0.037300
CHAN A3 (5V): 0.010100
CHAN B0 (3.3V): 0.005757
CHAN B1 (3.15aV): 0.004998
CHAN B2 (3.15bV): 0.005443
CHAN B3 (GND): -0.004220
OPEN: 0.004473
Full Scale: +/- 1 mA
2023-03-22T18:31:00.337Z,1679509860.337 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T18:31:00.337Z,1679509860.337 [Default:CheckIn:C.Wait] Stopped
2023-03-22T18:31:00.337Z,1679509860.337 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T18:31:00.337Z,1679509860.337 [Default:CheckIn:D] Running Loop=1
2023-03-22T18:31:00.729Z,1679509860.729 [Default:CheckIn:D] Stopped
2023-03-22T18:31:00.729Z,1679509860.729 [Default:CheckIn:E] Running Loop=1
2023-03-22T18:31:01.134Z,1679509861.134 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 184.584831 min 
2023-03-22T18:31:01.134Z,1679509861.134 [Default:CheckIn:E] Stopped
2023-03-22T18:31:01.134Z,1679509861.134 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T18:31:01.134Z,1679509861.134 [Default:CheckIn] Stopped
2023-03-22T18:31:01.134Z,1679509861.134 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T18:31:01.135Z,1679509861.135 [Default:CheckIn](INFO): Running loop #31
2023-03-22T18:31:01.135Z,1679509861.135 [Default:CheckIn] Running Loop=31
2023-03-22T18:31:01.135Z,1679509861.135 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T18:31:01.135Z,1679509861.135 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T18:31:03.153Z,1679509863.153 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183104.00,A,3648.17322,N,12147.27741,W,0.058,0.00,220323,,,A*76
2023-03-22T18:31:03.155Z,1679509863.155 [NAL9602](INFO): GPS fix at 20230322T183104: (36.802887, -121.787957)
2023-03-22T18:31:03.164Z,1679509863.164 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T18:31:03.164Z,1679509863.164 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T18:31:06.544Z,1679509866.544 [MassServo](ERROR): getPosition uart error serial timeout
2023-03-22T18:31:06.544Z,1679509866.544 [MassServo](FAULT): Invalid EZ Servo response:"\377"
2023-03-22T18:31:06.572Z,1679509866.572 [MassServo] Communications Fault, FailCount= 1
2023-03-22T18:31:06.572Z,1679509866.572 [MassServo](ERROR): Communications Fault
2023-03-22T18:31:06.605Z,1679509866.605 [CBIT](ERROR): Communications Fault in component: MassServo
2023-03-22T18:31:06.849Z,1679509866.849 [MassServo](DEBUG): Uninitialize Mass Servo.
2023-03-22T18:31:06.849Z,1679509866.849 [MassServo](INFO): Powering down
2023-03-22T18:31:07.684Z,1679509867.684 [MassServo](DEBUG): Initializing EZServoServo.
2023-03-22T18:31:07.802Z,1679509867.802 [MassServo](DEBUG): Initializing MassServo.
2023-03-22T18:31:07.809Z,1679509867.809 [CBIT](INFO): Clearing failed state for component MassServo
2023-03-22T18:31:07.809Z,1679509867.809 [MassServo] No Fault, FailCount= 1
2023-03-22T18:31:10.385Z,1679509870.385 [DataOverHttps](INFO): Sending 307 bytes from file Logs/20230322T152039/Courier0103.lzma
2023-03-22T18:31:11.387Z,1679509871.387 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Courier0103.lzma.bak
2023-03-22T18:31:11.387Z,1679509871.387 [DataOverHttps](INFO): SBD MOMSN=17541681
2023-03-22T18:31:12.542Z,1679509872.542 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadB7
2023-03-22T18:31:17.415Z,1679509877.415 [CBIT](INFO): Clearing failed state for component DVL_micro
2023-03-22T18:31:17.415Z,1679509877.415 [DVL_micro] No Fault, FailCount= 3
2023-03-22T18:31:27.390Z,1679509887.390 [DataOverHttps](INFO): Sending 985 bytes from file Logs/20230322T152039/Express0104.lzma
2023-03-22T18:31:28.391Z,1679509888.391 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Express0104.lzma.bak
2023-03-22T18:31:28.391Z,1679509888.391 [DataOverHttps](INFO): SBD MOMSN=17541687
2023-03-22T18:31:29.459Z,1679509889.459 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T18:31:29.459Z,1679509889.459 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T18:31:29.459Z,1679509889.459 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T18:31:35.155Z,1679509895.155 [DVL_micro](FAULT): Failed to initialize within timeout.
2023-03-22T18:31:35.155Z,1679509895.155 [DVL_micro] Communications Fault, FailCount= 1
2023-03-22T18:31:35.155Z,1679509895.155 [DVL_micro](ERROR): Communications Fault
2023-03-22T18:31:35.302Z,1679509895.302 [CBIT](ERROR): Communications Fault in component: DVL_micro
2023-03-22T18:31:35.665Z,1679509895.665 [DVL_micro](INFO): Powering down
2023-03-22T18:31:35.667Z,1679509895.667 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T18:31:36.503Z,1679509896.503 [CBIT](INFO): Clearing failed state for component DVL_micro
2023-03-22T18:31:36.504Z,1679509896.504 [DVL_micro] No Fault, FailCount= 1
2023-03-22T18:31:36.650Z,1679509896.650 [CommandExec](IMPORTANT): got command burn off
2023-03-22T18:31:36.650Z,1679509896.650 [CommandExec](IMPORTANT): Deactivating dropweight wire
2023-03-22T18:31:54.121Z,1679509914.121 [DVL_micro](FAULT): Failed to initialize within timeout.
2023-03-22T18:31:54.121Z,1679509914.121 [DVL_micro] Communications Fault, FailCount= 2
2023-03-22T18:31:54.121Z,1679509914.121 [DVL_micro](ERROR): Communications Fault
2023-03-22T18:31:54.189Z,1679509914.189 [CBIT](ERROR): Communications Fault in component: DVL_micro
2023-03-22T18:31:54.593Z,1679509914.593 [DVL_micro](INFO): Powering down
2023-03-22T18:31:55.403Z,1679509915.403 [CBIT](INFO): Clearing failed state for component DVL_micro
2023-03-22T18:31:55.403Z,1679509915.403 [DVL_micro] No Fault, FailCount= 2
2023-03-22T18:32:13.104Z,1679509933.104 [DVL_micro](FAULT): Failed to initialize within timeout.
2023-03-22T18:32:13.105Z,1679509933.105 [DVL_micro] Communications Fault, FailCount= 3
2023-03-22T18:32:13.105Z,1679509933.105 [DVL_micro](ERROR): Communications Fault
2023-03-22T18:32:13.123Z,1679509933.123 [CBIT](ERROR): Communications Fault in component: DVL_micro
2023-03-22T18:32:13.123Z,1679509933.123 [CBIT](CRITICAL): Communications Fault in component: DVL_micro
2023-03-22T18:32:13.589Z,1679509933.589 [DVL_micro](INFO): Powering down
2023-03-22T18:32:13.607Z,1679509933.607 [CBIT](INFO): Critical error at 20230322T183213
2023-03-22T18:32:23.667Z,1679509943.667 [CommandExec](IMPORTANT): got command get depth
2023-03-22T18:32:23.667Z,1679509943.667 [CommandExec](IMPORTANT): depth -0.146082 m
2023-03-22T18:35:13.498Z,1679510113.498 [CBIT](INFO): Clearing failed state for component DVL_micro
2023-03-22T18:35:13.498Z,1679510113.498 [DVL_micro] No Fault, FailCount= 3
2023-03-22T18:35:31.253Z,1679510131.253 [DVL_micro](FAULT): Failed to initialize within timeout.
2023-03-22T18:35:31.253Z,1679510131.253 [DVL_micro] Communications Fault, FailCount= 1
2023-03-22T18:35:31.253Z,1679510131.253 [DVL_micro](ERROR): Communications Fault
2023-03-22T18:35:31.280Z,1679510131.280 [CBIT](ERROR): Communications Fault in component: DVL_micro
2023-03-22T18:35:31.745Z,1679510131.745 [DVL_micro](INFO): Powering down
2023-03-22T18:35:32.495Z,1679510132.495 [CBIT](INFO): Clearing failed state for component DVL_micro
2023-03-22T18:35:32.495Z,1679510132.495 [DVL_micro] No Fault, FailCount= 1
2023-03-22T18:35:42.027Z,1679510142.027 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadB7
2023-03-22T18:35:43.898Z,1679510143.898 [CommandExec](IMPORTANT): got command gfscan
2023-03-22T18:35:44.223Z,1679510144.223 [CBIT](IMPORTANT): Beginning ground fault scan
2023-03-22T18:35:50.269Z,1679510150.269 [DVL_micro](FAULT): Failed to initialize within timeout.
2023-03-22T18:35:50.269Z,1679510150.269 [DVL_micro] Communications Fault, FailCount= 2
2023-03-22T18:35:50.269Z,1679510150.269 [DVL_micro](ERROR): Communications Fault
2023-03-22T18:35:50.288Z,1679510150.288 [CBIT](ERROR): Communications Fault in component: DVL_micro
2023-03-22T18:35:50.741Z,1679510150.741 [DVL_micro](INFO): Powering down
2023-03-22T18:35:51.516Z,1679510151.516 [CBIT](INFO): Clearing failed state for component DVL_micro
2023-03-22T18:35:51.517Z,1679510151.517 [DVL_micro] No Fault, FailCount= 2
2023-03-22T18:35:55.135Z,1679510155.135 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.094687
CHAN A1 (24V): -0.185927
CHAN A2 (12V): 0.054506
CHAN A3 (5V): 0.001466
CHAN B0 (3.3V): -0.000928
CHAN B1 (3.15aV): 0.000610
CHAN B2 (3.15bV): 0.002755
CHAN B3 (GND): -0.014599
OPEN: 0.006900
Full Scale: +/- 1 mA
2023-03-22T18:36:03.360Z,1679510163.360 [CommandExec](IMPORTANT): got command failComponent hardware DVL_micro
2023-03-22T18:36:03.360Z,1679510163.360 [DVL_micro] Hardware Fault, FailCount= 3
2023-03-22T18:36:03.360Z,1679510163.360 [DVL_micro](ERROR): Hardware Fault
2023-03-22T18:36:03.361Z,1679510163.361 [CommandExec](IMPORTANT): DVL_micro failureMode is Hardware Fault
2023-03-22T18:36:03.665Z,1679510163.665 [DVL_micro](INFO): Powering down
2023-03-22T18:36:03.690Z,1679510163.690 [CBIT](ERROR): Hardware Fault in component: DVL_micro
2023-03-22T18:36:03.691Z,1679510163.691 [CBIT](CRITICAL): Hardware Fault in component: DVL_micro
2023-03-22T18:36:04.030Z,1679510164.030 [CBIT](INFO): Critical error at 20230322T183603
2023-03-22T18:36:12.312Z,1679510172.312 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadB4
2023-03-22T18:36:17.206Z,1679510177.206 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadB7
2023-03-22T18:36:21.386Z,1679510181.386 [CommandExec](IMPORTANT): got command gfscan
2023-03-22T18:36:21.420Z,1679510181.420 [CBIT](IMPORTANT): Beginning ground fault scan
2023-03-22T18:36:29.866Z,1679510189.866 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T18:36:29.866Z,1679510189.866 [Default:CheckIn:C.Wait] Stopped
2023-03-22T18:36:29.866Z,1679510189.866 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T18:36:29.866Z,1679510189.866 [Default:CheckIn:D] Running Loop=1
2023-03-22T18:36:30.270Z,1679510190.270 [Default:CheckIn:D] Stopped
2023-03-22T18:36:30.270Z,1679510190.270 [Default:CheckIn:E] Running Loop=1
2023-03-22T18:36:30.694Z,1679510190.694 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 190.077181 min 
2023-03-22T18:36:30.694Z,1679510190.694 [Default:CheckIn:E] Stopped
2023-03-22T18:36:30.694Z,1679510190.694 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T18:36:30.694Z,1679510190.694 [Default:CheckIn] Stopped
2023-03-22T18:36:30.694Z,1679510190.694 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T18:36:30.694Z,1679510190.694 [Default:CheckIn](INFO): Running loop #32
2023-03-22T18:36:30.694Z,1679510190.694 [Default:CheckIn] Running Loop=32
2023-03-22T18:36:30.695Z,1679510190.695 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T18:36:30.695Z,1679510190.695 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T18:36:32.368Z,1679510192.368 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.050851
CHAN A1 (24V): -0.168703
CHAN A2 (12V): 0.034746
CHAN A3 (5V): 0.009665
CHAN B0 (3.3V): 0.005799
CHAN B1 (3.15aV): 0.005361
CHAN B2 (3.15bV): 0.005802
CHAN B3 (GND): -0.004093
OPEN: 0.004546
Full Scale: +/- 1 mA
2023-03-22T18:37:03.097Z,1679510223.097 [NAL9602](ERROR): getFix uart error: serial timeout
2023-03-22T18:37:33.463Z,1679510253.463 [NAL9602](ERROR): parseGSV uart error: serial timeout
2023-03-22T18:37:33.862Z,1679510253.862 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-03-22T18:37:34.381Z,1679510254.381 [NAL9602](ERROR): received: 
2023-03-22T18:37:36.115Z,1679510256.115 [CommandExec](IMPORTANT): got command show variable missingstick
2023-03-22T18:37:36.166Z,1679510256.166 [CommandExec](IMPORTANT): BPC1.batteryMissingStickThreshold (count)
2023-03-22T18:37:51.359Z,1679510271.359 [CommandExec](IMPORTANT): got command get BPC1.batteryMissingStickThreshold
2023-03-22T18:37:51.360Z,1679510271.360 [CommandExec](IMPORTANT): BPC1.batteryMissingStickThreshold 0 count
2023-03-22T18:38:04.805Z,1679510284.805 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-03-22T18:38:05.329Z,1679510285.329 [NAL9602](ERROR): received: 
2023-03-22T18:38:35.673Z,1679510315.673 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-03-22T18:38:36.197Z,1679510316.197 [NAL9602](ERROR): received: 
2023-03-22T18:38:52.342Z,1679510332.342 [CommandExec](IMPORTANT): got command restart application
2023-03-22T18:38:53.345Z,1679510333.345 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2023-03-22T18:38:53.345Z,1679510333.345 [CommandExec](INFO): Uninitializing the command executive.
2023-03-22T18:38:53.345Z,1679510333.345 [CommandExec](INFO): Uninitializing the command scheduler.
2023-03-22T18:38:53.346Z,1679510333.346 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-03-22T18:38:53.449Z,1679510333.449 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2023-03-22T18:38:53.449Z,1679510333.449 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2023-03-22T18:38:53.449Z,1679510333.449 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-03-22T18:38:53.450Z,1679510333.450 [NavChartDb](INFO): Join timeout helper Thread ID is 7373
2023-03-22T18:38:53.558Z,1679510333.558 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2023-03-22T18:38:53.559Z,1679510333.559 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-03-22T18:38:53.569Z,1679510333.569 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler
2023-03-22T18:38:53.569Z,1679510333.569 [DAT ThreadHandler](INFO): Thread cancelled.
2023-03-22T18:38:53.570Z,1679510333.570 [DAT](INFO): Join timeout helper Thread ID is 7374
2023-03-22T18:38:53.749Z,1679510333.749 [DAT](INFO): Powering down
2023-03-22T18:38:53.818Z,1679510333.818 [DAT ThreadHandler](INFO): Uninitializing protected caller thread.
2023-03-22T18:38:53.818Z,1679510333.818 [DAT](INFO): Powering down
2023-03-22T18:38:53.819Z,1679510333.819 [DAT ThreadHandler](INFO): Thread cancelled.
2023-03-22T18:38:53.829Z,1679510333.829 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2023-03-22T18:38:53.829Z,1679510333.829 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-03-22T18:38:53.829Z,1679510333.829 [Radio_Surface](INFO): Join timeout helper Thread ID is 7375
2023-03-22T18:38:54.021Z,1679510334.021 [Radio_Surface](INFO): Powering down
2023-03-22T18:38:54.022Z,1679510334.022 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2023-03-22T18:38:54.022Z,1679510334.022 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-03-22T18:38:54.038Z,1679510334.038 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2023-03-22T18:38:54.038Z,1679510334.038 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-03-22T18:38:54.038Z,1679510334.038 [Onboard](INFO): Join timeout helper Thread ID is 7376
2023-03-22T18:38:54.161Z,1679510334.161 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2023-03-22T18:38:55.129Z,1679510335.129 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2023-03-22T18:38:55.129Z,1679510335.129 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-03-22T18:38:55.145Z,1679510335.145 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2023-03-22T18:38:55.145Z,1679510335.145 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-03-22T18:38:55.145Z,1679510335.145 [DataOverHttps](INFO): Join timeout helper Thread ID is 7377
2023-03-22T18:38:55.165Z,1679510335.165 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2023-03-22T18:38:55.166Z,1679510335.166 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-03-22T18:38:55.169Z,1679510335.169 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2023-03-22T18:38:55.169Z,1679510335.169 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-03-22T18:38:55.170Z,1679510335.170 [BackseatComponent](INFO): Join timeout helper Thread ID is 7378
2023-03-22T18:38:55.185Z,1679510335.185 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2023-03-22T18:38:55.186Z,1679510335.186 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-03-22T18:38:55.194Z,1679510335.194 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2023-03-22T18:38:55.194Z,1679510335.194 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-03-22T18:38:55.194Z,1679510335.194 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 7379
2023-03-22T18:38:55.449Z,1679510335.449 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2023-03-22T18:38:55.449Z,1679510335.449 [WetLabsBB2FL](INFO): Powering down
2023-03-22T18:38:55.450Z,1679510335.450 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-03-22T18:38:55.470Z,1679510335.470 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2023-03-22T18:38:55.470Z,1679510335.470 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-03-22T18:38:55.470Z,1679510335.470 [CTD_Seabird](INFO): Join timeout helper Thread ID is 7380
2023-03-22T18:38:56.329Z,1679510336.329 [CTD_Seabird](INFO): Powering down
2023-03-22T18:38:56.341Z,1679510336.341 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2023-03-22T18:38:56.341Z,1679510336.341 [CTD_Seabird](INFO): Powering down
2023-03-22T18:38:56.353Z,1679510336.353 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-03-22T18:38:56.370Z,1679510336.370 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2023-03-22T18:38:56.370Z,1679510336.370 [logger ThreadHandler](INFO): Thread cancelled.
2023-03-22T18:38:56.370Z,1679510336.370 [logger](INFO): Join timeout helper Thread ID is 7381
2023-03-22T18:38:56.373Z,1679510336.373 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2023-03-22T18:38:56.373Z,1679510336.373 [logger ThreadHandler](INFO): Thread cancelled.
2023-03-22T18:38:56.390Z,1679510336.390 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2023-03-22T18:38:56.390Z,1679510336.390 [CommandLine ThreadHandler](INFO): Thread cancelled.
2023-03-22T18:38:56.390Z,1679510336.390 [CommandLine](INFO): Join timeout helper Thread ID is 7382
2023-03-22T18:38:56.393Z,1679510336.393 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2023-03-22T18:38:56.393Z,1679510336.393 [CommandLine ThreadHandler](INFO): Thread cancelled.
2023-03-22T18:38:56.410Z,1679510336.410 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2023-03-22T18:38:56.410Z,1679510336.410 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-03-22T18:38:56.410Z,1679510336.410 [CommandExec](INFO): Join timeout helper Thread ID is 7383
2023-03-22T18:38:56.411Z,1679510336.411 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2023-03-22T18:38:56.411Z,1679510336.411 [controlThread ThreadHandler](INFO): Thread cancelled.
2023-03-22T18:38:56.412Z,1679510336.412 [controlThread](INFO): Join timeout helper Thread ID is 7384
2023-03-22T18:38:56.457Z,1679510336.457 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2023-03-22T18:38:56.457Z,1679510336.457 [controlThread](DEBUG): Uninitializing ControlThread
2023-03-22T18:38:56.458Z,1679510336.458 [AHRS_M2](INFO): Powering down
2023-03-22T18:38:56.530Z,1679510336.530 [DVL_micro](INFO): Powering down
2023-03-22T18:38:56.531Z,1679510336.531 [MultiRay](INFO): Powering down.
2023-03-22T18:38:56.532Z,1679510336.532 [NAL9602](INFO): Powering down
2023-03-22T18:38:56.533Z,1679510336.533 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2023-03-22T18:38:56.534Z,1679510336.534 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2023-03-22T18:38:56.535Z,1679510336.535 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2023-03-22T18:38:56.535Z,1679510336.535 [MissionManager](INFO): Uninitializing Mission Default
2023-03-22T18:38:56.535Z,1679510336.535 [Default] Stopped
2023-03-22T18:38:56.535Z,1679510336.535 [Default](DEBUG): Aggregate::uninitialize Default
2023-03-22T18:38:56.536Z,1679510336.536 [Default:B.GoToSurface] Stopped
2023-03-22T18:38:56.536Z,1679510336.536 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-03-22T18:38:56.536Z,1679510336.536 [Default:CheckIn] Stopped
2023-03-22T18:38:56.536Z,1679510336.536 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T18:38:56.536Z,1679510336.536 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T18:38:56.539Z,1679510336.539 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2023-03-22T18:38:56.539Z,1679510336.539 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2023-03-22T18:38:56.539Z,1679510336.539 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2023-03-22T18:38:56.539Z,1679510336.539 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2023-03-22T18:38:56.540Z,1679510336.540 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2023-03-22T18:38:56.540Z,1679510336.540 [BuoyancyServo](INFO): Powering down
2023-03-22T18:38:56.553Z,1679510336.553 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2023-03-22T18:38:56.553Z,1679510336.553 [ElevatorServo](INFO): Powering down
2023-03-22T18:38:56.554Z,1679510336.554 [MassServo](DEBUG): Uninitialize Mass Servo.
2023-03-22T18:38:56.554Z,1679510336.554 [MassServo](INFO): Powering down
2023-03-22T18:38:56.555Z,1679510336.555 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2023-03-22T18:38:56.555Z,1679510336.555 [RudderServo](INFO): Powering down
2023-03-22T18:38:56.556Z,1679510336.556 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2023-03-22T18:38:56.556Z,1679510336.556 [ThrusterHE](INFO): Powering down
2023-03-22T18:38:56.557Z,1679510336.557 [SBIT](DEBUG): Uninitialize SBIT Component.
2023-03-22T18:38:56.557Z,1679510336.557 [IBIT](DEBUG): Uninitialize IBIT Component.
2023-03-22T18:38:56.558Z,1679510336.558 [CBIT](DEBUG): Uninitialize CBIT Component.
2023-03-22T18:38:56.558Z,1679510336.558 [CBIT](DEBUG): Powering off loads.
2023-03-22T18:38:56.569Z,1679510336.569 [CBIT](DEBUG): Disabling WDT.
2023-03-22T18:38:56.581Z,1679510336.581 [CBIT](DEBUG): Opening all GF detection circuits.
2023-03-22T18:38:56.582Z,1679510336.582 [controlThread ThreadHandler](INFO): Thread cancelled.
2023-03-22T18:38:56.622Z,1679510336.622 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-03-22T18:38:56.627Z,1679510336.627 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-03-22T18:38:56.657Z,1679510336.657 [DAT ThreadHandler](INFO): Thread cancelled.
2023-03-22T18:38:56.661Z,1679510336.661 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-03-22T18:38:56.663Z,1679510336.663 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-03-22T18:38:56.671Z,1679510336.671 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-03-22T18:38:56.715Z,1679510336.715 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-03-22T18:38:56.767Z,1679510336.767 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-03-22T18:38:56.836Z,1679510336.836 [logger ThreadHandler](INFO): Thread cancelled.