2021-10-07T16:16:03.406Z,1633623363.406 [Supervisor](DEBUG): Initializing supervisor.
2021-10-07T16:16:03.411Z,1633623363.411 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2021-10-07T16:16:03.412Z,1633623363.412 [SyncHandler](INFO): Protected caller Thread ID is 1184
2021-10-07T16:16:03.412Z,1633623363.412 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2021-10-07T16:16:03.413Z,1633623363.413 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2021-10-07T16:16:03.413Z,1633623363.413 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1185
2021-10-07T16:16:03.418Z,1633623363.418 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2021-10-07T16:16:03.436Z,1633623363.436 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2021-10-07T16:16:03.437Z,1633623363.437 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2021-10-07T16:16:03.437Z,1633623363.437 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 1186
2021-10-07T16:16:03.441Z,1633623363.441 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2021-10-07T16:16:03.442Z,1633623363.442 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2021-10-07T16:16:03.443Z,1633623363.443 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1187
2021-10-07T16:16:03.445Z,1633623363.445 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2021-10-07T16:16:03.446Z,1633623363.446 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2021-10-07T16:16:03.446Z,1633623363.446 [logger ThreadHandler](INFO): Protected caller Thread ID is 1188
2021-10-07T16:16:03.450Z,1633623363.450 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2021-10-07T16:16:03.451Z,1633623363.451 [Supervisor](INFO): Looking for Config files in directory: Config/
2021-10-07T16:16:03.452Z,1633623363.452 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2021-10-07T16:16:03.549Z,1633623363.549 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2021-10-07T16:16:03.549Z,1633623363.549 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2021-10-07T16:16:04.128Z,1633623364.128 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2021-10-07T16:16:04.128Z,1633623364.128 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2021-10-07T16:16:04.340Z,1633623364.340 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2021-10-07T16:16:04.340Z,1633623364.340 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2021-10-07T16:16:04.419Z,1633623364.419 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2021-10-07T16:16:04.543Z,1633623364.543 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2021-10-07T16:16:04.543Z,1633623364.543 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2021-10-07T16:16:04.624Z,1633623364.624 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2021-10-07T16:16:04.730Z,1633623364.730 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2021-10-07T16:16:04.731Z,1633623364.731 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2021-10-07T16:16:05.085Z,1633623365.085 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2021-10-07T16:16:05.086Z,1633623365.086 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2021-10-07T16:16:05.602Z,1633623365.602 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2021-10-07T16:16:05.603Z,1633623365.603 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2021-10-07T16:16:05.749Z,1633623365.749 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2021-10-07T16:16:05.750Z,1633623365.750 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2021-10-07T16:16:05.935Z,1633623365.935 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2021-10-07T16:16:05.936Z,1633623365.936 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2021-10-07T16:16:06.380Z,1633623366.380 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2021-10-07T16:16:06.380Z,1633623366.380 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2021-10-07T16:16:06.616Z,1633623366.616 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2021-10-07T16:16:06.617Z,1633623366.617 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2021-10-07T16:16:06.818Z,1633623366.818 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2021-10-07T16:16:06.819Z,1633623366.819 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2021-10-07T16:16:07.178Z,1633623367.178 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2021-10-07T16:16:07.179Z,1633623367.179 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2021-10-07T16:16:07.510Z,1633623367.510 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2021-10-07T16:16:07.512Z,1633623367.512 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/
2021-10-07T16:16:07.513Z,1633623367.513 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg
2021-10-07T16:16:07.709Z,1633623367.709 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg
2021-10-07T16:16:07.980Z,1633623367.980 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg
2021-10-07T16:16:08.194Z,1633623368.194 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg
2021-10-07T16:16:08.447Z,1633623368.447 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg
2021-10-07T16:16:08.540Z,1633623368.540 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg
2021-10-07T16:16:08.723Z,1633623368.723 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg
2021-10-07T16:16:08.980Z,1633623368.980 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2021-10-07T16:16:08.981Z,1633623368.981 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg
2021-10-07T16:16:09.074Z,1633623369.074 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg
2021-10-07T16:16:09.172Z,1633623369.172 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg
2021-10-07T16:16:09.310Z,1633623369.310 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg
2021-10-07T16:16:09.409Z,1633623369.409 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/root/
2021-10-07T16:16:09.410Z,1633623369.410 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2021-10-07T16:16:09.417Z,1633623369.417 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2021-10-07T16:16:09.516Z,1633623369.516 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2021-10-07T16:16:09.516Z,1633623369.516 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2021-10-07T16:16:09.570Z,1633623369.570 [VerticalControl](DEBUG): Construct VerticalControl.
2021-10-07T16:16:09.632Z,1633623369.632 [VerticalControl] Loaded
2021-10-07T16:16:09.633Z,1633623369.633 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2021-10-07T16:16:09.635Z,1633623369.635 [HorizontalControl](DEBUG): Construct HorizontalControl.
2021-10-07T16:16:09.674Z,1633623369.674 [HorizontalControl] Loaded
2021-10-07T16:16:09.674Z,1633623369.674 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2021-10-07T16:16:09.677Z,1633623369.677 [SpeedControl](DEBUG): Construct SpeedControl.
2021-10-07T16:16:09.680Z,1633623369.680 [SpeedControl] Loaded
2021-10-07T16:16:09.680Z,1633623369.680 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2021-10-07T16:16:09.683Z,1633623369.683 [LoopControl](DEBUG): Construct LoopControl.
2021-10-07T16:16:09.683Z,1633623369.683 [LoopControl] Loaded
2021-10-07T16:16:09.684Z,1633623369.684 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2021-10-07T16:16:09.684Z,1633623369.684 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2021-10-07T16:16:09.684Z,1633623369.684 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2021-10-07T16:16:09.727Z,1633623369.727 [DepthRateCalculator] Loaded
2021-10-07T16:16:09.727Z,1633623369.727 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2021-10-07T16:16:09.732Z,1633623369.732 [PitchRateCalculator] Loaded
2021-10-07T16:16:09.732Z,1633623369.732 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2021-10-07T16:16:09.742Z,1633623369.742 [SpeedCalculator] Loaded
2021-10-07T16:16:09.743Z,1633623369.743 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2021-10-07T16:16:09.756Z,1633623369.756 [TempGradientCalculator] Loaded
2021-10-07T16:16:09.756Z,1633623369.756 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2021-10-07T16:16:09.761Z,1633623369.761 [YawRateCalculator] Loaded
2021-10-07T16:16:09.761Z,1633623369.761 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2021-10-07T16:16:09.778Z,1633623369.778 [ElevatorOffsetCalculator] Loaded
2021-10-07T16:16:09.778Z,1633623369.778 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2021-10-07T16:16:09.779Z,1633623369.779 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2021-10-07T16:16:09.779Z,1633623369.779 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2021-10-07T16:16:09.808Z,1633623369.808 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2021-10-07T16:16:09.809Z,1633623369.809 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2021-10-07T16:16:09.867Z,1633623369.867 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2021-10-07T16:16:09.867Z,1633623369.867 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2021-10-07T16:16:10.195Z,1633623370.195 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2021-10-07T16:16:10.195Z,1633623370.195 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2021-10-07T16:16:10.301Z,1633623370.301 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2021-10-07T16:16:10.302Z,1633623370.302 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2021-10-07T16:16:10.692Z,1633623370.692 [AHRS_M2] Loaded
2021-10-07T16:16:10.692Z,1633623370.692 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2021-10-07T16:16:10.721Z,1633623370.721 [BackseatComponent] Loaded
2021-10-07T16:16:10.722Z,1633623370.722 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2021-10-07T16:16:10.723Z,1633623370.723 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 4093B4E0
2021-10-07T16:16:10.723Z,1633623370.723 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 1270
2021-10-07T16:16:10.726Z,1633623370.726 [LcmUniversalReporter] Loaded
2021-10-07T16:16:10.726Z,1633623370.726 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2021-10-07T16:16:11.507Z,1633623371.507 [BPC1] Loaded
2021-10-07T16:16:11.507Z,1633623371.507 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2021-10-07T16:16:11.581Z,1633623371.581 [DataOverHttps] Loaded
2021-10-07T16:16:11.581Z,1633623371.581 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2021-10-07T16:16:11.582Z,1633623371.582 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4096B4E0
2021-10-07T16:16:11.583Z,1633623371.583 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1271
2021-10-07T16:16:11.602Z,1633623371.602 [Depth_Keller] Loaded
2021-10-07T16:16:11.603Z,1633623371.603 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2021-10-07T16:16:11.607Z,1633623371.607 [DropWeight] Loaded
2021-10-07T16:16:11.608Z,1633623371.608 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2021-10-07T16:16:11.667Z,1633623371.667 [NAL9602] Loaded
2021-10-07T16:16:11.667Z,1633623371.667 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2021-10-07T16:16:11.696Z,1633623371.696 [Onboard] Loaded
2021-10-07T16:16:11.696Z,1633623371.696 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2021-10-07T16:16:11.697Z,1633623371.697 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4099B4E0
2021-10-07T16:16:11.698Z,1633623371.698 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 1272
2021-10-07T16:16:11.710Z,1633623371.710 [Power24vConverter] Loaded
2021-10-07T16:16:11.711Z,1633623371.711 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2021-10-07T16:16:11.723Z,1633623371.723 [Radio_Surface] Loaded
2021-10-07T16:16:11.724Z,1633623371.724 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2021-10-07T16:16:11.725Z,1633623371.725 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409CB4E0
2021-10-07T16:16:11.725Z,1633623371.725 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1273
2021-10-07T16:16:11.768Z,1633623371.768 [RDI_Pathfinder] Loaded
2021-10-07T16:16:11.768Z,1633623371.768 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2021-10-07T16:16:11.769Z,1633623371.769 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2021-10-07T16:16:11.769Z,1633623371.769 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2021-10-07T16:16:11.848Z,1633623371.848 [DeadReckonUsingMultipleVelocitySources] Loaded
2021-10-07T16:16:11.849Z,1633623371.849 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2021-10-07T16:16:11.862Z,1633623371.862 [NavChart] Loaded
2021-10-07T16:16:11.862Z,1633623371.862 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2021-10-07T16:16:11.868Z,1633623371.868 [UniversalFixResidualReporter] Loaded
2021-10-07T16:16:11.868Z,1633623371.868 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2021-10-07T16:16:11.869Z,1633623371.869 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2021-10-07T16:16:11.869Z,1633623371.869 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2021-10-07T16:16:12.016Z,1633623372.016 [SBIT](DEBUG): Construct Startup Built In Test.
2021-10-07T16:16:12.025Z,1633623372.025 [SBIT] Loaded
2021-10-07T16:16:12.025Z,1633623372.025 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2021-10-07T16:16:12.028Z,1633623372.028 [IBIT](DEBUG): Construct Initiated Built In Test.
2021-10-07T16:16:12.041Z,1633623372.041 [IBIT] Loaded
2021-10-07T16:16:12.041Z,1633623372.041 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2021-10-07T16:16:12.047Z,1633623372.047 [CBIT](DEBUG): Construct Continuous Built In Test.
2021-10-07T16:16:12.147Z,1633623372.147 [CBIT] Loaded
2021-10-07T16:16:12.147Z,1633623372.147 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2021-10-07T16:16:12.147Z,1633623372.147 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2021-10-07T16:16:12.148Z,1633623372.148 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2021-10-07T16:16:12.480Z,1633623372.480 [BuoyancyServo] Loaded
2021-10-07T16:16:12.480Z,1633623372.480 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2021-10-07T16:16:12.566Z,1633623372.566 [ElevatorServo] Loaded
2021-10-07T16:16:12.566Z,1633623372.566 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2021-10-07T16:16:12.681Z,1633623372.681 [MassServo] Loaded
2021-10-07T16:16:12.681Z,1633623372.681 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2021-10-07T16:16:12.702Z,1633623372.702 [RudderServo] Loaded
2021-10-07T16:16:12.702Z,1633623372.702 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2021-10-07T16:16:12.719Z,1633623372.719 [ThrusterServo] Loaded
2021-10-07T16:16:12.720Z,1633623372.720 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2021-10-07T16:16:12.720Z,1633623372.720 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2021-10-07T16:16:12.721Z,1633623372.721 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2021-10-07T16:16:12.767Z,1633623372.767 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2021-10-07T16:16:12.768Z,1633623372.768 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2021-10-07T16:16:13.187Z,1633623373.187 [CTD_Seabird] Loaded
2021-10-07T16:16:13.187Z,1633623373.187 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2021-10-07T16:16:13.200Z,1633623373.200 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40B044E0
2021-10-07T16:16:13.201Z,1633623373.201 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1274
2021-10-07T16:16:13.237Z,1633623373.237 [PAR_Licor] Loaded
2021-10-07T16:16:13.238Z,1633623373.238 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2021-10-07T16:16:13.270Z,1633623373.270 [WetLabsBB2FL] Loaded
2021-10-07T16:16:13.271Z,1633623373.271 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2021-10-07T16:16:13.272Z,1633623373.272 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40B344E0
2021-10-07T16:16:13.272Z,1633623373.272 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1275
2021-10-07T16:16:13.292Z,1633623373.292 [WetLabsUBAT] Loaded
2021-10-07T16:16:13.293Z,1633623373.293 [ComponentRegistry](DEBUG): Component "WetLabsUBAT" handled in its own thread.
2021-10-07T16:16:13.294Z,1633623373.294 [WetLabsUBAT ThreadHandler](DEBUG): Created PCaller Thread at 40B644E0
2021-10-07T16:16:13.294Z,1633623373.294 [WetLabsUBAT ThreadHandler](INFO): Protected caller Thread ID is 1276
2021-10-07T16:16:13.295Z,1633623373.295 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2021-10-07T16:16:13.301Z,1633623373.301 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2021-10-07T16:16:13.304Z,1633623373.304 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2021-10-07T16:16:13.314Z,1633623373.314 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2021-10-07T16:16:13.315Z,1633623373.315 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B944E0
2021-10-07T16:16:13.316Z,1633623373.316 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1277
2021-10-07T16:16:13.320Z,1633623373.320 [Supervisor](INFO): Main Thread ID is 833
2021-10-07T16:16:13.321Z,1633623373.321 [Supervisor](DEBUG): Running supervisor.
2021-10-07T16:16:13.321Z,1633623373.321 [CommandExec ThreadHandler](INFO): Handler Thread ID is 1278
2021-10-07T16:16:13.322Z,1633623373.322 [CommandExec](INFO): Initializing the command executive.
2021-10-07T16:16:13.323Z,1633623373.323 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1279
2021-10-07T16:16:13.327Z,1633623373.327 [controlThread ThreadHandler](INFO): Handler Thread ID is 1280
2021-10-07T16:16:13.327Z,1633623373.327 [controlThread](DEBUG): Initializing ControlThread
2021-10-07T16:16:13.328Z,1633623373.328 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2021-10-07T16:16:13.330Z,1633623373.330 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2021-10-07T16:16:13.331Z,1633623373.331 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2021-10-07T16:16:13.331Z,1633623373.331 [LoopControl](DEBUG): Initialize LoopControlComponent.
2021-10-07T16:16:13.332Z,1633623373.332 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2021-10-07T16:16:13.332Z,1633623373.332 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2021-10-07T16:16:13.332Z,1633623373.332 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2021-10-07T16:16:13.333Z,1633623373.333 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2021-10-07T16:16:13.333Z,1633623373.333 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2021-10-07T16:16:13.334Z,1633623373.334 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2021-10-07T16:16:13.342Z,1633623373.342 [NavChart](DEBUG): Initialize NavChart Navigation.
2021-10-07T16:16:13.342Z,1633623373.342 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2021-10-07T16:16:13.343Z,1633623373.343 [SBIT](INFO): Initialize SBIT Component.
2021-10-07T16:16:13.344Z,1633623373.344 [SBIT](IMPORTANT): git: 2021-10-07
2021-10-07T16:16:13.344Z,1633623373.344 [SBIT](INFO): git hash: 51b3ba56a881ceedc3f3cac81267d645fb41da2c
2021-10-07T16:16:13.344Z,1633623373.344 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2021-10-07T16:16:13.345Z,1633623373.345 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2021-10-07T16:16:13.346Z,1633623373.346 [SBIT](INFO): Beginning SBIT in 55.000000 seconds.
2021-10-07T16:16:13.347Z,1633623373.347 [IBIT](INFO): Initialize IBIT Component.
2021-10-07T16:16:13.348Z,1633623373.348 [CBIT](DEBUG): Initialize CBIT Component.
2021-10-07T16:16:13.349Z,1633623373.349 [logger ThreadHandler](INFO): Handler Thread ID is 1281
2021-10-07T16:16:13.360Z,1633623373.360 [CBIT](DEBUG): Initialized mux pins.
2021-10-07T16:16:13.360Z,1633623373.360 [CBIT](DEBUG): Initializing the watchdog timer.
2021-10-07T16:16:13.368Z,1633623373.368 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 1282
2021-10-07T16:16:13.380Z,1633623373.380 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1283
2021-10-07T16:16:13.381Z,1633623373.381 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2021-10-07T16:16:13.384Z,1633623373.384 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2021-10-07T16:16:13.384Z,1633623373.384 [CBIT](DEBUG): Initializing heartbeat.
2021-10-07T16:16:13.392Z,1633623373.392 [Onboard ThreadHandler](INFO): Handler Thread ID is 1284
2021-10-07T16:16:13.409Z,1633623373.409 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1285
2021-10-07T16:16:13.428Z,1633623373.428 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1286
2021-10-07T16:16:13.429Z,1633623373.429 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2021-10-07T16:16:13.433Z,1633623373.433 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1288
2021-10-07T16:16:13.436Z,1633623373.436 [WetLabsBB2FL](INFO): Powering up
2021-10-07T16:16:13.437Z,1633623373.437 [WetLabsUBAT ThreadHandler](INFO): Handler Thread ID is 1290
2021-10-07T16:16:13.440Z,1633623373.440 [WetLabsUBAT](INFO): Powering up
2021-10-07T16:16:13.441Z,1633623373.441 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1292
2021-10-07T16:16:13.445Z,1633623373.445 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2021-10-07T16:16:13.445Z,1633623373.445 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2021-10-07T16:16:13.445Z,1633623373.445 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2021-10-07T16:16:13.445Z,1633623373.445 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2021-10-07T16:16:13.446Z,1633623373.446 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2021-10-07T16:16:13.446Z,1633623373.446 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2021-10-07T16:16:13.446Z,1633623373.446 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2021-10-07T16:16:13.446Z,1633623373.446 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2021-10-07T16:16:13.446Z,1633623373.446 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2021-10-07T16:16:13.447Z,1633623373.447 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2021-10-07T16:16:13.447Z,1633623373.447 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2021-10-07T16:16:13.447Z,1633623373.447 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2021-10-07T16:16:13.447Z,1633623373.447 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2021-10-07T16:16:13.447Z,1633623373.447 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2021-10-07T16:16:13.447Z,1633623373.447 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2021-10-07T16:16:13.448Z,1633623373.448 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2021-10-07T16:16:13.456Z,1633623373.456 [CBIT](DEBUG): Deactivating GF circuits.
2021-10-07T16:16:13.456Z,1633623373.456 [CBIT](DEBUG): Deactivating emergency mode.
2021-10-07T16:16:13.491Z,1633623373.491 [CBIT](DEBUG): Backplane powered.
2021-10-07T16:16:13.496Z,1633623373.496 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2021-10-07T16:16:13.518Z,1633623373.518 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2021-10-07T16:16:13.562Z,1633623373.562 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

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

    <Aggregate Id="StartupSatComms">

        <Sequence/>

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

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

    </Aggregate>

</Mission>


2021-10-07T16:16:13.563Z,1633623373.563 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2021-10-07T16:16:13.638Z,1633623373.638 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2021-10-07T16:16:13.639Z,1633623373.639 [Default:A.Wait](DEBUG): Construct Wait.
2021-10-07T16:16:13.642Z,1633623373.642 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2021-10-07T16:16:13.686Z,1633623373.686 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2021-10-07T16:16:13.705Z,1633623373.705 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2021-10-07T16:16:13.711Z,1633623373.711 [Default:E.Execute](DEBUG): Construct Execute.
2021-10-07T16:16:13.726Z,1633623373.726 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

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

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

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

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

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

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

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

    </Aggregate>

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

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

</Mission>


2021-10-07T16:16:13.731Z,1633623373.731 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,RDI_Pathfinder,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2021-10-07T16:16:13.756Z,1633623373.756 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2021-10-07T16:16:13.824Z,1633623373.824 [Radio_Surface](INFO): Powering up
2021-10-07T16:16:13.827Z,1633623373.827 [Power24vConverter](INFO): Powering up.
2021-10-07T16:16:13.890Z,1633623373.890 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2021-10-07T16:16:13.904Z,1633623373.904 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2021-10-07T16:16:13.905Z,1633623373.905 [ElevatorServo](DEBUG): Initializing EZServoServo.
2021-10-07T16:16:13.912Z,1633623373.912 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2021-10-07T16:16:13.913Z,1633623373.913 [MassServo](DEBUG): Initializing EZServoServo.
2021-10-07T16:16:13.920Z,1633623373.920 [MassServo](DEBUG): Initializing MassServo.
2021-10-07T16:16:13.921Z,1633623373.921 [RudderServo](DEBUG): Initializing EZServoServo.
2021-10-07T16:16:13.936Z,1633623373.936 [RudderServo](DEBUG): Initializing RudderServo.
2021-10-07T16:16:13.937Z,1633623373.937 [ThrusterServo](DEBUG): Initializing EZServoServo.
2021-10-07T16:16:13.944Z,1633623373.944 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2021-10-07T16:16:14.888Z,1633623374.888 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2021-10-07T16:16:14.888Z,1633623374.888 [RudderServo](FAULT): Rudder failed to initialize
2021-10-07T16:16:14.888Z,1633623374.888 [RudderServo] Communications Fault, FailCount= 1
2021-10-07T16:16:14.888Z,1633623374.888 [RudderServo](ERROR): Communications Fault
2021-10-07T16:16:14.988Z,1633623374.988 [CBIT](ERROR): Communications Fault in component: RudderServo
2021-10-07T16:16:15.169Z,1633623375.169 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2021-10-07T16:16:15.169Z,1633623375.169 [RudderServo](INFO): Powering down
2021-10-07T16:16:15.833Z,1633623375.833 [RudderServo](DEBUG): Initializing EZServoServo.
2021-10-07T16:16:15.953Z,1633623375.953 [RudderServo](DEBUG): Initializing RudderServo.
2021-10-07T16:16:15.957Z,1633623375.957 [CBIT](INFO): Clearing failed state for component RudderServo
2021-10-07T16:16:15.957Z,1633623375.957 [RudderServo] No Fault, FailCount= 1
2021-10-07T16:16:16.048Z,1633623376.048 [WetLabsBB2FL](INFO): Powering down
2021-10-07T16:16:20.464Z,1633623380.464 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2021-10-07T16:16:22.712Z,1633623382.712 [WetLabsUBAT](INFO): Powering down
2021-10-07T16:16:36.013Z,1633623396.013 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2021-10-07T16:16:36.013Z,1633623396.013 [RDI_Pathfinder] Communications Fault, FailCount= 1
2021-10-07T16:16:36.013Z,1633623396.013 [RDI_Pathfinder](ERROR): Communications Fault
2021-10-07T16:16:36.092Z,1633623396.092 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2021-10-07T16:16:36.497Z,1633623396.497 [RDI_Pathfinder](INFO): Powering down
2021-10-07T16:16:37.296Z,1633623397.296 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-10-07T16:16:37.296Z,1633623397.296 [RDI_Pathfinder] No Fault, FailCount= 1
2021-10-07T16:16:41.673Z,1633623401.673 [NAL9602](INFO): Powering up NAL9602
2021-10-07T16:16:52.577Z,1633623412.577 [NAL9602](INFO): NAL9602 initialized
2021-10-07T16:16:59.850Z,1633623419.850 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2021-10-07T16:16:59.850Z,1633623419.850 [RDI_Pathfinder] Communications Fault, FailCount= 2
2021-10-07T16:16:59.850Z,1633623419.850 [RDI_Pathfinder](ERROR): Communications Fault
2021-10-07T16:16:59.883Z,1633623419.883 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2021-10-07T16:17:00.320Z,1633623420.320 [RDI_Pathfinder](INFO): Powering down
2021-10-07T16:17:01.118Z,1633623421.118 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-10-07T16:17:01.118Z,1633623421.118 [RDI_Pathfinder] No Fault, FailCount= 2
2021-10-07T16:17:08.767Z,1633623428.767 [SBIT](IMPORTANT): Beginning Startup BIT
2021-10-07T16:17:08.772Z,1633623428.772 [CBIT](IMPORTANT): Beginning ground fault scan
2021-10-07T16:17:19.756Z,1633623439.756 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.010999
CHAN A1 (24V): -0.165264
CHAN A2 (12V): -0.007832
CHAN A3 (5V): -0.002243
CHAN B0 (3.3V): 0.000432
CHAN B1 (3.15aV): -0.000390
CHAN B2 (3.15bV): -0.000522
CHAN B3 (GND): 0.002480
OPEN: 0.004144
Full Scale: +/- 1 mA
2021-10-07T16:17:23.703Z,1633623443.703 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2021-10-07T16:17:23.703Z,1633623443.703 [RDI_Pathfinder] Communications Fault, FailCount= 3
2021-10-07T16:17:23.703Z,1633623443.703 [RDI_Pathfinder](ERROR): Communications Fault
2021-10-07T16:17:23.864Z,1633623443.864 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2021-10-07T16:17:23.865Z,1633623443.865 [CBIT](CRITICAL): Communications Fault in component: RDI_Pathfinder
2021-10-07T16:17:24.156Z,1633623444.156 [RDI_Pathfinder](INFO): Powering down
2021-10-07T16:17:24.322Z,1633623444.322 [CommandExec](FAULT): Scheduling is paused
2021-10-07T16:17:24.323Z,1633623444.323 [CBIT](INFO): Critical error at 20211007T161723
2021-10-07T16:17:24.323Z,1633623444.323 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2021-10-07T16:17:50.362Z,1633623470.362 [NAL9602](INFO): SBD MO Status=2, MOMSN=16157, MT Status=2, MTMSN=0
2021-10-07T16:17:50.362Z,1633623470.362 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-10-07T16:18:02.496Z,1633623482.496 [SBIT](IMPORTANT): SBIT PASSED
2021-10-07T16:18:02.496Z,1633623482.496 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2021-10-07T16:18:02.497Z,1633623482.497 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=6 count;

2021-10-07T16:18:02.497Z,1633623482.497 [SBIT](IMPORTANT): CBIT.gf24Offset=143 microampere;

2021-10-07T16:18:02.497Z,1633623482.497 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool;

2021-10-07T16:18:02.497Z,1633623482.497 [SBIT](IMPORTANT): IBIT.batteryCapacityThreshold=24 ampere_hour;

2021-10-07T16:18:02.498Z,1633623482.498 [SBIT](IMPORTANT): IBIT.batteryVoltageThreshold=13 volt;

2021-10-07T16:18:02.498Z,1633623482.498 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=231.913961 cubic_centimeter;

2021-10-07T16:18:02.498Z,1633623482.498 [SBIT](IMPORTANT): VerticalControl.massDefault=8.903467 millimeter;

2021-10-07T16:18:02.890Z,1633623482.890 [MissionManager](IMPORTANT): Started mission Startup
2021-10-07T16:18:02.891Z,1633623482.891 [Startup] Running Loop=1
2021-10-07T16:18:02.891Z,1633623482.891 [Startup](DEBUG): Aggregate::initialize Startup
2021-10-07T16:18:02.891Z,1633623482.891 [Startup:A.GoToSurface] Running Loop=1
2021-10-07T16:18:02.891Z,1633623482.891 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-10-07T16:18:02.892Z,1633623482.892 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-10-07T16:18:02.892Z,1633623482.892 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-10-07T16:18:02.893Z,1633623482.893 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-10-07T16:18:02.893Z,1633623482.893 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-10-07T16:18:02.893Z,1633623482.893 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-10-07T16:18:02.895Z,1633623482.895 [Startup:StartupSatComms] Running Loop=1
2021-10-07T16:18:02.895Z,1633623482.895 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2021-10-07T16:18:02.895Z,1633623482.895 [Startup:StartupSatComms:A] Running Loop=1
2021-10-07T16:18:03.294Z,1633623483.294 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2021-10-07T16:18:07.727Z,1633623487.727 [NAL9602](INFO): SBD MO Status=2, MOMSN=16157, MT Status=2, MTMSN=0
2021-10-07T16:18:07.728Z,1633623487.728 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-10-07T16:19:03.082Z,1633623543.082 [Startup:StartupSatComms:A](INFO): Timed out from 2021-10-07T16:18:02.9Z
2021-10-07T16:19:03.083Z,1633623543.083 [Startup:StartupSatComms:A] Stopped
2021-10-07T16:19:03.083Z,1633623543.083 [Startup:StartupSatComms:B] Running Loop=1
2021-10-07T16:19:03.490Z,1633623543.490 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-10-07T16:19:13.597Z,1633623553.597 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2021-10-07T16:19:13.597Z,1633623553.597 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-10-07T16:19:13.608Z,1633623553.608 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-10-07T16:19:14.003Z,1633623554.003 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-10-07T16:19:14.003Z,1633623554.003 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2021-10-07T16:19:36.458Z,1633623576.458 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004474
2021-10-07T16:19:43.652Z,1633623583.652 [DataOverHttps](INFO): Sending 201 bytes from file Logs/20211007T160641/Courier0007.lzma
2021-10-07T16:19:44.654Z,1633623584.654 [DataOverHttps](INFO): Moved sent file to Logs/20211007T160641/Courier0007.lzma.bak
2021-10-07T16:19:44.654Z,1633623584.654 [DataOverHttps](INFO): SBD MOMSN=15978061
2021-10-07T16:20:01.564Z,1633623601.564 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20211007T161603/Courier0000.lzma
2021-10-07T16:20:03.324Z,1633623603.324 [DataOverHttps](INFO): Moved sent file to Logs/20211007T161603/Courier0000.lzma.bak
2021-10-07T16:20:03.324Z,1633623603.324 [DataOverHttps](INFO): SBD MOMSN=15978064
2021-10-07T16:20:03.384Z,1633623603.384 [Startup:StartupSatComms:B](INFO): Timed out from 2021-10-07T16:19:03.1Z
2021-10-07T16:20:03.384Z,1633623603.384 [Startup:StartupSatComms:B] Stopped
2021-10-07T16:20:03.384Z,1633623603.384 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2021-10-07T16:20:03.384Z,1633623603.384 [Startup:StartupSatComms] Stopped
2021-10-07T16:20:03.384Z,1633623603.384 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2021-10-07T16:20:03.385Z,1633623603.385 [Startup](INFO): Completed Startup
2021-10-07T16:20:03.385Z,1633623603.385 [MissionManager](INFO): Startup is completed.
2021-10-07T16:20:03.386Z,1633623603.386 [MissionManager](INFO): Uninitializing Mission Startup
2021-10-07T16:20:03.386Z,1633623603.386 [Startup] Stopped
2021-10-07T16:20:03.386Z,1633623603.386 [Startup](DEBUG): Aggregate::uninitialize Startup
2021-10-07T16:20:03.386Z,1633623603.386 [Startup:A.GoToSurface] Stopped
2021-10-07T16:20:03.386Z,1633623603.386 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-10-07T16:20:03.723Z,1633623603.723 [MissionManager](IMPORTANT): Started mission Default
2021-10-07T16:20:03.723Z,1633623603.723 [Default] Running Loop=1
2021-10-07T16:20:03.723Z,1633623603.723 [Default](DEBUG): Aggregate::initialize Default
2021-10-07T16:20:03.723Z,1633623603.723 [Default:B.GoToSurface] Running Loop=1
2021-10-07T16:20:03.724Z,1633623603.724 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-10-07T16:20:03.724Z,1633623603.724 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-10-07T16:20:03.724Z,1633623603.724 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-10-07T16:20:03.725Z,1633623603.725 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-10-07T16:20:03.725Z,1633623603.725 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-10-07T16:20:03.725Z,1633623603.725 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-10-07T16:20:03.725Z,1633623603.725 [Default:A.Wait] Running Loop=1
2021-10-07T16:20:03.726Z,1633623603.726 [Default:A.Wait](DEBUG): Initialize Wait Component.
2021-10-07T16:20:17.086Z,1633623617.086 [Default:A.Wait](INFO): Done Waiting.
2021-10-07T16:20:17.086Z,1633623617.086 [Default:A.Wait] Stopped
2021-10-07T16:20:17.087Z,1633623617.087 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2021-10-07T16:20:17.480Z,1633623617.480 [Default:CheckIn] Running Loop=1
2021-10-07T16:20:17.480Z,1633623617.480 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-07T16:20:17.480Z,1633623617.480 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-07T16:20:17.886Z,1633623617.886 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2021-10-07T16:20:23.972Z,1633623623.972 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-10-07T16:20:23.972Z,1633623623.972 [RDI_Pathfinder] No Fault, FailCount= 3
2021-10-07T16:20:34.448Z,1633623634.448 [NAL9602](INFO): SBD MO Status=2, MOMSN=16157, MT Status=2, MTMSN=0
2021-10-07T16:20:34.448Z,1633623634.448 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-10-07T16:20:36.866Z,1633623636.866 [RDI_Pathfinder](FAULT): DVL failed to acquire valid data within timeout.
2021-10-07T16:20:36.866Z,1633623636.866 [RDI_Pathfinder] Data Fault, FailCount= 1
2021-10-07T16:20:36.866Z,1633623636.866 [RDI_Pathfinder](ERROR): Data Fault
2021-10-07T16:20:36.908Z,1633623636.908 [CBIT](ERROR): Data Fault in component: RDI_Pathfinder
2021-10-07T16:20:37.340Z,1633623637.340 [RDI_Pathfinder](INFO): Powering down
2021-10-07T16:20:38.105Z,1633623638.105 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-10-07T16:20:38.105Z,1633623638.105 [RDI_Pathfinder] No Fault, FailCount= 1
2021-10-07T16:20:54.775Z,1633623654.775 [NAL9602](INFO): SBD MO Status=0, MOMSN=16157, MT Status=0, MTMSN=0
2021-10-07T16:20:54.775Z,1633623654.775 [NAL9602](INFO): No messages in MT queue
2021-10-07T16:21:00.834Z,1633623660.834 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2021-10-07T16:21:00.834Z,1633623660.834 [RDI_Pathfinder] Communications Fault, FailCount= 2
2021-10-07T16:21:00.834Z,1633623660.834 [RDI_Pathfinder](ERROR): Communications Fault
2021-10-07T16:21:00.852Z,1633623660.852 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2021-10-07T16:21:01.308Z,1633623661.308 [RDI_Pathfinder](INFO): Powering down
2021-10-07T16:21:02.089Z,1633623662.089 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-10-07T16:21:02.089Z,1633623662.089 [RDI_Pathfinder] No Fault, FailCount= 2
2021-10-07T16:21:24.668Z,1633623684.668 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2021-10-07T16:21:24.668Z,1633623684.668 [RDI_Pathfinder] Communications Fault, FailCount= 3
2021-10-07T16:21:24.668Z,1633623684.668 [RDI_Pathfinder](ERROR): Communications Fault
2021-10-07T16:21:24.686Z,1633623684.686 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2021-10-07T16:21:24.687Z,1633623684.687 [CBIT](CRITICAL): Communications Fault in component: RDI_Pathfinder
2021-10-07T16:21:25.144Z,1633623685.144 [RDI_Pathfinder](INFO): Powering down
2021-10-07T16:21:25.183Z,1633623685.183 [CBIT](INFO): Critical error at 20211007T162124
2021-10-07T16:22:14.393Z,1633623734.393 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2021-10-07T16:22:14.393Z,1633623734.393 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-10-07T16:22:14.404Z,1633623734.404 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-10-07T16:22:14.775Z,1633623734.775 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-10-07T16:22:14.775Z,1633623734.775 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2021-10-07T16:24:04.249Z,1633623844.249 [BPC1](INFO): Calculating totals. Valid battery stick count: 52. Valid reserve battery stick count: 6.
2021-10-07T16:24:04.253Z,1633623844.253 [BPC1](INFO): Received data from all battery sticks.
2021-10-07T16:24:24.926Z,1633623864.926 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-10-07T16:24:24.926Z,1633623864.926 [RDI_Pathfinder] No Fault, FailCount= 3
2021-10-07T16:24:37.848Z,1633623877.848 [RDI_Pathfinder](FAULT): DVL failed to acquire valid data within timeout.
2021-10-07T16:24:37.848Z,1633623877.848 [RDI_Pathfinder] Data Fault, FailCount= 1
2021-10-07T16:24:37.848Z,1633623877.848 [RDI_Pathfinder](ERROR): Data Fault
2021-10-07T16:24:37.889Z,1633623877.889 [CBIT](ERROR): Data Fault in component: RDI_Pathfinder
2021-10-07T16:24:38.316Z,1633623878.316 [RDI_Pathfinder](INFO): Powering down
2021-10-07T16:24:39.059Z,1633623879.059 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-10-07T16:24:39.059Z,1633623879.059 [RDI_Pathfinder] No Fault, FailCount= 1
2021-10-07T16:25:01.680Z,1633623901.680 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2021-10-07T16:25:01.681Z,1633623901.681 [RDI_Pathfinder] Communications Fault, FailCount= 2
2021-10-07T16:25:01.681Z,1633623901.681 [RDI_Pathfinder](ERROR): Communications Fault
2021-10-07T16:25:01.727Z,1633623901.727 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2021-10-07T16:25:02.156Z,1633623902.156 [RDI_Pathfinder](INFO): Powering down
2021-10-07T16:25:02.911Z,1633623902.911 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-10-07T16:25:02.911Z,1633623902.911 [RDI_Pathfinder] No Fault, FailCount= 2
2021-10-07T16:25:13.791Z,1633623913.791 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162512.00,A,3648.13040,N,12147.24557,W,2.274,123.22,071021,,,A*76
2021-10-07T16:25:13.795Z,1633623913.795 [NAL9602](INFO): GPS fix at 20211007T162512: (36.802173, -121.787426)
2021-10-07T16:25:13.806Z,1633623913.806 [Default:CheckIn:Read_GPS] Stopped
2021-10-07T16:25:13.806Z,1633623913.806 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-07T16:25:14.217Z,1633623914.217 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-10-07T16:25:23.739Z,1633623923.739 [DataOverHttps](INFO): Sending 336 bytes from file Logs/20211007T161603/Courier0004.lzma
2021-10-07T16:25:24.743Z,1633623924.743 [DataOverHttps](INFO): Moved sent file to Logs/20211007T161603/Courier0004.lzma.bak
2021-10-07T16:25:24.743Z,1633623924.743 [DataOverHttps](INFO): SBD MOMSN=15978076
2021-10-07T16:25:25.508Z,1633623925.508 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2021-10-07T16:25:25.508Z,1633623925.508 [RDI_Pathfinder] Communications Fault, FailCount= 3
2021-10-07T16:25:25.508Z,1633623925.508 [RDI_Pathfinder](ERROR): Communications Fault
2021-10-07T16:25:25.532Z,1633623925.532 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2021-10-07T16:25:25.532Z,1633623925.532 [CBIT](CRITICAL): Communications Fault in component: RDI_Pathfinder
2021-10-07T16:25:25.980Z,1633623925.980 [RDI_Pathfinder](INFO): Powering down
2021-10-07T16:25:26.041Z,1633623926.041 [CBIT](INFO): Critical error at 20211007T162525
2021-10-07T16:25:44.836Z,1633623944.836 [DataOverHttps](INFO): Sending 974 bytes from file Logs/20211007T160641/Express0008.lzma
2021-10-07T16:25:45.837Z,1633623945.837 [DataOverHttps](INFO): Moved sent file to Logs/20211007T160641/Express0008.lzma.bak
2021-10-07T16:25:45.838Z,1633623945.838 [DataOverHttps](INFO): SBD MOMSN=15978080
2021-10-07T16:25:46.515Z,1633623946.515 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-07T16:26:03.248Z,1633623963.248 [DataOverHttps](INFO): Sending 861 bytes from file Logs/20211007T161603/Express0001.lzma
2021-10-07T16:26:04.249Z,1633623964.249 [DataOverHttps](INFO): Moved sent file to Logs/20211007T161603/Express0001.lzma.bak
2021-10-07T16:26:04.249Z,1633623964.249 [DataOverHttps](INFO): SBD MOMSN=15978116
2021-10-07T16:26:27.163Z,1633623987.163 [DataOverHttps](INFO): Sending 300 bytes from file Logs/20211007T161603/Express0005.lzma
2021-10-07T16:26:28.165Z,1633623988.165 [DataOverHttps](INFO): Moved sent file to Logs/20211007T161603/Express0005.lzma.bak
2021-10-07T16:26:28.165Z,1633623988.165 [DataOverHttps](INFO): SBD MOMSN=15978136
2021-10-07T16:26:30.674Z,1633623990.674 [Default:CheckIn:Read_Iridium] Stopped
2021-10-07T16:26:30.674Z,1633623990.674 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-07T16:26:30.674Z,1633623990.674 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-07T16:26:37.509Z,1633623997.509 [Power24vConverter](INFO): Powering down.
2021-10-07T16:28:25.829Z,1633624105.829 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-10-07T16:28:25.829Z,1633624105.829 [RDI_Pathfinder] No Fault, FailCount= 3
2021-10-07T16:28:26.596Z,1633624106.596 [Power24vConverter](INFO): Powering up.
2021-10-07T16:28:38.711Z,1633624118.711 [RDI_Pathfinder](FAULT): DVL failed to acquire valid data within timeout.
2021-10-07T16:28:38.711Z,1633624118.711 [RDI_Pathfinder] Data Fault, FailCount= 1
2021-10-07T16:28:38.711Z,1633624118.711 [RDI_Pathfinder](ERROR): Data Fault
2021-10-07T16:28:38.839Z,1633624118.839 [CBIT](ERROR): Data Fault in component: RDI_Pathfinder
2021-10-07T16:28:39.192Z,1633624119.192 [RDI_Pathfinder](INFO): Powering down
2021-10-07T16:28:39.971Z,1633624119.971 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-10-07T16:28:39.971Z,1633624119.971 [RDI_Pathfinder] No Fault, FailCount= 1
2021-10-07T16:29:02.546Z,1633624142.546 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2021-10-07T16:29:02.546Z,1633624142.546 [RDI_Pathfinder] Communications Fault, FailCount= 2
2021-10-07T16:29:02.546Z,1633624142.546 [RDI_Pathfinder](ERROR): Communications Fault
2021-10-07T16:29:02.566Z,1633624142.566 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2021-10-07T16:29:03.028Z,1633624143.028 [RDI_Pathfinder](INFO): Powering down
2021-10-07T16:29:03.813Z,1633624143.813 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-10-07T16:29:03.813Z,1633624143.813 [RDI_Pathfinder] No Fault, FailCount= 2
2021-10-07T16:29:26.385Z,1633624166.385 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2021-10-07T16:29:26.386Z,1633624166.386 [RDI_Pathfinder] Communications Fault, FailCount= 3
2021-10-07T16:29:26.386Z,1633624166.386 [RDI_Pathfinder](ERROR): Communications Fault
2021-10-07T16:29:26.434Z,1633624166.434 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2021-10-07T16:29:26.435Z,1633624166.435 [CBIT](CRITICAL): Communications Fault in component: RDI_Pathfinder
2021-10-07T16:29:26.864Z,1633624166.864 [RDI_Pathfinder](INFO): Powering down
2021-10-07T16:29:26.893Z,1633624166.893 [CBIT](INFO): Critical error at 20211007T162926
2021-10-07T16:31:31.239Z,1633624291.239 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-07T16:31:31.239Z,1633624291.239 [Default:CheckIn:C.Wait] Stopped
2021-10-07T16:31:31.239Z,1633624291.239 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-07T16:31:31.239Z,1633624291.239 [Default:CheckIn:D] Running Loop=1
2021-10-07T16:31:31.297Z,1633624291.297 [DataOverHttps](IMPORTANT): SBD MTMSN=20211007T163130
2021-10-07T16:31:31.633Z,1633624291.633 [Default:CheckIn:D] Stopped
2021-10-07T16:31:31.633Z,1633624291.633 [Default:CheckIn:E] Running Loop=1
2021-10-07T16:31:32.048Z,1633624292.048 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.465160 min 
2021-10-07T16:31:32.048Z,1633624292.048 [Default:CheckIn:E] Stopped
2021-10-07T16:31:32.049Z,1633624292.049 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-07T16:31:32.049Z,1633624292.049 [Default:CheckIn] Stopped
2021-10-07T16:31:32.049Z,1633624292.049 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-07T16:31:32.049Z,1633624292.049 [Default:CheckIn](INFO): Running loop #2
2021-10-07T16:31:32.049Z,1633624292.049 [Default:CheckIn] Running Loop=2
2021-10-07T16:31:32.049Z,1633624292.049 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-07T16:31:32.049Z,1633624292.049 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-07T16:31:34.048Z,1633624294.048 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163133.00,A,3648.11932,N,12147.23134,W,0.039,143.44,071021,,,D*72
2021-10-07T16:31:34.050Z,1633624294.050 [NAL9602](INFO): GPS fix at 20211007T163133: (36.801989, -121.787189)
2021-10-07T16:31:34.061Z,1633624294.061 [Default:CheckIn:Read_GPS] Stopped
2021-10-07T16:31:34.061Z,1633624294.061 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-07T16:31:38.890Z,1633624298.890 [DataOverHttps](INFO): Sending 135 bytes from file Logs/20211007T161603/Courier0007.lzma
2021-10-07T16:31:38.893Z,1633624298.893 [DataOverHttps](INFO): Received command: ibit
2021-10-07T16:31:38.916Z,1633624298.916 [CommandExec](IMPORTANT): got command ibit
2021-10-07T16:31:38.988Z,1633624298.988 [IBIT](IMPORTANT): Beginning Initiated BIT
2021-10-07T16:31:38.988Z,1633624298.988 [IBIT](IMPORTANT): Beginning control surface checks.
2021-10-07T16:31:38.996Z,1633624298.996 [CBIT](IMPORTANT): Beginning ground fault scan
2021-10-07T16:31:39.254Z,1633624299.254 [DataOverHttps](INFO): Moved sent file to Logs/20211007T161603/Courier0007.lzma.bak
2021-10-07T16:31:39.254Z,1633624299.254 [DataOverHttps](INFO): SBD MOMSN=15978152
2021-10-07T16:31:49.956Z,1633624309.956 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.010420
CHAN A1 (24V): -0.167336
CHAN A2 (12V): -0.007377
CHAN A3 (5V): -0.002077
CHAN B0 (3.3V): 0.000397
CHAN B1 (3.15aV): -0.000060
CHAN B2 (3.15bV): -0.000185
CHAN B3 (GND): 0.001741
OPEN: 0.004156
Full Scale: +/- 1 mA
2021-10-07T16:31:55.927Z,1633624315.927 [NAL9602](INFO): SBD MO Status=2, MOMSN=16158, MT Status=2, MTMSN=0
2021-10-07T16:31:55.927Z,1633624315.927 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-10-07T16:31:57.212Z,1633624317.212 [DataOverHttps](INFO): Sending 260 bytes from file Logs/20211007T161603/Express0008.lzma
2021-10-07T16:31:58.213Z,1633624318.213 [DataOverHttps](INFO): Moved sent file to Logs/20211007T161603/Express0008.lzma.bak
2021-10-07T16:31:58.213Z,1633624318.213 [DataOverHttps](INFO): SBD MOMSN=15978158
2021-10-07T16:32:17.054Z,1633624337.054 [NAL9602](INFO): SBD MO Status=0, MOMSN=16158, MT Status=0, MTMSN=0
2021-10-07T16:32:17.054Z,1633624337.054 [NAL9602](INFO): No messages in MT queue
2021-10-07T16:32:18.267Z,1633624338.267 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163217.00,A,3648.11908,N,12147.23121,W,0.058,143.44,071021,,,D*7D
2021-10-07T16:32:18.269Z,1633624338.269 [NAL9602](INFO): GPS fix at 20211007T163217: (36.801985, -121.787187)
2021-10-07T16:32:21.099Z,1633624341.099 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163220.00,A,3648.11913,N,12147.23117,W,0.019,143.44,071021,,,D*73
2021-10-07T16:32:21.101Z,1633624341.101 [NAL9602](INFO): GPS fix at 20211007T163220: (36.801986, -121.787186)
2021-10-07T16:32:21.523Z,1633624341.523 [DataOverHttps](INFO): Sending 182 bytes from file Logs/20211007T161603/Express0011.lzma
2021-10-07T16:32:22.525Z,1633624342.525 [DataOverHttps](INFO): Moved sent file to Logs/20211007T161603/Express0011.lzma.bak
2021-10-07T16:32:22.525Z,1633624342.525 [DataOverHttps](INFO): SBD MOMSN=15978163
2021-10-07T16:32:23.923Z,1633624343.923 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163223.00,A,3648.11917,N,12147.23127,W,0.039,143.44,071021,,,D*75
2021-10-07T16:32:23.944Z,1633624343.944 [NAL9602](INFO): GPS fix at 20211007T163223: (36.801986, -121.787188)
2021-10-07T16:32:24.824Z,1633624344.824 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 2
Latitude: 36.801987 Longitude: -121.787186
2021-10-07T16:32:25.159Z,1633624345.159 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 15.937000
2021-10-07T16:32:25.159Z,1633624345.159 [IBIT](IMPORTANT): batteryCapacityThreshold: 24.000000 Ah
2021-10-07T16:32:25.160Z,1633624345.160 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.000000 V
2021-10-07T16:32:25.591Z,1633624345.591 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2021-10-07T16:32:25.596Z,1633624345.596 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2021-10-07T16:32:25.597Z,1633624345.597 [IBIT](IMPORTANT): Pressure:7.567537 PSI
2021-10-07T16:32:25.598Z,1633624345.598 [IBIT](IMPORTANT): Humidity:21.407642 %
2021-10-07T16:32:25.999Z,1633624345.999 [IBIT](IMPORTANT): Vehicle Pitch:0.296338 degrees
2021-10-07T16:32:25.000Z,1633624346.000 [IBIT](IMPORTANT): Vehicle  Roll:-26.035673 degrees
2021-10-07T16:32:26.000Z,1633624346.000 [IBIT](IMPORTANT): Vehicle  Heading:294.033783 degrees
2021-10-07T16:32:26.382Z,1633624346.382 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2021-10-07T16:32:26.382Z,1633624346.382 [IBIT](IMPORTANT): buoyancyNeutral: 231.913956 cc
2021-10-07T16:32:26.382Z,1633624346.382 [IBIT](IMPORTANT): massDefault: 0.890347 cm
2021-10-07T16:32:26.383Z,1633624346.383 [IBIT](IMPORTANT): stopDepth: 215.000000 m
2021-10-07T16:32:26.383Z,1633624346.383 [IBIT](IMPORTANT): abortDepth: 255.000000 m
2021-10-07T16:32:26.383Z,1633624346.383 [IBIT](IMPORTANT): IBIT PASSED
2021-10-07T16:32:26.432Z,1633624346.432 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-10-07T16:32:26.432Z,1633624346.432 [RDI_Pathfinder] No Fault, FailCount= 3
2021-10-07T16:32:26.804Z,1633624346.804 [Default:CheckIn:Read_Iridium] Stopped
2021-10-07T16:32:26.804Z,1633624346.804 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-07T16:32:26.804Z,1633624346.804 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-07T16:32:39.311Z,1633624359.311 [RDI_Pathfinder](FAULT): DVL failed to acquire valid data within timeout.
2021-10-07T16:32:39.311Z,1633624359.311 [RDI_Pathfinder] Data Fault, FailCount= 1
2021-10-07T16:32:39.311Z,1633624359.311 [RDI_Pathfinder](ERROR): Data Fault
2021-10-07T16:32:39.393Z,1633624359.393 [CBIT](ERROR): Data Fault in component: RDI_Pathfinder
2021-10-07T16:32:39.748Z,1633624359.748 [RDI_Pathfinder](INFO): Powering down
2021-10-07T16:32:40.506Z,1633624360.506 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-10-07T16:32:40.506Z,1633624360.506 [RDI_Pathfinder] No Fault, FailCount= 1
2021-10-07T16:32:56.245Z,1633624376.245 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-07T16:33:03.115Z,1633624383.115 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2021-10-07T16:33:03.115Z,1633624383.115 [RDI_Pathfinder] Communications Fault, FailCount= 2
2021-10-07T16:33:03.116Z,1633624383.116 [RDI_Pathfinder](ERROR): Communications Fault
2021-10-07T16:33:03.135Z,1633624383.135 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2021-10-07T16:33:03.592Z,1633624383.592 [RDI_Pathfinder](INFO): Powering down
2021-10-07T16:33:04.367Z,1633624384.367 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-10-07T16:33:04.367Z,1633624384.367 [RDI_Pathfinder] No Fault, FailCount= 2
2021-10-07T16:33:26.955Z,1633624406.955 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2021-10-07T16:33:26.955Z,1633624406.955 [RDI_Pathfinder] Communications Fault, FailCount= 3
2021-10-07T16:33:26.955Z,1633624406.955 [RDI_Pathfinder](ERROR): Communications Fault
2021-10-07T16:33:26.977Z,1633624406.977 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2021-10-07T16:33:26.977Z,1633624406.977 [CBIT](CRITICAL): Communications Fault in component: RDI_Pathfinder
2021-10-07T16:33:27.420Z,1633624407.420 [RDI_Pathfinder](INFO): Powering down
2021-10-07T16:33:27.439Z,1633624407.439 [CBIT](INFO): Critical error at 20211007T163326
2021-10-07T16:36:27.152Z,1633624587.152 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-10-07T16:36:27.152Z,1633624587.152 [RDI_Pathfinder] No Fault, FailCount= 3
2021-10-07T16:36:40.063Z,1633624600.063 [RDI_Pathfinder](FAULT): DVL failed to acquire valid data within timeout.
2021-10-07T16:36:40.063Z,1633624600.063 [RDI_Pathfinder] Data Fault, FailCount= 1
2021-10-07T16:36:40.063Z,1633624600.063 [RDI_Pathfinder](ERROR): Data Fault
2021-10-07T16:36:40.083Z,1633624600.083 [CBIT](ERROR): Data Fault in component: RDI_Pathfinder
2021-10-07T16:36:40.536Z,1633624600.536 [RDI_Pathfinder](INFO): Powering down
2021-10-07T16:36:41.292Z,1633624601.292 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-10-07T16:36:41.292Z,1633624601.292 [RDI_Pathfinder] No Fault, FailCount= 1
2021-10-07T16:37:03.897Z,1633624623.897 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2021-10-07T16:37:03.898Z,1633624623.898 [RDI_Pathfinder] Communications Fault, FailCount= 2
2021-10-07T16:37:03.898Z,1633624623.898 [RDI_Pathfinder](ERROR): Communications Fault
2021-10-07T16:37:03.946Z,1633624623.946 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2021-10-07T16:37:04.368Z,1633624624.368 [RDI_Pathfinder](INFO): Powering down
2021-10-07T16:37:05.150Z,1633624625.150 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-10-07T16:37:05.150Z,1633624625.150 [RDI_Pathfinder] No Fault, FailCount= 2
2021-10-07T16:37:16.246Z,1633624636.246 [CommandExec](IMPORTANT): got command show variable 24
2021-10-07T16:37:16.256Z,1633624636.256 [CommandExec](IMPORTANT): Power24vConverter.loadAtStartup (bool)
2021-10-07T16:37:16.257Z,1633624636.257 [CommandExec](IMPORTANT): Power24vConverter.simulateHardware (bool)
2021-10-07T16:37:16.273Z,1633624636.273 [CommandExec](IMPORTANT): Power24vConverter.loadControl (none)
2021-10-07T16:37:16.276Z,1633624636.276 [CommandExec](IMPORTANT): CBIT.gf24Offset (microampere)
2021-10-07T16:37:16.313Z,1633624636.313 [CommandExec](IMPORTANT): Config/Battery.stick24 (none)
2021-10-07T16:37:16.321Z,1633624636.321 [CommandExec](IMPORTANT): BPC1.BattCapacity_24 (ampere_hour)
2021-10-07T16:37:16.321Z,1633624636.321 [CommandExec](IMPORTANT): BPC1.BattCurrent_24 (ampere)
2021-10-07T16:37:16.322Z,1633624636.322 [CommandExec](IMPORTANT): BPC1.BattStatus_24 (none_ushort)
2021-10-07T16:37:16.322Z,1633624636.322 [CommandExec](IMPORTANT): BPC1.BattTemp_24 (celsius)
2021-10-07T16:37:16.322Z,1633624636.322 [CommandExec](IMPORTANT): BPC1.BattVoltage_24 (millivolt)
2021-10-07T16:37:16.340Z,1633624636.340 [CommandExec](IMPORTANT): Power24vConverter.enableBroadcast (bool)
2021-10-07T16:37:16.341Z,1633624636.341 [CommandExec](IMPORTANT): Power24vConverter.component_voltage (volt)
2021-10-07T16:37:16.341Z,1633624636.341 [CommandExec](IMPORTANT): Power24vConverter.component_avgVoltage (volt)
2021-10-07T16:37:16.341Z,1633624636.341 [CommandExec](IMPORTANT): Power24vConverter.component_current (milliampere)
2021-10-07T16:37:16.342Z,1633624636.342 [CommandExec](IMPORTANT): Power24vConverter.component_avgCurrent (milliampere)
2021-10-07T16:37:16.342Z,1633624636.342 [CommandExec](IMPORTANT): Power24vConverter.power24vConverter (bool)
2021-10-07T16:37:27.345Z,1633624647.345 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-07T16:37:27.345Z,1633624647.345 [Default:CheckIn:C.Wait] Stopped
2021-10-07T16:37:27.345Z,1633624647.345 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-07T16:37:27.345Z,1633624647.345 [Default:CheckIn:D] Running Loop=1
2021-10-07T16:37:27.733Z,1633624647.733 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2021-10-07T16:37:27.734Z,1633624647.734 [RDI_Pathfinder] Communications Fault, FailCount= 3
2021-10-07T16:37:27.734Z,1633624647.734 [RDI_Pathfinder](ERROR): Communications Fault
2021-10-07T16:37:27.780Z,1633624647.780 [Default:CheckIn:D] Stopped
2021-10-07T16:37:27.780Z,1633624647.780 [Default:CheckIn:E] Running Loop=1
2021-10-07T16:37:27.809Z,1633624647.809 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2021-10-07T16:37:27.810Z,1633624647.810 [CBIT](CRITICAL): Communications Fault in component: RDI_Pathfinder
2021-10-07T16:37:28.200Z,1633624648.200 [RDI_Pathfinder](INFO): Powering down
2021-10-07T16:37:28.236Z,1633624648.236 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 17.400952 min 
2021-10-07T16:37:28.236Z,1633624648.236 [Default:CheckIn:E] Stopped
2021-10-07T16:37:28.236Z,1633624648.236 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-07T16:37:28.236Z,1633624648.236 [Default:CheckIn] Stopped
2021-10-07T16:37:28.236Z,1633624648.236 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-07T16:37:28.236Z,1633624648.236 [Default:CheckIn](INFO): Running loop #3
2021-10-07T16:37:28.237Z,1633624648.237 [Default:CheckIn] Running Loop=3
2021-10-07T16:37:28.237Z,1633624648.237 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-07T16:37:28.237Z,1633624648.237 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-07T16:37:28.245Z,1633624648.245 [CBIT](INFO): Critical error at 20211007T163727
2021-10-07T16:37:30.166Z,1633624650.166 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163729.00,A,3648.12012,N,12147.23267,W,0.019,143.44,071021,,,D*70
2021-10-07T16:37:30.174Z,1633624650.174 [NAL9602](INFO): GPS fix at 20211007T163729: (36.802002, -121.787211)
2021-10-07T16:37:30.184Z,1633624650.184 [Default:CheckIn:Read_GPS] Stopped
2021-10-07T16:37:30.184Z,1633624650.184 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-07T16:37:38.399Z,1633624658.399 [DataOverHttps](INFO): Sending 135 bytes from file Logs/20211007T161603/Courier0013.lzma
2021-10-07T16:37:39.401Z,1633624659.401 [DataOverHttps](INFO): Moved sent file to Logs/20211007T161603/Courier0013.lzma.bak
2021-10-07T16:37:39.402Z,1633624659.402 [DataOverHttps](INFO): SBD MOMSN=15978178
2021-10-07T16:37:45.506Z,1633624665.506 [NAL9602](INFO): SBD MO Status=0, MOMSN=16159, MT Status=0, MTMSN=0
2021-10-07T16:37:45.506Z,1633624665.506 [NAL9602](INFO): No messages in MT queue
2021-10-07T16:38:01.350Z,1633624681.350 [CommandExec](IMPORTANT): got command get Power24vConverter.loadAtStartup
2021-10-07T16:38:01.350Z,1633624681.350 [CommandExec](IMPORTANT): Power24vConverter.loadAtStartup 1 bool
2021-10-07T16:38:01.437Z,1633624681.437 [DataOverHttps](INFO): Sending 1025 bytes from file Logs/20211007T161603/Express0014.lzma
2021-10-07T16:38:02.438Z,1633624682.438 [DataOverHttps](INFO): Moved sent file to Logs/20211007T161603/Express0014.lzma.bak
2021-10-07T16:38:02.438Z,1633624682.438 [DataOverHttps](INFO): SBD MOMSN=15978183
2021-10-07T16:38:05.365Z,1633624685.365 [Default:CheckIn:Read_Iridium] Stopped
2021-10-07T16:38:05.365Z,1633624685.365 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-07T16:38:05.365Z,1633624685.365 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-07T16:38:16.249Z,1633624696.249 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-07T16:38:40.085Z,1633624720.085 [Power24vConverter](INFO): Powering down.
2021-10-07T16:40:28.036Z,1633624828.036 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-10-07T16:40:28.036Z,1633624828.036 [RDI_Pathfinder] No Fault, FailCount= 3
2021-10-07T16:40:28.821Z,1633624828.821 [Power24vConverter](INFO): Powering up.
2021-10-07T16:40:40.945Z,1633624840.945 [RDI_Pathfinder](FAULT): DVL failed to acquire valid data within timeout.
2021-10-07T16:40:40.945Z,1633624840.945 [RDI_Pathfinder] Data Fault, FailCount= 1
2021-10-07T16:40:40.945Z,1633624840.945 [RDI_Pathfinder](ERROR): Data Fault
2021-10-07T16:40:41.033Z,1633624841.033 [CBIT](ERROR): Data Fault in component: RDI_Pathfinder
2021-10-07T16:40:41.416Z,1633624841.416 [RDI_Pathfinder](INFO): Powering down
2021-10-07T16:40:42.175Z,1633624842.175 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-10-07T16:40:42.175Z,1633624842.175 [RDI_Pathfinder] No Fault, FailCount= 1
2021-10-07T16:41:03.532Z,1633624863.532 [CommandExec](IMPORTANT): got command get Power24vConverter.simulateHardware
2021-10-07T16:41:03.532Z,1633624863.532 [CommandExec](IMPORTANT): Power24vConverter.simulateHardware 1 bool
2021-10-07T16:41:04.783Z,1633624864.783 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2021-10-07T16:41:04.784Z,1633624864.784 [RDI_Pathfinder] Communications Fault, FailCount= 2
2021-10-07T16:41:04.784Z,1633624864.784 [RDI_Pathfinder](ERROR): Communications Fault
2021-10-07T16:41:04.844Z,1633624864.844 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2021-10-07T16:41:05.252Z,1633624865.252 [RDI_Pathfinder](INFO): Powering down
2021-10-07T16:41:06.023Z,1633624866.023 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-10-07T16:41:06.023Z,1633624866.023 [RDI_Pathfinder] No Fault, FailCount= 2
2021-10-07T16:41:28.617Z,1633624888.617 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2021-10-07T16:41:28.617Z,1633624888.617 [RDI_Pathfinder] Communications Fault, FailCount= 3
2021-10-07T16:41:28.617Z,1633624888.617 [RDI_Pathfinder](ERROR): Communications Fault
2021-10-07T16:41:28.683Z,1633624888.683 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2021-10-07T16:41:28.683Z,1633624888.683 [CBIT](CRITICAL): Communications Fault in component: RDI_Pathfinder
2021-10-07T16:41:29.092Z,1633624889.092 [RDI_Pathfinder](INFO): Powering down
2021-10-07T16:41:29.117Z,1633624889.117 [CBIT](INFO): Critical error at 20211007T164128
2021-10-07T16:42:40.824Z,1633624960.824 [CommandExec](IMPORTANT): got command configSet Power24vConverter.simulateHardware 0.000000 bool
2021-10-07T16:42:40.824Z,1633624960.824 [CommandExec](FAULT): configSet Power24vConverter.simulateHardware without persist will have no effect.
2021-10-07T16:42:40.825Z,1633624960.825 [CommandExec](IMPORTANT): got command restart
2021-10-07T16:42:40.825Z,1633624960.825 [CommandExec](FAULT): Incomplete syntax. Try: help restart
2021-10-07T16:42:51.164Z,1633624971.164 [CommandExec](IMPORTANT): got command gfscan
2021-10-07T16:42:51.493Z,1633624971.493 [CBIT](IMPORTANT): Beginning ground fault scan
2021-10-07T16:43:02.446Z,1633624982.446 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.010801
CHAN A1 (24V): -0.167033
CHAN A2 (12V): -0.006991
CHAN A3 (5V): -0.002595
CHAN B0 (3.3V): -0.000040
CHAN B1 (3.15aV): 0.000096
CHAN B2 (3.15bV): -0.000228
CHAN B3 (GND): 0.002236
OPEN: 0.004317
Full Scale: +/- 1 mA
2021-10-07T16:43:06.004Z,1633624986.004 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-07T16:43:06.004Z,1633624986.004 [Default:CheckIn:C.Wait] Stopped
2021-10-07T16:43:06.004Z,1633624986.004 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-07T16:43:06.004Z,1633624986.004 [Default:CheckIn:D] Running Loop=1
2021-10-07T16:43:06.418Z,1633624986.418 [Default:CheckIn:D] Stopped
2021-10-07T16:43:06.419Z,1633624986.419 [Default:CheckIn:E] Running Loop=1
2021-10-07T16:43:06.812Z,1633624986.812 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 23.044920 min 
2021-10-07T16:43:06.812Z,1633624986.812 [Default:CheckIn:E] Stopped
2021-10-07T16:43:06.812Z,1633624986.812 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-07T16:43:06.812Z,1633624986.812 [Default:CheckIn] Stopped
2021-10-07T16:43:06.812Z,1633624986.812 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-07T16:43:06.813Z,1633624986.813 [Default:CheckIn](INFO): Running loop #4
2021-10-07T16:43:06.813Z,1633624986.813 [Default:CheckIn] Running Loop=4
2021-10-07T16:43:06.813Z,1633624986.813 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-07T16:43:06.813Z,1633624986.813 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-07T16:43:08.823Z,1633624988.823 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164308.00,A,3648.11864,N,12147.23202,W,0.156,143.44,071021,,,D*73
2021-10-07T16:43:08.826Z,1633624988.826 [NAL9602](INFO): GPS fix at 20211007T164308: (36.801977, -121.787200)
2021-10-07T16:43:08.836Z,1633624988.836 [Default:CheckIn:Read_GPS] Stopped
2021-10-07T16:43:08.837Z,1633624988.837 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-07T16:43:14.849Z,1633624994.849 [CommandExec](IMPORTANT): got command ! echo 1 > /dev/loadB2
2021-10-07T16:43:17.207Z,1633624997.207 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20211007T161603/Courier0016.lzma
2021-10-07T16:43:18.209Z,1633624998.209 [DataOverHttps](INFO): Moved sent file to Logs/20211007T161603/Courier0016.lzma.bak
2021-10-07T16:43:18.210Z,1633624998.210 [DataOverHttps](INFO): SBD MOMSN=15978232
2021-10-07T16:43:21.749Z,1633625001.749 [CommandExec](IMPORTANT): got command gfscan
2021-10-07T16:43:21.794Z,1633625001.794 [NAL9602](INFO): SBD MO Status=0, MOMSN=16160, MT Status=0, MTMSN=0
2021-10-07T16:43:21.794Z,1633625001.794 [NAL9602](INFO): No messages in MT queue
2021-10-07T16:43:21.854Z,1633625001.854 [CBIT](IMPORTANT): Beginning ground fault scan
2021-10-07T16:43:32.730Z,1633625012.730 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.010513
CHAN A1 (24V): -0.000044
CHAN A2 (12V): -0.006991
CHAN A3 (5V): -0.001648
CHAN B0 (3.3V): 0.000350
CHAN B1 (3.15aV): 0.000010
CHAN B2 (3.15bV): -0.000119
CHAN B3 (GND): 0.002127
OPEN: 0.003926
Full Scale: +/- 1 mA
2021-10-07T16:43:35.957Z,1633625015.957 [DataOverHttps](INFO): Sending 555 bytes from file Logs/20211007T161603/Express0017.lzma
2021-10-07T16:43:36.957Z,1633625016.957 [DataOverHttps](INFO): Moved sent file to Logs/20211007T161603/Express0017.lzma.bak
2021-10-07T16:43:36.957Z,1633625016.957 [DataOverHttps](INFO): SBD MOMSN=15978237
2021-10-07T16:43:37.176Z,1633625017.176 [CommandExec](IMPORTANT): got command failComponent
2021-10-07T16:43:37.176Z,1633625017.176 [CommandExec](IMPORTANT): Failed components:
2021-10-07T16:43:37.177Z,1633625017.177 [CommandExec](IMPORTANT): RDI_Pathfinder: Communications Fault
2021-10-07T16:43:39.580Z,1633625019.580 [Default:CheckIn:Read_Iridium] Stopped
2021-10-07T16:43:39.580Z,1633625019.580 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-07T16:43:39.580Z,1633625019.580 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-07T16:43:44.919Z,1633625024.919 [CommandExec](IMPORTANT): got command failComponent none RDI_Pathfinder
2021-10-07T16:43:44.919Z,1633625024.919 [RDI_Pathfinder] No Fault, FailCount= 3
2021-10-07T16:43:44.920Z,1633625024.920 [CommandExec](IMPORTANT): RDI_Pathfinder failureMode is No Fault
2021-10-07T16:43:52.481Z,1633625032.481 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-07T16:43:57.725Z,1633625037.725 [RDI_Pathfinder](FAULT): DVL failed to acquire valid data within timeout.
2021-10-07T16:43:57.725Z,1633625037.725 [RDI_Pathfinder] Data Fault, FailCount= 4
2021-10-07T16:43:57.725Z,1633625037.725 [RDI_Pathfinder](ERROR): Data Fault
2021-10-07T16:43:57.796Z,1633625037.796 [CBIT](ERROR): Data Fault in component: RDI_Pathfinder
2021-10-07T16:43:57.797Z,1633625037.797 [CBIT](CRITICAL): Data Fault in component: RDI_Pathfinder
2021-10-07T16:43:58.208Z,1633625038.208 [RDI_Pathfinder](INFO): Powering down
2021-10-07T16:43:58.227Z,1633625038.227 [CBIT](INFO): Critical error at 20211007T164357
2021-10-07T16:44:02.293Z,1633625042.293 [CommandExec](IMPORTANT): got command configSet list
2021-10-07T16:44:02.293Z,1633625042.293 [CommandExec](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2021-10-07T16:44:02.294Z,1633625042.294 [CommandExec](IMPORTANT): BPC1.batteryMissingStickThreshold=6 count;

2021-10-07T16:44:02.294Z,1633625042.294 [CommandExec](IMPORTANT): CBIT.gf24Offset=143 microampere;

2021-10-07T16:44:02.294Z,1633625042.294 [CommandExec](IMPORTANT): DAT.loadAtStartup=0 bool;

2021-10-07T16:44:02.294Z,1633625042.294 [CommandExec](IMPORTANT): IBIT.batteryCapacityThreshold=24 ampere_hour;

2021-10-07T16:44:02.295Z,1633625042.295 [CommandExec](IMPORTANT): IBIT.batteryVoltageThreshold=13 volt;

2021-10-07T16:44:02.295Z,1633625042.295 [CommandExec](IMPORTANT): VerticalControl.buoyancyNeutral=231.913961 cubic_centimeter;

2021-10-07T16:44:02.295Z,1633625042.295 [CommandExec](IMPORTANT): VerticalControl.massDefault=8.903467 millimeter;

2021-10-07T16:45:15.229Z,1633625115.229 [CommandExec](IMPORTANT): got command failComponent
2021-10-07T16:45:15.229Z,1633625115.229 [CommandExec](IMPORTANT): Failed components:
2021-10-07T16:45:15.229Z,1633625115.229 [CommandExec](IMPORTANT): RDI_Pathfinder: Data Fault
2021-10-07T16:45:22.859Z,1633625122.859 [CommandExec](IMPORTANT): got command failComponent none RDI_Pathfinder
2021-10-07T16:45:22.860Z,1633625122.860 [RDI_Pathfinder] No Fault, FailCount= 4
2021-10-07T16:45:22.860Z,1633625122.860 [CommandExec](IMPORTANT): RDI_Pathfinder failureMode is No Fault
2021-10-07T16:45:37.137Z,1633625137.137 [RDI_Pathfinder](INFO): Failure count cleared after critical for RDI_Pathfinder
2021-10-07T16:48:40.164Z,1633625320.164 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-07T16:48:40.164Z,1633625320.164 [Default:CheckIn:C.Wait] Stopped
2021-10-07T16:48:40.164Z,1633625320.164 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-07T16:48:40.164Z,1633625320.164 [Default:CheckIn:D] Running Loop=1
2021-10-07T16:48:40.562Z,1633625320.562 [Default:CheckIn:D] Stopped
2021-10-07T16:48:40.562Z,1633625320.562 [Default:CheckIn:E] Running Loop=1
2021-10-07T16:48:40.997Z,1633625320.997 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 28.613985 min 
2021-10-07T16:48:40.997Z,1633625320.997 [Default:CheckIn:E] Stopped
2021-10-07T16:48:40.998Z,1633625320.998 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-07T16:48:40.998Z,1633625320.998 [Default:CheckIn] Stopped
2021-10-07T16:48:40.998Z,1633625320.998 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-07T16:48:40.998Z,1633625320.998 [Default:CheckIn](INFO): Running loop #5
2021-10-07T16:48:40.998Z,1633625320.998 [Default:CheckIn] Running Loop=5
2021-10-07T16:48:40.998Z,1633625320.998 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-07T16:48:40.998Z,1633625320.998 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-07T16:48:42.975Z,1633625322.975 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164842.00,A,3648.40606,N,12147.11979,W,4.646,7.82,071021,,,D*77
2021-10-07T16:48:42.981Z,1633625322.981 [NAL9602](INFO): GPS fix at 20211007T164842: (36.806768, -121.785330)
2021-10-07T16:48:43.174Z,1633625323.174 [Default:CheckIn:Read_GPS] Stopped
2021-10-07T16:48:43.174Z,1633625323.174 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-07T16:48:52.355Z,1633625332.355 [DataOverHttps](INFO): Sending 122 bytes from file Logs/20211007T161603/Courier0019.lzma
2021-10-07T16:48:53.357Z,1633625333.357 [DataOverHttps](INFO): Moved sent file to Logs/20211007T161603/Courier0019.lzma.bak
2021-10-07T16:48:53.358Z,1633625333.358 [DataOverHttps](INFO): SBD MOMSN=15978259
2021-10-07T16:48:57.441Z,1633625337.441 [NAL9602](INFO): SBD MO Status=0, MOMSN=16161, MT Status=0, MTMSN=0
2021-10-07T16:48:57.441Z,1633625337.441 [NAL9602](INFO): No messages in MT queue
2021-10-07T16:49:11.304Z,1633625351.304 [DataOverHttps](INFO): Sending 777 bytes from file Logs/20211007T161603/Express0020.lzma
2021-10-07T16:49:12.305Z,1633625352.305 [DataOverHttps](INFO): Moved sent file to Logs/20211007T161603/Express0020.lzma.bak
2021-10-07T16:49:12.305Z,1633625352.305 [DataOverHttps](INFO): SBD MOMSN=15978263
2021-10-07T16:49:14.839Z,1633625354.839 [Default:CheckIn:Read_Iridium] Stopped
2021-10-07T16:49:14.844Z,1633625354.844 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-07T16:49:14.844Z,1633625354.844 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-07T16:49:28.141Z,1633625368.141 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-07T16:54:15.476Z,1633625655.476 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-07T16:54:15.477Z,1633625655.477 [Default:CheckIn:C.Wait] Stopped
2021-10-07T16:54:15.477Z,1633625655.477 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-07T16:54:15.477Z,1633625655.477 [Default:CheckIn:D] Running Loop=1
2021-10-07T16:54:15.892Z,1633625655.892 [Default:CheckIn:D] Stopped
2021-10-07T16:54:15.892Z,1633625655.892 [Default:CheckIn:E] Running Loop=1
2021-10-07T16:54:16.273Z,1633625656.273 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 34.202820 min 
2021-10-07T16:54:16.273Z,1633625656.273 [Default:CheckIn:E] Stopped
2021-10-07T16:54:16.273Z,1633625656.273 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-07T16:54:16.273Z,1633625656.273 [Default:CheckIn] Stopped
2021-10-07T16:54:16.274Z,1633625656.274 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-07T16:54:16.274Z,1633625656.274 [Default:CheckIn](INFO): Running loop #6
2021-10-07T16:54:16.274Z,1633625656.274 [Default:CheckIn] Running Loop=6
2021-10-07T16:54:16.274Z,1633625656.274 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-07T16:54:16.274Z,1633625656.274 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-07T16:54:18.279Z,1633625658.279 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165417.00,A,3648.38707,N,12147.83399,W,14.773,287.38,071021,,,D*47
2021-10-07T16:54:18.299Z,1633625658.299 [NAL9602](INFO): GPS fix at 20211007T165417: (36.806451, -121.797233)
2021-10-07T16:54:18.317Z,1633625658.317 [Default:CheckIn:Read_GPS] Stopped
2021-10-07T16:54:18.317Z,1633625658.317 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-07T16:54:31.107Z,1633625671.107 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20211007T161603/Courier0022.lzma
2021-10-07T16:54:32.110Z,1633625672.110 [DataOverHttps](INFO): Moved sent file to Logs/20211007T161603/Courier0022.lzma.bak
2021-10-07T16:54:32.110Z,1633625672.110 [DataOverHttps](INFO): SBD MOMSN=15978298
2021-10-07T16:54:32.242Z,1633625672.242 [NAL9602](INFO): SBD MO Status=0, MOMSN=16162, MT Status=0, MTMSN=0
2021-10-07T16:54:32.242Z,1633625672.242 [NAL9602](INFO): No messages in MT queue
2021-10-07T16:54:51.268Z,1633625691.268 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20211007T161603/Express0023.lzma
2021-10-07T16:54:53.511Z,1633625693.511 [DataOverHttps](INFO): Moved sent file to Logs/20211007T161603/Express0023.lzma.bak
2021-10-07T16:54:53.511Z,1633625693.511 [DataOverHttps](INFO): SBD MOMSN=15978301
2021-10-07T16:54:55.372Z,1633625695.372 [Default:CheckIn:Read_Iridium] Stopped
2021-10-07T16:54:55.373Z,1633625695.373 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-07T16:54:55.373Z,1633625695.373 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-07T16:55:02.932Z,1633625702.932 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-07T16:59:55.951Z,1633625995.951 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-07T16:59:55.951Z,1633625995.951 [Default:CheckIn:C.Wait] Stopped
2021-10-07T16:59:55.951Z,1633625995.951 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-07T16:59:55.951Z,1633625995.951 [Default:CheckIn:D] Running Loop=1
2021-10-07T16:59:56.340Z,1633625996.340 [Default:CheckIn:D] Stopped
2021-10-07T16:59:56.340Z,1633625996.340 [Default:CheckIn:E] Running Loop=1
2021-10-07T16:59:56.747Z,1633625996.747 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.876945 min 
2021-10-07T16:59:56.747Z,1633625996.747 [Default:CheckIn:E] Stopped
2021-10-07T16:59:56.748Z,1633625996.748 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-07T16:59:56.748Z,1633625996.748 [Default:CheckIn] Stopped
2021-10-07T16:59:56.748Z,1633625996.748 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-07T16:59:56.748Z,1633625996.748 [Default:CheckIn](INFO): Running loop #7
2021-10-07T16:59:56.748Z,1633625996.748 [Default:CheckIn] Running Loop=7
2021-10-07T16:59:56.748Z,1633625996.748 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-07T16:59:56.748Z,1633625996.748 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-07T16:59:58.755Z,1633625998.755 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165958.00,A,3648.76835,N,12149.91576,W,18.214,275.97,071021,,,D*4F
2021-10-07T16:59:58.757Z,1633625998.757 [NAL9602](INFO): GPS fix at 20211007T165958: (36.812806, -121.831929)
2021-10-07T16:59:58.768Z,1633625998.768 [Default:CheckIn:Read_GPS] Stopped
2021-10-07T16:59:58.769Z,1633625998.769 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-07T17:00:10.599Z,1633626010.599 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20211007T161603/Courier0025.lzma
2021-10-07T17:00:11.602Z,1633626011.602 [DataOverHttps](INFO): Moved sent file to Logs/20211007T161603/Courier0025.lzma.bak
2021-10-07T17:00:11.602Z,1633626011.602 [DataOverHttps](INFO): SBD MOMSN=15978311
2021-10-07T17:00:22.666Z,1633626022.666 [NAL9602](INFO): SBD MO Status=2, MOMSN=16163, MT Status=2, MTMSN=0
2021-10-07T17:00:22.667Z,1633626022.667 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-10-07T17:00:35.315Z,1633626035.315 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20211007T161603/Express0026.lzma
2021-10-07T17:00:36.317Z,1633626036.317 [DataOverHttps](INFO): Moved sent file to Logs/20211007T161603/Express0026.lzma.bak
2021-10-07T17:00:36.318Z,1633626036.318 [DataOverHttps](INFO): SBD MOMSN=15978314
2021-10-07T17:00:38.859Z,1633626038.859 [Default:CheckIn:Read_Iridium] Stopped
2021-10-07T17:00:38.859Z,1633626038.859 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-07T17:00:38.859Z,1633626038.859 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-07T17:00:46.090Z,1633626046.090 [NAL9602](INFO): SBD MO Status=0, MOMSN=16163, MT Status=0, MTMSN=0
2021-10-07T17:00:46.090Z,1633626046.090 [NAL9602](INFO): No messages in MT queue
2021-10-07T17:01:16.798Z,1633626076.798 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-07T17:05:39.459Z,1633626339.459 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-07T17:05:39.463Z,1633626339.463 [Default:CheckIn:C.Wait] Stopped
2021-10-07T17:05:39.464Z,1633626339.464 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-07T17:05:39.464Z,1633626339.464 [Default:CheckIn:D] Running Loop=1
2021-10-07T17:05:39.865Z,1633626339.865 [Default:CheckIn:D] Stopped
2021-10-07T17:05:39.865Z,1633626339.865 [Default:CheckIn:E] Running Loop=1
2021-10-07T17:05:40.281Z,1633626340.281 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.602364 min 
2021-10-07T17:05:40.281Z,1633626340.281 [Default:CheckIn:E] Stopped
2021-10-07T17:05:40.282Z,1633626340.282 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-07T17:05:40.282Z,1633626340.282 [Default:CheckIn] Stopped
2021-10-07T17:05:40.282Z,1633626340.282 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-07T17:05:40.282Z,1633626340.282 [Default:CheckIn](INFO): Running loop #8
2021-10-07T17:05:40.282Z,1633626340.282 [Default:CheckIn] Running Loop=8
2021-10-07T17:05:40.282Z,1633626340.282 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-07T17:05:40.282Z,1633626340.282 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-07T17:05:42.279Z,1633626342.279 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170541.00,A,3649.05326,N,12152.07653,W,22.063,277.67,071021,,,A*41
2021-10-07T17:05:42.281Z,1633626342.281 [NAL9602](INFO): GPS fix at 20211007T170541: (36.817554, -121.867942)
2021-10-07T17:05:42.292Z,1633626342.292 [Default:CheckIn:Read_GPS] Stopped
2021-10-07T17:05:42.292Z,1633626342.292 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-07T17:05:50.871Z,1633626350.871 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20211007T161603/Courier0028.lzma
2021-10-07T17:05:51.869Z,1633626351.869 [DataOverHttps](INFO): Moved sent file to Logs/20211007T161603/Courier0028.lzma.bak
2021-10-07T17:05:51.870Z,1633626351.870 [DataOverHttps](INFO): SBD MOMSN=15978328
2021-10-07T17:05:59.330Z,1633626359.330 [NAL9602](INFO): SBD MO Status=0, MOMSN=16164, MT Status=0, MTMSN=0
2021-10-07T17:05:59.330Z,1633626359.330 [NAL9602](INFO): No messages in MT queue
2021-10-07T17:06:13.499Z,1633626373.499 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20211007T161603/Express0029.lzma
2021-10-07T17:06:14.502Z,1633626374.502 [DataOverHttps](INFO): Moved sent file to Logs/20211007T161603/Express0029.lzma.bak
2021-10-07T17:06:14.502Z,1633626374.502 [DataOverHttps](INFO): SBD MOMSN=15978331
2021-10-07T17:06:19.320Z,1633626379.320 [Default:CheckIn:Read_Iridium] Stopped
2021-10-07T17:06:19.320Z,1633626379.320 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-07T17:06:19.320Z,1633626379.320 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-07T17:06:30.109Z,1633626390.109 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-07T17:11:19.898Z,1633626679.898 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-07T17:11:19.898Z,1633626679.898 [Default:CheckIn:C.Wait] Stopped
2021-10-07T17:11:19.898Z,1633626679.898 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-07T17:11:19.898Z,1633626679.898 [Default:CheckIn:D] Running Loop=1
2021-10-07T17:11:20.277Z,1633626680.277 [Default:CheckIn:D] Stopped
2021-10-07T17:11:20.277Z,1633626680.277 [Default:CheckIn:E] Running Loop=1
2021-10-07T17:11:20.684Z,1633626680.684 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 51.275895 min 
2021-10-07T17:11:20.684Z,1633626680.684 [Default:CheckIn:E] Stopped
2021-10-07T17:11:20.684Z,1633626680.684 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-07T17:11:20.684Z,1633626680.684 [Default:CheckIn] Stopped
2021-10-07T17:11:20.684Z,1633626680.684 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-07T17:11:20.684Z,1633626680.684 [Default:CheckIn](INFO): Running loop #9
2021-10-07T17:11:20.685Z,1633626680.685 [Default:CheckIn] Running Loop=9
2021-10-07T17:11:20.685Z,1633626680.685 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-07T17:11:20.685Z,1633626680.685 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-07T17:11:22.691Z,1633626682.691 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171122.00,A,3649.20131,N,12154.01396,W,18.253,273.86,071021,,,A*4D
2021-10-07T17:11:22.693Z,1633626682.693 [NAL9602](INFO): GPS fix at 20211007T171122: (36.820022, -121.900233)
2021-10-07T17:11:22.729Z,1633626682.729 [Default:CheckIn:Read_GPS] Stopped
2021-10-07T17:11:22.729Z,1633626682.729 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-07T17:11:30.851Z,1633626690.851 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20211007T161603/Courier0031.lzma
2021-10-07T17:11:31.849Z,1633626691.849 [DataOverHttps](INFO): Moved sent file to Logs/20211007T161603/Courier0031.lzma.bak
2021-10-07T17:11:31.850Z,1633626691.850 [DataOverHttps](INFO): SBD MOMSN=15978343
2021-10-07T17:11:39.658Z,1633626699.658 [NAL9602](INFO): SBD MO Status=0, MOMSN=16165, MT Status=0, MTMSN=0
2021-10-07T17:11:39.658Z,1633626699.658 [NAL9602](INFO): No messages in MT queue
2021-10-07T17:11:50.915Z,1633626710.915 [DataOverHttps](INFO): Sending 141 bytes from file Logs/20211007T161603/Express0032.lzma
2021-10-07T17:11:51.917Z,1633626711.917 [DataOverHttps](INFO): Moved sent file to Logs/20211007T161603/Express0032.lzma.bak
2021-10-07T17:11:51.918Z,1633626711.918 [DataOverHttps](INFO): SBD MOMSN=15978346
2021-10-07T17:11:54.641Z,1633626714.641 [Default:CheckIn:Read_Iridium] Stopped
2021-10-07T17:11:54.641Z,1633626714.641 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-07T17:11:54.641Z,1633626714.641 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-07T17:12:10.061Z,1633626730.061 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-07T17:16:55.297Z,1633627015.297 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-07T17:16:55.297Z,1633627015.297 [Default:CheckIn:C.Wait] Stopped
2021-10-07T17:16:55.297Z,1633627015.297 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-07T17:16:55.297Z,1633627015.297 [Default:CheckIn:D] Running Loop=1
2021-10-07T17:16:55.704Z,1633627015.704 [Default:CheckIn:D] Stopped
2021-10-07T17:16:55.704Z,1633627015.704 [Default:CheckIn:E] Running Loop=1
2021-10-07T17:16:56.112Z,1633627016.112 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 56.866349 min 
2021-10-07T17:16:56.112Z,1633627016.112 [Default:CheckIn:E] Stopped
2021-10-07T17:16:56.112Z,1633627016.112 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-07T17:16:56.112Z,1633627016.112 [Default:CheckIn] Stopped
2021-10-07T17:16:56.112Z,1633627016.112 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-07T17:16:56.112Z,1633627016.112 [Default:CheckIn](INFO): Running loop #10
2021-10-07T17:16:56.113Z,1633627016.113 [Default:CheckIn] Running Loop=10
2021-10-07T17:16:56.113Z,1633627016.113 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-07T17:16:56.113Z,1633627016.113 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-07T17:16:58.123Z,1633627018.123 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171657.00,A,3649.43423,N,12155.81238,W,13.976,286.22,071021,,,A*44
2021-10-07T17:16:58.125Z,1633627018.125 [NAL9602](INFO): GPS fix at 20211007T171657: (36.823904, -121.930206)
2021-10-07T17:16:58.174Z,1633627018.174 [Default:CheckIn:Read_GPS] Stopped
2021-10-07T17:16:58.174Z,1633627018.174 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-07T17:17:01.692Z,1633627021.692 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20211007T161603/Courier0034.lzma
2021-10-07T17:17:07.825Z,1633627027.825 [DataOverHttps](INFO): Moved sent file to Logs/20211007T161603/Courier0034.lzma.bak
2021-10-07T17:17:07.826Z,1633627027.826 [DataOverHttps](INFO): SBD MOMSN=15978357
2021-10-07T17:17:16.002Z,1633627036.002 [NAL9602](INFO): SBD MO Status=0, MOMSN=16166, MT Status=0, MTMSN=0
2021-10-07T17:17:16.003Z,1633627036.003 [NAL9602](INFO): No messages in MT queue
2021-10-07T17:17:46.705Z,1633627066.705 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-07T17:18:28.725Z,1633627108.725 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.840275
2021-10-07T17:18:59.848Z,1633627139.848 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-07T17:19:33.590Z,1633627173.590 [NAL9602](INFO): SBD MO Status=1, MOMSN=16167, MT Status=0, MTMSN=0
2021-10-07T17:19:33.650Z,1633627173.650 [NAL9602](INFO): Sent 142 bytes from file Logs/20211007T161603/Express0035.lzma
2021-10-07T17:19:33.651Z,1633627173.651 [NAL9602](INFO): Packets left to send: 0
2021-10-07T17:19:34.988Z,1633627174.988 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-07T17:19:42.002Z,1633627182.002 [NAL9602](INFO): SBD MO Status=0, MOMSN=16168, MT Status=0, MTMSN=0
2021-10-07T17:19:42.089Z,1633627182.089 [Default:CheckIn:Read_Iridium] Stopped
2021-10-07T17:19:42.089Z,1633627182.089 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-07T17:19:42.090Z,1633627182.090 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-07T17:20:10.140Z,1633627210.140 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-07T17:20:12.697Z,1633627212.697 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-07T17:21:20.432Z,1633627280.432 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-07T17:21:55.572Z,1633627315.572 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-07T17:22:30.712Z,1633627350.712 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-07T17:23:05.856Z,1633627385.856 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-07T17:24:16.704Z,1633627456.704 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-07T17:24:42.587Z,1633627482.587 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-07T17:24:42.587Z,1633627482.587 [Default:CheckIn:C.Wait] Stopped
2021-10-07T17:24:42.587Z,1633627482.587 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-07T17:24:42.587Z,1633627482.588 [Default:CheckIn:D] Running Loop=1
2021-10-07T17:24:43.018Z,1633627483.018 [Default:CheckIn:D] Stopped
2021-10-07T17:24:43.018Z,1633627483.018 [Default:CheckIn:E] Running Loop=1
2021-10-07T17:24:43.412Z,1633627483.412 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 64.654919 min 
2021-10-07T17:24:43.412Z,1633627483.412 [Default:CheckIn:E] Stopped
2021-10-07T17:24:43.412Z,1633627483.412 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-07T17:24:43.412Z,1633627483.412 [Default:CheckIn] Stopped
2021-10-07T17:24:43.412Z,1633627483.412 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-07T17:24:43.413Z,1633627483.413 [Default:CheckIn](INFO): Running loop #11
2021-10-07T17:24:43.413Z,1633627483.413 [Default:CheckIn] Running Loop=11
2021-10-07T17:24:43.413Z,1633627483.413 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-07T17:24:43.413Z,1633627483.413 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-07T17:24:45.407Z,1633627485.407 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172444.00,A,3649.69952,N,12158.21063,W,12.771,277.85,071021,,,D*41
2021-10-07T17:24:45.410Z,1633627485.410 [NAL9602](INFO): GPS fix at 20211007T172444: (36.828325, -121.970177)
2021-10-07T17:24:45.428Z,1633627485.428 [Default:CheckIn:Read_GPS] Stopped
2021-10-07T17:24:45.429Z,1633627485.429 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-07T17:24:51.848Z,1633627491.848 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-07T17:25:09.789Z,1633627509.789 [NAL9602](INFO): SBD MO Status=1, MOMSN=16169, MT Status=0, MTMSN=0
2021-10-07T17:25:09.844Z,1633627509.844 [NAL9602](INFO): Sent 73 bytes from file Logs/20211007T161603/Courier0037.lzma
2021-10-07T17:25:09.845Z,1633627509.845 [NAL9602](INFO): Packets left to send: 0
2021-10-07T17:25:26.996Z,1633627526.996 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-07T17:25:32.093Z,1633627532.093 [NAL9602](INFO): SBD MO Status=2, MOMSN=16170, MT Status=2, MTMSN=0
2021-10-07T17:25:32.093Z,1633627532.093 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-10-07T17:26:02.160Z,1633627562.160 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-07T17:26:05.399Z,1633627565.399 [NAL9602](INFO): SBD MO Status=1, MOMSN=16170, MT Status=0, MTMSN=0
2021-10-07T17:26:05.452Z,1633627565.452 [NAL9602](INFO): Sent 147 bytes from file Logs/20211007T161603/Express0038.lzma
2021-10-07T17:26:05.452Z,1633627565.452 [NAL9602](INFO): Packets left to send: 0
2021-10-07T17:26:17.439Z,1633627577.439 [NAL9602](INFO): SBD MO Status=0, MOMSN=16171, MT Status=0, MTMSN=0
2021-10-07T17:26:17.561Z,1633627577.561 [Default:CheckIn:Read_Iridium] Stopped
2021-10-07T17:26:17.561Z,1633627577.561 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-07T17:26:17.561Z,1633627577.561 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-07T17:26:37.320Z,1633627597.320 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-07T17:26:48.164Z,1633627608.164 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-07T17:27:12.460Z,1633627632.460 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-07T17:27:47.632Z,1633627667.632 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-07T17:28:22.772Z,1633627702.772 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-07T17:28:57.912Z,1633627737.912 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-07T17:29:33.052Z,1633627773.052 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-07T17:30:08.192Z,1633627808.192 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-07T17:30:43.340Z,1633627843.340 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-07T17:31:18.089Z,1633627878.089 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-07T17:31:18.089Z,1633627878.089 [Default:CheckIn:C.Wait] Stopped
2021-10-07T17:31:18.089Z,1633627878.089 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-07T17:31:18.089Z,1633627878.089 [Default:CheckIn:D] Running Loop=1
2021-10-07T17:31:18.436Z,1633627878.436 [Default:CheckIn:D] Stopped
2021-10-07T17:31:18.436Z,1633627878.436 [Default:CheckIn:E] Running Loop=1
2021-10-07T17:31:18.480Z,1633627878.480 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-07T17:31:18.877Z,1633627878.877 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 71.245215 min 
2021-10-07T17:31:18.878Z,1633627878.878 [Default:CheckIn:E] Stopped
2021-10-07T17:31:18.878Z,1633627878.878 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-07T17:31:18.878Z,1633627878.878 [Default:CheckIn] Stopped
2021-10-07T17:31:18.878Z,1633627878.878 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-07T17:31:18.879Z,1633627878.879 [Default:CheckIn](INFO): Running loop #12
2021-10-07T17:31:18.879Z,1633627878.879 [Default:CheckIn] Running Loop=12
2021-10-07T17:31:18.919Z,1633627878.919 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-07T17:31:18.919Z,1633627878.919 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-07T17:31:20.883Z,1633627880.883 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173120.00,A,3649.97090,N,12200.30813,W,14.637,275.19,071021,,,D*42
2021-10-07T17:31:20.888Z,1633627880.888 [NAL9602](INFO): GPS fix at 20211007T173120: (36.832848, -122.005135)
2021-10-07T17:31:20.960Z,1633627880.960 [Default:CheckIn:Read_GPS] Stopped
2021-10-07T17:31:20.960Z,1633627880.960 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-07T17:31:30.947Z,1633627890.947 [BPC1](INFO): Calculating totals. Valid battery stick count: 52. Valid reserve battery stick count: 6.
2021-10-07T17:31:30.962Z,1633627890.962 [BPC1](INFO): Received data from all battery sticks.
2021-10-07T17:31:53.628Z,1633627913.628 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-07T17:31:56.171Z,1633627916.171 [NAL9602](INFO): SBD MO Status=1, MOMSN=16172, MT Status=0, MTMSN=0
2021-10-07T17:31:56.218Z,1633627916.218 [NAL9602](INFO): Sent 72 bytes from file Logs/20211007T161603/Courier0040.lzma
2021-10-07T17:31:56.218Z,1633627916.218 [NAL9602](INFO): Packets left to send: 0
2021-10-07T17:32:08.022Z,1633627928.022 [NAL9602](INFO): SBD MO Status=1, MOMSN=16173, MT Status=0, MTMSN=0
2021-10-07T17:32:08.072Z,1633627928.072 [NAL9602](INFO): Sent 140 bytes from file Logs/20211007T161603/Express0041.lzma
2021-10-07T17:32:08.072Z,1633627928.072 [NAL9602](INFO): Packets left to send: 0
2021-10-07T17:32:28.768Z,1633627948.768 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-07T17:32:29.707Z,1633627949.707 [NAL9602](INFO): SBD MO Status=0, MOMSN=16174, MT Status=0, MTMSN=0
2021-10-07T17:32:29.801Z,1633627949.801 [Default:CheckIn:Read_Iridium] Stopped
2021-10-07T17:32:29.801Z,1633627949.801 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-07T17:32:29.801Z,1633627949.801 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-07T17:33:00.413Z,1633627980.413 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-07T17:33:03.908Z,1633627983.908 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-07T17:33:19.540Z,1633627999.540 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002887
2021-10-07T17:36:03.344Z,1633628163.344 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.239384
2021-10-07T17:37:00.552Z,1633628220.552 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002913
2021-10-07T17:37:30.297Z,1633628250.297 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-07T17:37:30.297Z,1633628250.297 [Default:CheckIn:C.Wait] Stopped
2021-10-07T17:37:30.297Z,1633628250.297 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-07T17:37:30.297Z,1633628250.297 [Default:CheckIn:D] Running Loop=1
2021-10-07T17:37:30.701Z,1633628250.701 [Default:CheckIn:D] Stopped
2021-10-07T17:37:30.701Z,1633628250.701 [Default:CheckIn:E] Running Loop=1
2021-10-07T17:37:31.125Z,1633628251.125 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 77.449634 min 
2021-10-07T17:37:31.126Z,1633628251.126 [Default:CheckIn:E] Stopped
2021-10-07T17:37:31.126Z,1633628251.126 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-07T17:37:31.126Z,1633628251.126 [Default:CheckIn] Stopped
2021-10-07T17:37:31.126Z,1633628251.126 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-07T17:37:31.126Z,1633628251.126 [Default:CheckIn](INFO): Running loop #13
2021-10-07T17:37:31.126Z,1633628251.126 [Default:CheckIn] Running Loop=13
2021-10-07T17:37:31.126Z,1633628251.126 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-07T17:37:31.126Z,1633628251.126 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-07T17:37:33.111Z,1633628253.111 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173732.00,A,3650.28675,N,12202.15011,W,15.143,280.50,071021,,,A*4E
2021-10-07T17:37:33.113Z,1633628253.113 [NAL9602](INFO): GPS fix at 20211007T173732: (36.838113, -122.035835)
2021-10-07T17:37:33.172Z,1633628253.172 [Default:CheckIn:Read_GPS] Stopped
2021-10-07T17:37:33.172Z,1633628253.172 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-07T17:37:41.167Z,1633628261.167 [DataOverHttps](INFO): Sending 84 bytes from file Logs/20211007T161603/Courier0043.lzma
2021-10-07T17:37:42.169Z,1633628262.169 [DataOverHttps](INFO): Moved sent file to Logs/20211007T161603/Courier0043.lzma.bak
2021-10-07T17:37:42.170Z,1633628262.170 [DataOverHttps](INFO): SBD MOMSN=15978409
2021-10-07T17:37:46.038Z,1633628266.038 [NAL9602](INFO): SBD MO Status=0, MOMSN=16175, MT Status=0, MTMSN=0
2021-10-07T17:37:46.038Z,1633628266.038 [NAL9602](INFO): No messages in MT queue
2021-10-07T17:38:00.875Z,1633628280.875 [DataOverHttps](INFO): Sending 147 bytes from file Logs/20211007T161603/Express0044.lzma
2021-10-07T17:38:01.874Z,1633628281.874 [DataOverHttps](INFO): Moved sent file to Logs/20211007T161603/Express0044.lzma.bak
2021-10-07T17:38:01.874Z,1633628281.874 [DataOverHttps](INFO): SBD MOMSN=15978412
2021-10-07T17:38:05.130Z,1633628285.130 [Default:CheckIn:Read_Iridium] Stopped
2021-10-07T17:38:05.131Z,1633628285.131 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-07T17:38:05.131Z,1633628285.131 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-07T17:38:16.864Z,1633628296.864 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-07T17:41:35.237Z,1633628495.237 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for water mass range.
2021-10-07T17:43:05.739Z,1633628585.739 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-07T17:43:05.739Z,1633628585.739 [Default:CheckIn:C.Wait] Stopped
2021-10-07T17:43:05.739Z,1633628585.739 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-07T17:43:05.739Z,1633628585.739 [Default:CheckIn:D] Running Loop=1
2021-10-07T17:43:06.148Z,1633628586.148 [Default:CheckIn:D] Stopped
2021-10-07T17:43:06.148Z,1633628586.148 [Default:CheckIn:E] Running Loop=1
2021-10-07T17:43:06.624Z,1633628586.624 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 83.040405 min 
2021-10-07T17:43:06.624Z,1633628586.624 [Default:CheckIn:E] Stopped
2021-10-07T17:43:06.624Z,1633628586.624 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-07T17:43:06.624Z,1633628586.624 [Default:CheckIn] Stopped
2021-10-07T17:43:06.625Z,1633628586.625 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-07T17:43:06.625Z,1633628586.625 [Default:CheckIn](INFO): Running loop #14
2021-10-07T17:43:06.625Z,1633628586.625 [Default:CheckIn] Running Loop=14
2021-10-07T17:43:06.625Z,1633628586.625 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-07T17:43:06.625Z,1633628586.625 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-07T17:43:08.555Z,1633628588.555 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174307.00,A,3650.62988,N,12203.58883,W,16.231,283.74,071021,,,A*43
2021-10-07T17:43:08.557Z,1633628588.557 [NAL9602](INFO): GPS fix at 20211007T174307: (36.843831, -122.059814)
2021-10-07T17:43:08.577Z,1633628588.577 [Default:CheckIn:Read_GPS] Stopped
2021-10-07T17:43:08.577Z,1633628588.577 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-07T17:43:11.648Z,1633628591.648 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20211007T161603/Courier0046.lzma
2021-10-07T17:43:12.653Z,1633628592.653 [DataOverHttps](INFO): Moved sent file to Logs/20211007T161603/Courier0046.lzma.bak
2021-10-07T17:43:12.654Z,1633628592.654 [DataOverHttps](INFO): SBD MOMSN=15978423
2021-10-07T17:43:26.079Z,1633628606.079 [NAL9602](INFO): SBD MO Status=0, MOMSN=16176, MT Status=0, MTMSN=0
2021-10-07T17:43:26.079Z,1633628606.079 [NAL9602](INFO): No messages in MT queue
2021-10-07T17:43:31.683Z,1633628611.683 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20211007T161603/Express0047.lzma
2021-10-07T17:43:32.685Z,1633628612.685 [DataOverHttps](INFO): Moved sent file to Logs/20211007T161603/Express0047.lzma.bak
2021-10-07T17:43:32.686Z,1633628612.686 [DataOverHttps](INFO): SBD MOMSN=15978426
2021-10-07T17:43:35.393Z,1633628615.393 [Default:CheckIn:Read_Iridium] Stopped
2021-10-07T17:43:35.393Z,1633628615.393 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-07T17:43:35.394Z,1633628615.394 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-07T17:43:56.789Z,1633628636.789 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-07T17:48:36.059Z,1633628916.059 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-07T17:48:36.059Z,1633628916.059 [Default:CheckIn:C.Wait] Stopped
2021-10-07T17:48:36.059Z,1633628916.059 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-07T17:48:36.059Z,1633628916.059 [Default:CheckIn:D] Running Loop=1
2021-10-07T17:48:36.469Z,1633628916.469 [Default:CheckIn:D] Stopped
2021-10-07T17:48:36.469Z,1633628916.469 [Default:CheckIn:E] Running Loop=1
2021-10-07T17:48:36.910Z,1633628916.910 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 88.545768 min 
2021-10-07T17:48:36.911Z,1633628916.911 [Default:CheckIn:E] Stopped
2021-10-07T17:48:36.911Z,1633628916.911 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-07T17:48:36.911Z,1633628916.911 [Default:CheckIn] Stopped
2021-10-07T17:48:36.911Z,1633628916.911 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-07T17:48:36.911Z,1633628916.911 [Default:CheckIn](INFO): Running loop #15
2021-10-07T17:48:36.912Z,1633628916.912 [Default:CheckIn] Running Loop=15
2021-10-07T17:48:36.912Z,1633628916.912 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-07T17:48:36.912Z,1633628916.912 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-07T17:48:38.886Z,1633628918.886 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174838.00,A,3650.88544,N,12205.21883,W,14.073,274.60,071021,,,A*4F
2021-10-07T17:48:38.888Z,1633628918.888 [NAL9602](INFO): GPS fix at 20211007T174838: (36.848091, -122.086980)
2021-10-07T17:48:38.945Z,1633628918.945 [Default:CheckIn:Read_GPS] Stopped
2021-10-07T17:48:38.945Z,1633628918.945 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-07T17:48:46.939Z,1633628926.939 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20211007T161603/Courier0049.lzma
2021-10-07T17:48:48.494Z,1633628928.494 [DataOverHttps](INFO): Moved sent file to Logs/20211007T161603/Courier0049.lzma.bak
2021-10-07T17:48:48.495Z,1633628928.495 [DataOverHttps](INFO): SBD MOMSN=15978440
2021-10-07T17:48:53.450Z,1633628933.450 [NAL9602](INFO): SBD MO Status=0, MOMSN=16177, MT Status=0, MTMSN=0
2021-10-07T17:48:53.450Z,1633628933.450 [NAL9602](INFO): No messages in MT queue
2021-10-07T17:49:07.110Z,1633628947.110 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20211007T161603/Express0050.lzma
2021-10-07T17:49:08.109Z,1633628948.109 [DataOverHttps](INFO): Moved sent file to Logs/20211007T161603/Express0050.lzma.bak
2021-10-07T17:49:08.110Z,1633628948.110 [DataOverHttps](INFO): SBD MOMSN=15978443
2021-10-07T17:49:10.899Z,1633628950.899 [Default:CheckIn:Read_Iridium] Stopped
2021-10-07T17:49:10.900Z,1633628950.900 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-07T17:49:10.900Z,1633628950.900 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-07T17:49:24.149Z,1633628964.149 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-07T17:54:11.530Z,1633629251.530 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-07T17:54:11.530Z,1633629251.530 [Default:CheckIn:C.Wait] Stopped
2021-10-07T17:54:11.530Z,1633629251.530 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-07T17:54:11.530Z,1633629251.530 [Default:CheckIn:D] Running Loop=1
2021-10-07T17:54:11.902Z,1633629251.902 [Default:CheckIn:D] Stopped
2021-10-07T17:54:11.902Z,1633629251.902 [Default:CheckIn:E] Running Loop=1
2021-10-07T17:54:12.307Z,1633629252.307 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 94.136320 min 
2021-10-07T17:54:12.307Z,1633629252.307 [Default:CheckIn:E] Stopped
2021-10-07T17:54:12.307Z,1633629252.307 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-07T17:54:12.307Z,1633629252.307 [Default:CheckIn] Stopped
2021-10-07T17:54:12.308Z,1633629252.308 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-07T17:54:12.308Z,1633629252.308 [Default:CheckIn](INFO): Running loop #16
2021-10-07T17:54:12.308Z,1633629252.308 [Default:CheckIn] Running Loop=16
2021-10-07T17:54:12.308Z,1633629252.308 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-07T17:54:12.308Z,1633629252.308 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-07T17:54:14.280Z,1633629254.280 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175413.00,A,3650.79278,N,12206.70174,W,15.026,243.30,071021,,,D*4E
2021-10-07T17:54:14.283Z,1633629254.283 [NAL9602](INFO): GPS fix at 20211007T175413: (36.846546, -122.111696)
2021-10-07T17:54:14.303Z,1633629254.303 [Default:CheckIn:Read_GPS] Stopped
2021-10-07T17:54:14.303Z,1633629254.303 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-07T17:54:23.340Z,1633629263.340 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20211007T161603/Courier0052.lzma
2021-10-07T17:54:24.337Z,1633629264.337 [DataOverHttps](INFO): Moved sent file to Logs/20211007T161603/Courier0052.lzma.bak
2021-10-07T17:54:24.338Z,1633629264.338 [DataOverHttps](INFO): SBD MOMSN=15978456
2021-10-07T17:54:31.390Z,1633629271.390 [NAL9602](INFO): SBD MO Status=0, MOMSN=16178, MT Status=0, MTMSN=0
2021-10-07T17:54:31.390Z,1633629271.390 [NAL9602](INFO): No messages in MT queue
2021-10-07T17:54:44.451Z,1633629284.451 [DataOverHttps](INFO): Sending 141 bytes from file Logs/20211007T161603/Express0053.lzma
2021-10-07T17:54:45.453Z,1633629285.453 [DataOverHttps](INFO): Moved sent file to Logs/20211007T161603/Express0053.lzma.bak
2021-10-07T17:54:45.454Z,1633629285.454 [DataOverHttps](INFO): SBD MOMSN=15978459
2021-10-07T17:54:48.383Z,1633629288.383 [Default:CheckIn:Read_Iridium] Stopped
2021-10-07T17:54:48.388Z,1633629288.388 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-07T17:54:48.388Z,1633629288.388 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-07T17:55:02.081Z,1633629302.081 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-07T17:59:48.983Z,1633629588.983 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-07T17:59:48.984Z,1633629588.984 [Default:CheckIn:C.Wait] Stopped
2021-10-07T17:59:48.984Z,1633629588.984 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-07T17:59:48.984Z,1633629588.984 [Default:CheckIn:D] Running Loop=1
2021-10-07T17:59:49.335Z,1633629589.335 [Default:CheckIn:D] Stopped
2021-10-07T17:59:49.335Z,1633629589.335 [Default:CheckIn:E] Running Loop=1
2021-10-07T17:59:49.741Z,1633629589.741 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 99.760197 min 
2021-10-07T17:59:49.741Z,1633629589.741 [Default:CheckIn:E] Stopped
2021-10-07T17:59:49.741Z,1633629589.741 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-07T17:59:49.742Z,1633629589.742 [Default:CheckIn] Stopped
2021-10-07T17:59:49.742Z,1633629589.742 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-07T17:59:49.742Z,1633629589.742 [Default:CheckIn](INFO): Running loop #17
2021-10-07T17:59:49.742Z,1633629589.742 [Default:CheckIn] Running Loop=17
2021-10-07T17:59:49.742Z,1633629589.742 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-07T17:59:49.742Z,1633629589.742 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-07T17:59:51.751Z,1633629591.751 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175951.00,A,3650.42946,N,12208.20472,W,14.968,242.32,071021,,,D*42
2021-10-07T17:59:51.753Z,1633629591.753 [NAL9602](INFO): GPS fix at 20211007T175951: (36.840491, -122.136745)
2021-10-07T17:59:51.765Z,1633629591.765 [Default:CheckIn:Read_GPS] Stopped
2021-10-07T17:59:51.765Z,1633629591.765 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-07T18:00:01.035Z,1633629601.035 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20211007T161603/Courier0055.lzma
2021-10-07T18:00:02.037Z,1633629602.037 [DataOverHttps](INFO): Moved sent file to Logs/20211007T161603/Courier0055.lzma.bak
2021-10-07T18:00:02.038Z,1633629602.038 [DataOverHttps](INFO): SBD MOMSN=15978471
2021-10-07T18:00:06.774Z,1633629606.774 [NAL9602](INFO): SBD MO Status=0, MOMSN=16179, MT Status=0, MTMSN=0
2021-10-07T18:00:06.775Z,1633629606.775 [NAL9602](INFO): No messages in MT queue
2021-10-07T18:00:25.147Z,1633629625.147 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20211007T161603/Express0056.lzma
2021-10-07T18:00:26.153Z,1633629626.153 [DataOverHttps](INFO): Moved sent file to Logs/20211007T161603/Express0056.lzma.bak
2021-10-07T18:00:26.154Z,1633629626.154 [DataOverHttps](INFO): SBD MOMSN=15978474
2021-10-07T18:00:29.139Z,1633629629.139 [Default:CheckIn:Read_Iridium] Stopped
2021-10-07T18:00:29.139Z,1633629629.139 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-07T18:00:29.139Z,1633629629.139 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-07T18:00:37.541Z,1633629637.541 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-07T18:05:29.749Z,1633629929.749 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-07T18:05:29.750Z,1633629929.750 [Default:CheckIn:C.Wait] Stopped
2021-10-07T18:05:29.750Z,1633629929.750 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-07T18:05:29.751Z,1633629929.751 [Default:CheckIn:D] Running Loop=1
2021-10-07T18:05:30.163Z,1633629930.163 [Default:CheckIn:D] Stopped
2021-10-07T18:05:30.163Z,1633629930.163 [Default:CheckIn:E] Running Loop=1
2021-10-07T18:05:30.577Z,1633629930.577 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 105.440658 min 
2021-10-07T18:05:30.577Z,1633629930.577 [Default:CheckIn:E] Stopped
2021-10-07T18:05:30.577Z,1633629930.577 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-07T18:05:30.577Z,1633629930.577 [Default:CheckIn] Stopped
2021-10-07T18:05:30.578Z,1633629930.578 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-07T18:05:30.578Z,1633629930.578 [Default:CheckIn](INFO): Running loop #18
2021-10-07T18:05:30.578Z,1633629930.578 [Default:CheckIn] Running Loop=18
2021-10-07T18:05:30.578Z,1633629930.578 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-07T18:05:30.578Z,1633629930.578 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-07T18:05:32.567Z,1633629932.567 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180531.00,A,3649.58601,N,12209.18221,W,6.337,104.66,071021,,,D*74
2021-10-07T18:05:32.569Z,1633629932.569 [NAL9602](INFO): GPS fix at 20211007T180531: (36.826434, -122.153037)
2021-10-07T18:05:32.580Z,1633629932.580 [Default:CheckIn:Read_GPS] Stopped
2021-10-07T18:05:32.580Z,1633629932.580 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-07T18:05:44.371Z,1633629944.371 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20211007T161603/Courier0058.lzma
2021-10-07T18:05:46.377Z,1633629946.377 [DataOverHttps](INFO): Moved sent file to Logs/20211007T161603/Courier0058.lzma.bak
2021-10-07T18:05:46.378Z,1633629946.378 [DataOverHttps](INFO): SBD MOMSN=15978488
2021-10-07T18:06:03.672Z,1633629963.672 [NAL9602](INFO): SBD MO Status=0, MOMSN=16180, MT Status=0, MTMSN=0
2021-10-07T18:06:03.672Z,1633629963.672 [NAL9602](INFO): No messages in MT queue
2021-10-07T18:06:04.115Z,1633629964.115 [DataOverHttps](INFO): Sending 147 bytes from file Logs/20211007T161603/Express0059.lzma
2021-10-07T18:06:05.118Z,1633629965.118 [DataOverHttps](INFO): Moved sent file to Logs/20211007T161603/Express0059.lzma.bak
2021-10-07T18:06:05.118Z,1633629965.118 [DataOverHttps](INFO): SBD MOMSN=15978491
2021-10-07T18:06:10.613Z,1633629970.613 [Default:CheckIn:Read_Iridium] Stopped
2021-10-07T18:06:10.613Z,1633629970.613 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-07T18:06:10.613Z,1633629970.613 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-07T18:06:34.154Z,1633629994.154 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-07T18:11:03.836Z,1633630263.836 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-07T18:11:08.864Z,1633630268.864 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.275589
2021-10-07T18:11:11.341Z,1633630271.341 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-07T18:11:11.341Z,1633630271.341 [Default:CheckIn:C.Wait] Stopped
2021-10-07T18:11:11.341Z,1633630271.341 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-07T18:11:11.341Z,1633630271.341 [Default:CheckIn:D] Running Loop=1
2021-10-07T18:11:11.734Z,1633630271.734 [Default:CheckIn:D] Stopped
2021-10-07T18:11:11.735Z,1633630271.735 [Default:CheckIn:E] Running Loop=1
2021-10-07T18:11:12.147Z,1633630272.147 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 111.133521 min 
2021-10-07T18:11:12.148Z,1633630272.148 [Default:CheckIn:E] Stopped
2021-10-07T18:11:12.148Z,1633630272.148 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-07T18:11:12.148Z,1633630272.148 [Default:CheckIn] Stopped
2021-10-07T18:11:12.148Z,1633630272.148 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-07T18:11:12.148Z,1633630272.148 [Default:CheckIn](INFO): Running loop #19
2021-10-07T18:11:12.148Z,1633630272.148 [Default:CheckIn] Running Loop=19
2021-10-07T18:11:12.148Z,1633630272.148 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-07T18:11:12.148Z,1633630272.148 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-07T18:11:14.152Z,1633630274.152 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181113.00,A,3649.47845,N,12208.84823,W,2.371,117.02,071021,,,D*7B
2021-10-07T18:11:14.155Z,1633630274.155 [NAL9602](INFO): GPS fix at 20211007T181113: (36.824641, -122.147470)
2021-10-07T18:11:14.166Z,1633630274.166 [Default:CheckIn:Read_GPS] Stopped
2021-10-07T18:11:14.167Z,1633630274.167 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-07T18:11:28.554Z,1633630288.554 [NAL9602](INFO): SBD MO Status=1, MOMSN=16181, MT Status=0, MTMSN=0
2021-10-07T18:11:28.600Z,1633630288.600 [NAL9602](INFO): Sent 73 bytes from file Logs/20211007T161603/Courier0061.lzma
2021-10-07T18:11:28.600Z,1633630288.600 [NAL9602](INFO): Packets left to send: 0
2021-10-07T18:11:40.230Z,1633630300.230 [NAL9602](INFO): SBD MO Status=1, MOMSN=16182, MT Status=0, MTMSN=0
2021-10-07T18:11:40.280Z,1633630300.280 [NAL9602](INFO): Sent 138 bytes from file Logs/20211007T161603/Express0062.lzma
2021-10-07T18:11:40.280Z,1633630300.280 [NAL9602](INFO): Packets left to send: 0
2021-10-07T18:11:48.967Z,1633630308.967 [NAL9602](INFO): SBD MO Status=0, MOMSN=16183, MT Status=0, MTMSN=0
2021-10-07T18:11:49.146Z,1633630309.146 [Default:CheckIn:Read_Iridium] Stopped
2021-10-07T18:11:49.146Z,1633630309.146 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-07T18:11:49.147Z,1633630309.147 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-07T18:11:51.716Z,1633630311.716 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002809
2021-10-07T18:12:19.669Z,1633630339.669 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-07T18:16:49.601Z,1633630609.601 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-07T18:16:49.602Z,1633630609.602 [Default:CheckIn:C.Wait] Stopped
2021-10-07T18:16:49.602Z,1633630609.602 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-07T18:16:49.602Z,1633630609.602 [Default:CheckIn:D] Running Loop=1
2021-10-07T18:16:49.997Z,1633630609.997 [Default:CheckIn:D] Stopped
2021-10-07T18:16:49.997Z,1633630609.997 [Default:CheckIn:E] Running Loop=1
2021-10-07T18:16:50.400Z,1633630610.400 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 116.771232 min 
2021-10-07T18:16:50.400Z,1633630610.400 [Default:CheckIn:E] Stopped
2021-10-07T18:16:50.400Z,1633630610.400 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-07T18:16:50.401Z,1633630610.401 [Default:CheckIn] Stopped
2021-10-07T18:16:50.401Z,1633630610.401 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-07T18:16:50.401Z,1633630610.401 [Default:CheckIn](INFO): Running loop #20
2021-10-07T18:16:50.401Z,1633630610.401 [Default:CheckIn] Running Loop=20
2021-10-07T18:16:50.401Z,1633630610.401 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-07T18:16:50.401Z,1633630610.401 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-07T18:16:52.411Z,1633630612.411 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181651.00,A,3649.33384,N,12208.59264,W,1.536,132.80,071021,,,A*78
2021-10-07T18:16:52.422Z,1633630612.422 [NAL9602](INFO): GPS fix at 20211007T181651: (36.822231, -122.143211)
2021-10-07T18:16:52.434Z,1633630612.434 [Default:CheckIn:Read_GPS] Stopped
2021-10-07T18:16:52.434Z,1633630612.434 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-07T18:16:59.855Z,1633630619.855 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20211007T161603/Courier0064.lzma
2021-10-07T18:17:00.858Z,1633630620.858 [DataOverHttps](INFO): Moved sent file to Logs/20211007T161603/Courier0064.lzma.bak
2021-10-07T18:17:00.858Z,1633630620.858 [DataOverHttps](INFO): SBD MOMSN=15978514
2021-10-07T18:17:07.363Z,1633630627.363 [NAL9602](INFO): SBD MO Status=0, MOMSN=16184, MT Status=0, MTMSN=0
2021-10-07T18:17:07.363Z,1633630627.363 [NAL9602](INFO): No messages in MT queue
2021-10-07T18:17:21.535Z,1633630641.535 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20211007T161603/Express0065.lzma
2021-10-07T18:17:22.537Z,1633630642.537 [DataOverHttps](INFO): Moved sent file to Logs/20211007T161603/Express0065.lzma.bak
2021-10-07T18:17:22.538Z,1633630642.538 [DataOverHttps](INFO): SBD MOMSN=15978517
2021-10-07T18:17:25.217Z,1633630645.217 [Default:CheckIn:Read_Iridium] Stopped
2021-10-07T18:17:25.217Z,1633630645.217 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-07T18:17:25.217Z,1633630645.217 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-07T18:17:38.057Z,1633630658.057 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-07T18:20:04.765Z,1633630804.765 [DataOverHttps](IMPORTANT): SBD MTMSN=20211007T182004
2021-10-07T18:20:16.955Z,1633630816.955 [DataOverHttps](INFO): Received command: restart logs