2023-11-16T20:02:14.676Z,1700164934.676 [Supervisor](DEBUG): Initializing supervisor.
2023-11-16T20:02:14.680Z,1700164934.680 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2023-11-16T20:02:14.681Z,1700164934.681 [SyncHandler](INFO): Protected caller Thread ID is 5933
2023-11-16T20:02:14.681Z,1700164934.681 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2023-11-16T20:02:14.682Z,1700164934.682 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2023-11-16T20:02:14.682Z,1700164934.682 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 5934
2023-11-16T20:02:14.686Z,1700164934.686 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2023-11-16T20:02:14.704Z,1700164934.704 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2023-11-16T20:02:14.705Z,1700164934.705 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2023-11-16T20:02:14.706Z,1700164934.706 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 5935
2023-11-16T20:02:14.710Z,1700164934.710 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2023-11-16T20:02:14.711Z,1700164934.711 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2023-11-16T20:02:14.711Z,1700164934.711 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 5936
2023-11-16T20:02:14.713Z,1700164934.713 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2023-11-16T20:02:14.714Z,1700164934.714 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2023-11-16T20:02:14.715Z,1700164934.715 [logger ThreadHandler](INFO): Protected caller Thread ID is 5937
2023-11-16T20:02:14.718Z,1700164934.718 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2023-11-16T20:02:14.719Z,1700164934.719 [Supervisor](INFO): Looking for Config files in directory: Config/
2023-11-16T20:02:14.723Z,1700164934.723 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2023-11-16T20:02:15.001Z,1700164935.001 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2023-11-16T20:02:15.002Z,1700164935.002 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2023-11-16T20:02:15.113Z,1700164935.113 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2023-11-16T20:02:15.114Z,1700164935.114 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2023-11-16T20:02:15.213Z,1700164935.213 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2023-11-16T20:02:15.215Z,1700164935.215 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2023-11-16T20:02:15.697Z,1700164935.697 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2023-11-16T20:02:15.698Z,1700164935.698 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2023-11-16T20:02:16.053Z,1700164936.053 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2023-11-16T20:02:16.054Z,1700164936.054 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2023-11-16T20:02:16.391Z,1700164936.391 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2023-11-16T20:02:16.391Z,1700164936.391 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2023-11-16T20:02:16.585Z,1700164936.585 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2023-11-16T20:02:16.586Z,1700164936.586 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2023-11-16T20:02:16.670Z,1700164936.670 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2023-11-16T20:02:16.755Z,1700164936.755 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2023-11-16T20:02:17.166Z,1700164937.166 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2023-11-16T20:02:17.167Z,1700164937.167 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2023-11-16T20:02:17.454Z,1700164937.454 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2023-11-16T20:02:17.455Z,1700164937.455 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2023-11-16T20:02:17.985Z,1700164937.985 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2023-11-16T20:02:17.987Z,1700164937.987 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2023-11-16T20:02:18.216Z,1700164938.216 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2023-11-16T20:02:18.217Z,1700164938.217 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2023-11-16T20:02:18.457Z,1700164938.457 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2023-11-16T20:02:18.458Z,1700164938.458 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2023-11-16T20:02:18.602Z,1700164938.602 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2023-11-16T20:02:18.603Z,1700164938.603 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2023-11-16T20:02:19.435Z,1700164939.435 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2023-11-16T20:02:19.438Z,1700164939.438 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-galene/
2023-11-16T20:02:19.439Z,1700164939.439 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/secure.cfg
2023-11-16T20:02:19.527Z,1700164939.527 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/vehicle.cfg
2023-11-16T20:02:19.676Z,1700164939.676 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Battery.cfg
2023-11-16T20:02:20.670Z,1700164940.670 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2023-11-16T20:02:20.671Z,1700164940.671 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Science.cfg
2023-11-16T20:02:20.811Z,1700164940.811 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Control.cfg
2023-11-16T20:02:20.921Z,1700164940.921 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/logger.cfg
2023-11-16T20:02:21.019Z,1700164941.019 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Servo.cfg
2023-11-16T20:02:21.132Z,1700164941.132 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Navigation.cfg
2023-11-16T20:02:21.231Z,1700164941.231 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Simulator.cfg
2023-11-16T20:02:21.321Z,1700164941.321 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/BIT.cfg
2023-11-16T20:02:21.426Z,1700164941.426 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Sensor.cfg
2023-11-16T20:02:21.601Z,1700164941.601 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2023-11-16T20:02:21.624Z,1700164941.624 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2023-11-16T20:02:21.694Z,1700164941.694 [DepthRateCalculator] Loaded
2023-11-16T20:02:21.694Z,1700164941.694 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2023-11-16T20:02:21.699Z,1700164941.699 [PitchRateCalculator] Loaded
2023-11-16T20:02:21.700Z,1700164941.700 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2023-11-16T20:02:21.710Z,1700164941.710 [SpeedCalculator] Loaded
2023-11-16T20:02:21.710Z,1700164941.710 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2023-11-16T20:02:21.715Z,1700164941.715 [YawRateCalculator] Loaded
2023-11-16T20:02:21.716Z,1700164941.716 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2023-11-16T20:02:21.737Z,1700164941.737 [ElevatorOffsetCalculator] Loaded
2023-11-16T20:02:21.738Z,1700164941.738 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2023-11-16T20:02:21.738Z,1700164941.738 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2023-11-16T20:02:21.739Z,1700164941.739 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2023-11-16T20:02:21.781Z,1700164941.781 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2023-11-16T20:02:21.782Z,1700164941.782 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2023-11-16T20:02:21.797Z,1700164941.797 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2023-11-16T20:02:21.797Z,1700164941.797 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2023-11-16T20:02:22.526Z,1700164942.526 [AHRS_M2] Loaded
2023-11-16T20:02:22.526Z,1700164942.526 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2023-11-16T20:02:22.776Z,1700164942.776 [BackseatComponent] Loaded
2023-11-16T20:02:22.776Z,1700164942.776 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2023-11-16T20:02:22.778Z,1700164942.778 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 4084E4E0
2023-11-16T20:02:22.778Z,1700164942.778 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 6019
2023-11-16T20:02:22.781Z,1700164942.781 [LcmUniversalReporter] Loaded
2023-11-16T20:02:22.781Z,1700164942.781 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2023-11-16T20:02:23.583Z,1700164943.583 [BPC1] Loaded
2023-11-16T20:02:23.583Z,1700164943.583 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2023-11-16T20:02:23.677Z,1700164943.677 [DataOverHttps] Loaded
2023-11-16T20:02:23.677Z,1700164943.677 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2023-11-16T20:02:23.678Z,1700164943.678 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4087E4E0
2023-11-16T20:02:23.679Z,1700164943.679 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 6020
2023-11-16T20:02:23.700Z,1700164943.700 [Depth_Keller] Loaded
2023-11-16T20:02:23.700Z,1700164943.700 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2023-11-16T20:02:23.705Z,1700164943.705 [DropWeight] Loaded
2023-11-16T20:02:23.705Z,1700164943.705 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2023-11-16T20:02:23.724Z,1700164943.724 [MultiRay] Loaded
2023-11-16T20:02:23.724Z,1700164943.724 [ComponentRegistry](DEBUG): SyncComponent "MultiRay" handled in the control thread.
2023-11-16T20:02:23.787Z,1700164943.787 [NAL9602] Loaded
2023-11-16T20:02:23.787Z,1700164943.787 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2023-11-16T20:02:23.818Z,1700164943.818 [Onboard] Loaded
2023-11-16T20:02:23.818Z,1700164943.818 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2023-11-16T20:02:23.819Z,1700164943.819 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408AE4E0
2023-11-16T20:02:23.819Z,1700164943.819 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 6021
2023-11-16T20:02:23.825Z,1700164943.825 [PowerOnly](INFO): Adding load control power supply at /dev/loadC3
2023-11-16T20:02:23.837Z,1700164943.837 [PowerOnly] Loaded
2023-11-16T20:02:23.837Z,1700164943.837 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2023-11-16T20:02:23.849Z,1700164943.849 [Power24vConverter] Loaded
2023-11-16T20:02:23.849Z,1700164943.849 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2023-11-16T20:02:23.863Z,1700164943.863 [Radio_Surface] Loaded
2023-11-16T20:02:23.863Z,1700164943.863 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2023-11-16T20:02:23.865Z,1700164943.865 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408DE4E0
2023-11-16T20:02:23.865Z,1700164943.865 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 6022
2023-11-16T20:02:23.866Z,1700164943.866 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2023-11-16T20:02:23.867Z,1700164943.867 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2023-11-16T20:02:24.002Z,1700164944.002 [DeadReckonUsingMultipleVelocitySources] Loaded
2023-11-16T20:02:24.002Z,1700164944.002 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2023-11-16T20:02:24.045Z,1700164944.045 [DeadReckonUsingSpeedCalculator] Loaded
2023-11-16T20:02:24.046Z,1700164944.046 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2023-11-16T20:02:24.059Z,1700164944.059 [NavChart] Loaded
2023-11-16T20:02:24.060Z,1700164944.060 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2023-11-16T20:02:24.065Z,1700164944.065 [UniversalFixResidualReporter] Loaded
2023-11-16T20:02:24.066Z,1700164944.066 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2023-11-16T20:02:24.066Z,1700164944.066 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2023-11-16T20:02:24.067Z,1700164944.067 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2023-11-16T20:02:24.229Z,1700164944.229 [SBIT](DEBUG): Construct Startup Built In Test.
2023-11-16T20:02:24.243Z,1700164944.243 [SBIT] Loaded
2023-11-16T20:02:24.243Z,1700164944.243 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2023-11-16T20:02:24.246Z,1700164944.246 [IBIT](DEBUG): Construct Initiated Built In Test.
2023-11-16T20:02:24.258Z,1700164944.258 [IBIT] Loaded
2023-11-16T20:02:24.259Z,1700164944.259 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2023-11-16T20:02:24.264Z,1700164944.264 [CBIT](DEBUG): Construct Continuous Built In Test.
2023-11-16T20:02:24.368Z,1700164944.368 [CBIT] Loaded
2023-11-16T20:02:24.368Z,1700164944.368 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2023-11-16T20:02:24.369Z,1700164944.369 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2023-11-16T20:02:24.369Z,1700164944.369 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2023-11-16T20:02:24.587Z,1700164944.587 [CTD_Seabird] Loaded
2023-11-16T20:02:24.587Z,1700164944.587 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2023-11-16T20:02:24.588Z,1700164944.588 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409E54E0
2023-11-16T20:02:24.589Z,1700164944.589 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 6023
2023-11-16T20:02:24.609Z,1700164944.609 [PAR_Licor] Loaded
2023-11-16T20:02:24.609Z,1700164944.609 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2023-11-16T20:02:24.650Z,1700164944.650 [WetLabsBB2FL] Loaded
2023-11-16T20:02:24.650Z,1700164944.650 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2023-11-16T20:02:24.651Z,1700164944.651 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A154E0
2023-11-16T20:02:24.652Z,1700164944.652 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 6024
2023-11-16T20:02:24.653Z,1700164944.653 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2023-11-16T20:02:24.653Z,1700164944.653 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2023-11-16T20:02:24.821Z,1700164944.821 [BuoyancyServo] Loaded
2023-11-16T20:02:24.822Z,1700164944.822 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2023-11-16T20:02:24.927Z,1700164944.927 [ElevatorServo] Loaded
2023-11-16T20:02:24.927Z,1700164944.927 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2023-11-16T20:02:24.949Z,1700164944.949 [MassServo] Loaded
2023-11-16T20:02:24.949Z,1700164944.949 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2023-11-16T20:02:24.970Z,1700164944.970 [RudderServo] Loaded
2023-11-16T20:02:24.970Z,1700164944.970 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2023-11-16T20:02:24.986Z,1700164944.986 [ThrusterHE] Loaded
2023-11-16T20:02:24.986Z,1700164944.986 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2023-11-16T20:02:24.987Z,1700164944.987 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2023-11-16T20:02:24.987Z,1700164944.987 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2023-11-16T20:02:25.054Z,1700164945.054 [VerticalControl](DEBUG): Construct VerticalControl.
2023-11-16T20:02:25.104Z,1700164945.104 [VerticalControl] Loaded
2023-11-16T20:02:25.104Z,1700164945.104 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2023-11-16T20:02:25.107Z,1700164945.107 [HorizontalControl](DEBUG): Construct HorizontalControl.
2023-11-16T20:02:25.144Z,1700164945.144 [HorizontalControl] Loaded
2023-11-16T20:02:25.144Z,1700164945.144 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2023-11-16T20:02:25.147Z,1700164945.147 [SpeedControl](DEBUG): Construct SpeedControl.
2023-11-16T20:02:25.149Z,1700164945.149 [SpeedControl] Loaded
2023-11-16T20:02:25.149Z,1700164945.149 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2023-11-16T20:02:25.152Z,1700164945.152 [LoopControl](DEBUG): Construct LoopControl.
2023-11-16T20:02:25.152Z,1700164945.152 [LoopControl] Loaded
2023-11-16T20:02:25.153Z,1700164945.153 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2023-11-16T20:02:25.153Z,1700164945.153 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2023-11-16T20:02:25.154Z,1700164945.154 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2023-11-16T20:02:25.281Z,1700164945.281 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2023-11-16T20:02:25.281Z,1700164945.281 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2023-11-16T20:02:25.501Z,1700164945.501 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2023-11-16T20:02:25.502Z,1700164945.502 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2023-11-16T20:02:25.871Z,1700164945.871 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2023-11-16T20:02:25.871Z,1700164945.871 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2023-11-16T20:02:25.972Z,1700164945.972 [StratificationFrontDetector](INFO): thresholdVTHI set to: 0.399988 degC
2023-11-16T20:02:25.972Z,1700164945.972 [StratificationFrontDetector](DEBUG): (re)initializing
2023-11-16T20:02:25.973Z,1700164945.973 [StratificationFrontDetector] Loaded
2023-11-16T20:02:25.973Z,1700164945.973 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2023-11-16T20:02:25.973Z,1700164945.973 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2023-11-16T20:02:25.980Z,1700164945.980 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2023-11-16T20:02:25.983Z,1700164945.983 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2023-11-16T20:02:25.994Z,1700164945.994 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2023-11-16T20:02:25.995Z,1700164945.995 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BCB4E0
2023-11-16T20:02:25.995Z,1700164945.995 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 6025
2023-11-16T20:02:25.000Z,1700164946.000 [Supervisor](INFO): Main Thread ID is 5932
2023-11-16T20:02:26.000Z,1700164946.000 [Supervisor](DEBUG): Running supervisor.
2023-11-16T20:02:26.001Z,1700164946.001 [CommandExec ThreadHandler](INFO): Handler Thread ID is 6026
2023-11-16T20:02:26.001Z,1700164946.001 [CommandExec](INFO): Initializing the command executive.
2023-11-16T20:02:26.003Z,1700164946.003 [CommandLine ThreadHandler](INFO): Handler Thread ID is 6027
2023-11-16T20:02:26.005Z,1700164946.005 [controlThread ThreadHandler](INFO): Handler Thread ID is 6028
2023-11-16T20:02:26.005Z,1700164946.005 [controlThread](DEBUG): Initializing ControlThread
2023-11-16T20:02:26.006Z,1700164946.006 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2023-11-16T20:02:26.006Z,1700164946.006 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2023-11-16T20:02:26.007Z,1700164946.007 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2023-11-16T20:02:26.007Z,1700164946.007 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2023-11-16T20:02:26.008Z,1700164946.008 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2023-11-16T20:02:26.015Z,1700164946.015 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-11-16T20:02:26.015Z,1700164946.015 [NavChart](DEBUG): Initialize NavChart Navigation.
2023-11-16T20:02:26.016Z,1700164946.016 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2023-11-16T20:02:26.017Z,1700164946.017 [SBIT](INFO): Initialize SBIT Component.
2023-11-16T20:02:26.017Z,1700164946.017 [SBIT](IMPORTANT): git: 2023-09-18-3-g7ee55e0de
2023-11-16T20:02:26.017Z,1700164946.017 [SBIT](INFO): git hash: 7ee55e0ded82548f5c252ba0d9a41930617440e4
2023-11-16T20:02:26.018Z,1700164946.018 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2023-11-16T20:02:26.019Z,1700164946.019 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2023-11-16T20:02:26.020Z,1700164946.020 [SBIT](INFO): Beginning SBIT in 47.000000 seconds.
2023-11-16T20:02:26.021Z,1700164946.021 [IBIT](INFO): Initialize IBIT Component.
2023-11-16T20:02:26.021Z,1700164946.021 [CBIT](DEBUG): Initialize CBIT Component.
2023-11-16T20:02:26.022Z,1700164946.022 [logger ThreadHandler](INFO): Handler Thread ID is 6029
2023-11-16T20:02:26.032Z,1700164946.032 [CBIT](DEBUG): Initialized mux pins.
2023-11-16T20:02:26.032Z,1700164946.032 [CBIT](DEBUG): Initializing the watchdog timer.
2023-11-16T20:02:26.045Z,1700164946.045 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 6030
2023-11-16T20:02:26.053Z,1700164946.053 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 6031
2023-11-16T20:02:26.054Z,1700164946.054 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2023-11-16T20:02:26.056Z,1700164946.056 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2023-11-16T20:02:26.057Z,1700164946.057 [CBIT](DEBUG): Initializing heartbeat.
2023-11-16T20:02:26.065Z,1700164946.065 [Onboard ThreadHandler](INFO): Handler Thread ID is 6032
2023-11-16T20:02:26.082Z,1700164946.082 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 6033
2023-11-16T20:02:26.105Z,1700164946.105 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 6034
2023-11-16T20:02:26.106Z,1700164946.106 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2023-11-16T20:02:26.110Z,1700164946.110 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 6036
2023-11-16T20:02:26.113Z,1700164946.113 [WetLabsBB2FL](INFO): Powering up
2023-11-16T20:02:26.114Z,1700164946.114 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 6038
2023-11-16T20:02:26.120Z,1700164946.120 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2023-11-16T20:02:26.120Z,1700164946.120 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2023-11-16T20:02:26.121Z,1700164946.121 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2023-11-16T20:02:26.121Z,1700164946.121 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2023-11-16T20:02:26.121Z,1700164946.121 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2023-11-16T20:02:26.121Z,1700164946.121 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2023-11-16T20:02:26.121Z,1700164946.121 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2023-11-16T20:02:26.121Z,1700164946.121 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2023-11-16T20:02:26.128Z,1700164946.128 [CBIT](DEBUG): Deactivating GF circuits.
2023-11-16T20:02:26.128Z,1700164946.128 [CBIT](DEBUG): Deactivating emergency mode.
2023-11-16T20:02:26.168Z,1700164946.168 [CBIT](DEBUG): Backplane powered.
2023-11-16T20:02:26.174Z,1700164946.174 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2023-11-16T20:02:26.175Z,1700164946.175 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2023-11-16T20:02:26.176Z,1700164946.176 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2023-11-16T20:02:26.177Z,1700164946.177 [LoopControl](DEBUG): Initialize LoopControlComponent.
2023-11-16T20:02:26.178Z,1700164946.178 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2023-11-16T20:02:26.214Z,1700164946.214 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2023-11-16T20:02:26.239Z,1700164946.239 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

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

    <Aggregate Id="StartupSatComms">

        <Sequence/>

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

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

    </Aggregate>

</Mission>


2023-11-16T20:02:26.240Z,1700164946.240 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2023-11-16T20:02:26.313Z,1700164946.313 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2023-11-16T20:02:26.315Z,1700164946.315 [Default:A.Wait](DEBUG): Construct Wait.
2023-11-16T20:02:26.317Z,1700164946.317 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-11-16T20:02:26.328Z,1700164946.328 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2023-11-16T20:02:26.331Z,1700164946.331 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2023-11-16T20:02:26.358Z,1700164946.358 [Default:E.Execute](DEBUG): Construct Execute.
2023-11-16T20:02:26.361Z,1700164946.361 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

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

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

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

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

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

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

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

    </Aggregate>

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

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

</Mission>


2023-11-16T20:02:26.376Z,1700164946.376 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,MultiRay,NAL9602,PowerOnly,Power24vConverter,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2023-11-16T20:02:26.383Z,1700164946.383 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-11-16T20:02:26.488Z,1700164946.488 [Radio_Surface](INFO): Powering up
2023-11-16T20:02:26.517Z,1700164946.517 [Depth_Keller](ERROR): Pressure or depth reading out of range: 816.065491 decibar, 0.000000 m
2023-11-16T20:02:26.518Z,1700164946.518 [MultiRay](INFO): Powering up MultiRay Lights
2023-11-16T20:02:26.557Z,1700164946.557 [Power24vConverter](INFO): Powering up.
2023-11-16T20:02:26.580Z,1700164946.580 [DepthRateCalculator](ERROR): Depth measurement is not active
2023-11-16T20:02:26.605Z,1700164946.605 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2023-11-16T20:02:26.613Z,1700164946.613 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2023-11-16T20:02:26.614Z,1700164946.614 [ElevatorServo](DEBUG): Initializing EZServoServo.
2023-11-16T20:02:26.620Z,1700164946.620 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2023-11-16T20:02:26.621Z,1700164946.621 [MassServo](DEBUG): Initializing EZServoServo.
2023-11-16T20:02:26.629Z,1700164946.629 [MassServo](DEBUG): Initializing MassServo.
2023-11-16T20:02:26.630Z,1700164946.630 [RudderServo](DEBUG): Initializing EZServoServo.
2023-11-16T20:02:26.637Z,1700164946.637 [RudderServo](DEBUG): Initializing RudderServo.
2023-11-16T20:02:26.637Z,1700164946.637 [ThrusterHE](DEBUG): Initializing EZServoServo.
2023-11-16T20:02:26.649Z,1700164946.649 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2023-11-16T20:02:26.827Z,1700164946.827 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2023-11-16T20:02:26.827Z,1700164946.827 [DropWeight] Hardware Fault, FailCount= 1
2023-11-16T20:02:26.827Z,1700164946.827 [DropWeight](ERROR): Hardware Fault
2023-11-16T20:02:26.888Z,1700164946.888 [CommandExec](FAULT): Scheduling is paused
2023-11-16T20:02:26.893Z,1700164946.893 [CBIT](INFO): Critical error at 20231116T200226
2023-11-16T20:02:26.893Z,1700164946.893 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2023-11-16T20:02:26.895Z,1700164946.895 [CBIT](ERROR): Hardware Fault in component: DropWeight
2023-11-16T20:02:26.900Z,1700164946.900 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2023-11-16T20:02:27.239Z,1700164947.239 [CBIT](INFO): Critical error at 20231116T200226
2023-11-16T20:02:28.724Z,1700164948.724 [WetLabsBB2FL](INFO): Powering down
2023-11-16T20:02:32.222Z,1700164952.222 [ThrusterHE](ERROR): Zero Speed Commanded.
2023-11-16T20:02:36.641Z,1700164956.641 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.027118
2023-11-16T20:02:53.922Z,1700164973.922 [NAL9602](INFO): Powering up NAL9602
2023-11-16T20:03:04.830Z,1700164984.830 [NAL9602](INFO): NAL9602 initialized
2023-11-16T20:03:08.274Z,1700164988.274 [CommandExec](IMPORTANT): got command strobe off
2023-11-16T20:03:08.274Z,1700164988.274 [CommandExec](IMPORTANT): Deactivating strobe
2023-11-16T20:03:13.749Z,1700164993.749 [SBIT](IMPORTANT): Beginning Startup BIT
2023-11-16T20:03:13.753Z,1700164993.753 [CBIT](IMPORTANT): Beginning ground fault scan
2023-11-16T20:03:24.702Z,1700165004.702 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.006637
CHAN A1 (24V): 0.000911
CHAN A2 (12V): -0.005096
CHAN A3 (5V): -0.002195
CHAN B0 (3.3V): -0.000748
CHAN B1 (3.15aV): -0.001311
CHAN B2 (3.15bV): -0.001509
CHAN B3 (GND): -0.000551
OPEN: 0.004844
Full Scale: +/- 1 mA
2023-11-16T20:04:07.879Z,1700165047.879 [SBIT](IMPORTANT): SBIT PASSED
2023-11-16T20:04:07.880Z,1700165047.880 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-11-16T20:04:07.881Z,1700165047.881 [SBIT](IMPORTANT): BackseatComponent.missionCritical=1 bool;

2023-11-16T20:04:07.881Z,1700165047.881 [SBIT](IMPORTANT): CBIT.gfScanTimeout=1 hour;

2023-11-16T20:04:07.881Z,1700165047.881 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=2 minute;

2023-11-16T20:04:07.881Z,1700165047.881 [SBIT](IMPORTANT): Express none CTD_Seabird.bin_median_sea_water_salinity;

2023-11-16T20:04:07.881Z,1700165047.881 [SBIT](IMPORTANT): Express none CTD_Seabird.bin_median_sea_water_temperature;

2023-11-16T20:04:07.881Z,1700165047.881 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water;

2023-11-16T20:04:07.882Z,1700165047.882 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water;

2023-11-16T20:04:07.882Z,1700165047.882 [SBIT](IMPORTANT): Express linearApproximation _.ayeris_disk_space 100.000000 gigabyte;

2023-11-16T20:04:07.882Z,1700165047.882 [SBIT](IMPORTANT): Express linearApproximation _.ayeris_particle_counts 300.000000 count_per_second;

2023-11-16T20:04:07.882Z,1700165047.882 [SBIT](IMPORTANT): Express none _.ayeris_particle_shape;

2023-11-16T20:04:07.882Z,1700165047.882 [SBIT](IMPORTANT): Express none _.ayeris_particle_slope;

2023-11-16T20:04:07.882Z,1700165047.882 [SBIT](IMPORTANT): Express linearApproximation depth 5.000000 meter;

2023-11-16T20:04:07.882Z,1700165047.882 [SBIT](IMPORTANT): Express linearApproximation latitude 0.005000 degree;

2023-11-16T20:04:07.882Z,1700165047.882 [SBIT](IMPORTANT): Express linearApproximation longitude 0.005000 degree;

2023-11-16T20:04:07.883Z,1700165047.883 [SBIT](IMPORTANT): StratificationFrontDetector.loadAtStartup=1 bool;

2023-11-16T20:04:07.883Z,1700165047.883 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=200.005958 cubic_centimeter;

2023-11-16T20:04:07.883Z,1700165047.883 [SBIT](IMPORTANT): VerticalControl.kdPitchMass=0 second;

2023-11-16T20:04:07.883Z,1700165047.883 [SBIT](IMPORTANT): VerticalControl.kiPitchMass=0.0015 reciprocal_second;

2023-11-16T20:04:07.883Z,1700165047.883 [SBIT](IMPORTANT): VerticalControl.kpPitchMass=0.01 none;

2023-11-16T20:04:07.883Z,1700165047.883 [SBIT](IMPORTANT): VerticalControl.massDeadband=1 millimeter;

2023-11-16T20:04:07.883Z,1700165047.883 [SBIT](IMPORTANT): VerticalControl.massDefault=6.920555 millimeter;

2023-11-16T20:04:07.883Z,1700165047.883 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.depth3=20 meter;

2023-11-16T20:04:07.883Z,1700165047.883 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.depth4=30 meter;

2023-11-16T20:04:08.297Z,1700165048.297 [MissionManager](IMPORTANT): Started mission Startup
2023-11-16T20:04:08.297Z,1700165048.297 [Startup] Running Loop=1
2023-11-16T20:04:08.297Z,1700165048.297 [Startup](DEBUG): Aggregate::initialize Startup
2023-11-16T20:04:08.297Z,1700165048.297 [Startup:A.GoToSurface] Running Loop=1
2023-11-16T20:04:08.297Z,1700165048.297 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-11-16T20:04:08.298Z,1700165048.298 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-11-16T20:04:08.298Z,1700165048.298 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-11-16T20:04:08.299Z,1700165048.299 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-11-16T20:04:08.299Z,1700165048.299 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-11-16T20:04:08.299Z,1700165048.299 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-11-16T20:04:08.301Z,1700165048.301 [Startup:StartupSatComms] Running Loop=1
2023-11-16T20:04:08.301Z,1700165048.301 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2023-11-16T20:04:08.301Z,1700165048.301 [Startup:StartupSatComms:A] Running Loop=1
2023-11-16T20:04:08.669Z,1700165048.669 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2023-11-16T20:05:08.544Z,1700165108.544 [Startup:StartupSatComms:A](INFO): Timed out from 2023-11-16T20:04:08.3Z
2023-11-16T20:05:08.544Z,1700165108.544 [Startup:StartupSatComms:A] Stopped
2023-11-16T20:05:08.544Z,1700165108.544 [Startup:StartupSatComms:B] Running Loop=1
2023-11-16T20:05:08.915Z,1700165108.915 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-11-16T20:05:16.961Z,1700165116.961 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20231109T222358/Courier0013.lzma
2023-11-16T20:05:17.962Z,1700165117.962 [DataOverHttps](INFO): Moved sent file to Logs/20231109T222358/Courier0013.lzma.bak
2023-11-16T20:05:17.963Z,1700165117.963 [DataOverHttps](INFO): SBD MOMSN=19071162
2023-11-16T20:05:26.274Z,1700165126.274 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2023-11-16T20:05:26.274Z,1700165126.274 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-11-16T20:05:26.275Z,1700165126.275 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2023-11-16T20:05:26.275Z,1700165126.275 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-11-16T20:05:26.310Z,1700165126.310 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-11-16T20:05:26.310Z,1700165126.310 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-11-16T20:05:26.692Z,1700165126.692 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-11-16T20:05:26.692Z,1700165126.692 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2023-11-16T20:05:26.693Z,1700165126.693 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-11-16T20:05:26.693Z,1700165126.693 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2023-11-16T20:05:27.044Z,1700165127.044 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-11-16T20:05:36.097Z,1700165136.097 [DataOverHttps](INFO): Sending 242 bytes from file Logs/20231110T164230/Courier0000.lzma
2023-11-16T20:05:37.098Z,1700165137.098 [DataOverHttps](INFO): Moved sent file to Logs/20231110T164230/Courier0000.lzma.bak
2023-11-16T20:05:37.098Z,1700165137.098 [DataOverHttps](INFO): SBD MOMSN=19071164
2023-11-16T20:05:52.913Z,1700165152.913 [DataOverHttps](INFO): Sending 243 bytes from file Logs/20231116T200214/Courier0000.lzma
2023-11-16T20:05:53.914Z,1700165153.914 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Courier0000.lzma.bak
2023-11-16T20:05:53.914Z,1700165153.914 [DataOverHttps](INFO): SBD MOMSN=19071169
2023-11-16T20:06:08.695Z,1700165168.695 [Startup:StartupSatComms:B](INFO): Timed out from 2023-11-16T20:05:08.5Z
2023-11-16T20:06:08.695Z,1700165168.695 [Startup:StartupSatComms:B] Stopped
2023-11-16T20:06:08.695Z,1700165168.695 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2023-11-16T20:06:08.695Z,1700165168.695 [Startup:StartupSatComms] Stopped
2023-11-16T20:06:08.695Z,1700165168.695 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2023-11-16T20:06:08.696Z,1700165168.696 [Startup](INFO): Completed Startup
2023-11-16T20:06:08.696Z,1700165168.696 [MissionManager](INFO): Startup is completed.
2023-11-16T20:06:08.696Z,1700165168.696 [MissionManager](INFO): Uninitializing Mission Startup
2023-11-16T20:06:08.696Z,1700165168.696 [Startup] Stopped
2023-11-16T20:06:08.696Z,1700165168.696 [Startup](DEBUG): Aggregate::uninitialize Startup
2023-11-16T20:06:08.697Z,1700165168.697 [Startup:A.GoToSurface] Stopped
2023-11-16T20:06:08.697Z,1700165168.697 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-11-16T20:06:09.077Z,1700165169.077 [MissionManager](IMPORTANT): Started mission Default
2023-11-16T20:06:09.077Z,1700165169.077 [Default] Running Loop=1
2023-11-16T20:06:09.077Z,1700165169.077 [Default](DEBUG): Aggregate::initialize Default
2023-11-16T20:06:09.078Z,1700165169.078 [Default:B.GoToSurface] Running Loop=1
2023-11-16T20:06:09.078Z,1700165169.078 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-11-16T20:06:09.078Z,1700165169.078 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-11-16T20:06:09.078Z,1700165169.078 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-11-16T20:06:09.078Z,1700165169.078 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-11-16T20:06:09.079Z,1700165169.079 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-11-16T20:06:09.079Z,1700165169.079 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-11-16T20:06:09.079Z,1700165169.079 [Default:A.Wait] Running Loop=1
2023-11-16T20:06:09.079Z,1700165169.079 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-11-16T20:06:14.433Z,1700165174.433 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20231109T222358/Express0014.lzma
2023-11-16T20:06:15.434Z,1700165175.434 [DataOverHttps](INFO): Moved sent file to Logs/20231109T222358/Express0014.lzma.bak
2023-11-16T20:06:15.434Z,1700165175.434 [DataOverHttps](INFO): SBD MOMSN=19071174
2023-11-16T20:06:22.401Z,1700165182.401 [Default:A.Wait](INFO): Done Waiting.
2023-11-16T20:06:22.401Z,1700165182.401 [Default:A.Wait] Stopped
2023-11-16T20:06:22.401Z,1700165182.401 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-11-16T20:06:22.800Z,1700165182.800 [Default:CheckIn] Running Loop=1
2023-11-16T20:06:22.800Z,1700165182.800 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-11-16T20:06:22.800Z,1700165182.800 [Default:CheckIn:Read_GPS] Running Loop=1
2023-11-16T20:06:23.210Z,1700165183.210 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-11-16T20:08:08.238Z,1700165288.238 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-11-16T20:08:27.233Z,1700165307.233 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2023-11-16T20:08:27.233Z,1700165307.233 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-11-16T20:08:27.234Z,1700165307.234 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2
2023-11-16T20:08:27.234Z,1700165307.234 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-11-16T20:08:27.277Z,1700165307.277 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-11-16T20:08:27.278Z,1700165307.278 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-11-16T20:08:27.644Z,1700165307.644 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-11-16T20:08:27.644Z,1700165307.644 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2023-11-16T20:08:27.644Z,1700165307.644 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-11-16T20:08:27.645Z,1700165307.645 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2
2023-11-16T20:08:28.042Z,1700165308.042 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-11-16T20:09:57.316Z,1700165397.316 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2023-11-16T20:09:57.320Z,1700165397.320 [BPC1](INFO): Received data from all battery sticks.
2023-11-16T20:11:23.004Z,1700165483.004 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-11-16T20:06:22.8Z
2023-11-16T20:11:23.004Z,1700165483.004 [Default:CheckIn:Read_GPS] Stopped
2023-11-16T20:11:23.004Z,1700165483.004 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-11-16T20:11:23.410Z,1700165483.410 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-11-16T20:11:28.237Z,1700165488.237 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2023-11-16T20:11:28.237Z,1700165488.237 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-11-16T20:11:28.238Z,1700165488.238 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 3
2023-11-16T20:11:28.238Z,1700165488.238 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-11-16T20:11:28.285Z,1700165488.285 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-11-16T20:11:28.285Z,1700165488.285 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-11-16T20:11:28.689Z,1700165488.689 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-11-16T20:11:28.689Z,1700165488.689 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2023-11-16T20:11:28.690Z,1700165488.690 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-11-16T20:11:28.690Z,1700165488.690 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 3
2023-11-16T20:11:29.061Z,1700165489.061 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-11-16T20:11:31.808Z,1700165491.808 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20231116T200214/Courier0004.lzma
2023-11-16T20:11:32.810Z,1700165492.810 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Courier0004.lzma.bak
2023-11-16T20:11:32.810Z,1700165492.810 [DataOverHttps](INFO): SBD MOMSN=19071177
2023-11-16T20:11:51.266Z,1700165511.266 [DataOverHttps](INFO): Sending 498 bytes from file Logs/20231110T164230/Express0001.lzma
2023-11-16T20:11:52.266Z,1700165512.266 [DataOverHttps](INFO): Moved sent file to Logs/20231110T164230/Express0001.lzma.bak
2023-11-16T20:11:52.266Z,1700165512.266 [DataOverHttps](INFO): SBD MOMSN=19071179
2023-11-16T20:12:10.818Z,1700165530.818 [DataOverHttps](INFO): Sending 1148 bytes from file Logs/20231116T200214/Express0001.lzma
2023-11-16T20:12:11.818Z,1700165531.818 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Express0001.lzma.bak
2023-11-16T20:12:11.818Z,1700165531.818 [DataOverHttps](INFO): SBD MOMSN=19071194
2023-11-16T20:12:27.603Z,1700165547.603 [Power24vConverter](INFO): Powering down.
2023-11-16T20:12:29.104Z,1700165549.104 [DataOverHttps](INFO): Sending 186 bytes from file Logs/20231116T200214/Express0005.lzma
2023-11-16T20:12:30.106Z,1700165550.106 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Express0005.lzma.bak
2023-11-16T20:12:30.106Z,1700165550.106 [DataOverHttps](INFO): SBD MOMSN=19071231
2023-11-16T20:12:34.118Z,1700165554.118 [Default:CheckIn:Read_Iridium] Stopped
2023-11-16T20:12:34.118Z,1700165554.118 [Default:CheckIn:C.Wait] Running Loop=1
2023-11-16T20:12:34.118Z,1700165554.118 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-11-16T20:13:06.390Z,1700165586.390 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-11-16T20:13:06.390Z,1700165586.390 [NAL9602] Data Fault, FailCount= 1
2023-11-16T20:13:06.390Z,1700165586.390 [NAL9602](ERROR): Data Fault
2023-11-16T20:13:06.408Z,1700165586.408 [CBIT](ERROR): Data Fault in component: NAL9602
2023-11-16T20:13:06.789Z,1700165586.789 [NAL9602](INFO): Powering down
2023-11-16T20:13:07.630Z,1700165587.630 [CBIT](INFO): Clearing failed state for component NAL9602
2023-11-16T20:13:07.630Z,1700165587.630 [NAL9602] No Fault, FailCount= 1
2023-11-16T20:13:37.094Z,1700165617.094 [NAL9602](INFO): Powering up NAL9602
2023-11-16T20:13:48.002Z,1700165628.002 [NAL9602](INFO): NAL9602 initialized
2023-11-16T20:14:29.221Z,1700165669.221 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2023-11-16T20:14:29.221Z,1700165669.221 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-11-16T20:14:29.222Z,1700165669.222 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 4
2023-11-16T20:14:29.222Z,1700165669.222 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-11-16T20:14:29.234Z,1700165669.234 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-11-16T20:14:29.234Z,1700165669.234 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-11-16T20:14:29.646Z,1700165669.646 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-11-16T20:14:29.646Z,1700165669.646 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2023-11-16T20:14:29.646Z,1700165669.646 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-11-16T20:14:29.647Z,1700165669.647 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 4
2023-11-16T20:14:30.053Z,1700165670.053 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-11-16T20:16:45.924Z,1700165805.924 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting.
2023-11-16T20:16:47.933Z,1700165807.933 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.386902
2023-11-16T20:16:58.109Z,1700165818.109 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002949
2023-11-16T20:17:26.989Z,1700165846.989 [CBIT](INFO): Clearing failed state for component DropWeight
2023-11-16T20:17:26.989Z,1700165846.989 [DropWeight] No Fault, FailCount= 1
2023-11-16T20:17:30.224Z,1700165850.224 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2023-11-16T20:17:30.225Z,1700165850.225 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-11-16T20:17:30.237Z,1700165850.237 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 5
2023-11-16T20:17:30.237Z,1700165850.237 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-11-16T20:17:30.277Z,1700165850.277 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-11-16T20:17:30.278Z,1700165850.278 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-11-16T20:17:30.659Z,1700165850.659 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-11-16T20:17:30.659Z,1700165850.659 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2023-11-16T20:17:30.659Z,1700165850.659 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-11-16T20:17:30.659Z,1700165850.659 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 5
2023-11-16T20:17:31.050Z,1700165851.050 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-11-16T20:17:34.683Z,1700165854.683 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-11-16T20:17:34.683Z,1700165854.683 [Default:CheckIn:C.Wait] Stopped
2023-11-16T20:17:34.683Z,1700165854.683 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-11-16T20:17:34.683Z,1700165854.683 [Default:CheckIn:D] Running Loop=1
2023-11-16T20:17:35.058Z,1700165855.058 [Default:CheckIn:D] Stopped
2023-11-16T20:17:35.058Z,1700165855.058 [Default:CheckIn:E] Running Loop=1
2023-11-16T20:17:35.477Z,1700165855.477 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.433013 min 
2023-11-16T20:17:35.477Z,1700165855.477 [Default:CheckIn:E] Stopped
2023-11-16T20:17:35.477Z,1700165855.477 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-11-16T20:17:35.478Z,1700165855.478 [Default:CheckIn] Stopped
2023-11-16T20:17:35.478Z,1700165855.478 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-11-16T20:17:35.478Z,1700165855.478 [Default:CheckIn](INFO): Running loop #2
2023-11-16T20:17:35.478Z,1700165855.478 [Default:CheckIn] Running Loop=2
2023-11-16T20:17:35.478Z,1700165855.478 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-11-16T20:17:35.478Z,1700165855.478 [Default:CheckIn:Read_GPS] Running Loop=1
2023-11-16T20:20:31.272Z,1700166031.272 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2023-11-16T20:20:31.272Z,1700166031.272 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-11-16T20:20:31.273Z,1700166031.273 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 6
2023-11-16T20:20:31.273Z,1700166031.273 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-11-16T20:20:31.284Z,1700166031.284 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-11-16T20:20:31.284Z,1700166031.284 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-11-16T20:20:31.675Z,1700166031.675 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-11-16T20:20:31.675Z,1700166031.675 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2023-11-16T20:20:31.692Z,1700166031.692 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-11-16T20:20:31.692Z,1700166031.692 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 6
2023-11-16T20:20:32.063Z,1700166032.063 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-11-16T20:22:35.672Z,1700166155.672 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-11-16T20:17:35.5Z
2023-11-16T20:22:35.672Z,1700166155.672 [Default:CheckIn:Read_GPS] Stopped
2023-11-16T20:22:35.672Z,1700166155.672 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-11-16T20:22:44.063Z,1700166164.063 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20231116T200214/Courier0007.lzma
2023-11-16T20:22:45.066Z,1700166165.066 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Courier0007.lzma.bak
2023-11-16T20:22:45.066Z,1700166165.066 [DataOverHttps](INFO): SBD MOMSN=19071315
2023-11-16T20:23:05.704Z,1700166185.704 [DataOverHttps](INFO): Sending 181 bytes from file Logs/20231116T200214/Express0008.lzma
2023-11-16T20:23:06.706Z,1700166186.706 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Express0008.lzma.bak
2023-11-16T20:23:06.706Z,1700166186.706 [DataOverHttps](INFO): SBD MOMSN=19071317
2023-11-16T20:23:10.874Z,1700166190.874 [Default:CheckIn:Read_Iridium] Stopped
2023-11-16T20:23:10.874Z,1700166190.874 [Default:CheckIn:C.Wait] Running Loop=1
2023-11-16T20:23:10.874Z,1700166190.874 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-11-16T20:23:32.266Z,1700166212.266 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2023-11-16T20:23:32.266Z,1700166212.266 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-11-16T20:23:32.267Z,1700166212.267 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 7
2023-11-16T20:23:32.267Z,1700166212.267 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-11-16T20:23:32.278Z,1700166212.278 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-11-16T20:23:32.278Z,1700166212.278 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-11-16T20:23:32.667Z,1700166212.667 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-11-16T20:23:32.667Z,1700166212.667 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2023-11-16T20:23:32.667Z,1700166212.667 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-11-16T20:23:32.667Z,1700166212.667 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 7
2023-11-16T20:23:33.045Z,1700166213.045 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-11-16T20:23:49.598Z,1700166229.598 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-11-16T20:23:49.598Z,1700166229.598 [NAL9602] Data Fault, FailCount= 2
2023-11-16T20:23:49.598Z,1700166229.598 [NAL9602](ERROR): Data Fault
2023-11-16T20:23:49.668Z,1700166229.668 [CBIT](ERROR): Data Fault in component: NAL9602
2023-11-16T20:23:50.002Z,1700166230.002 [NAL9602](INFO): Powering down
2023-11-16T20:23:50.839Z,1700166230.839 [CBIT](INFO): Clearing failed state for component NAL9602
2023-11-16T20:23:50.840Z,1700166230.840 [NAL9602] No Fault, FailCount= 2
2023-11-16T20:24:20.306Z,1700166260.306 [NAL9602](INFO): Powering up NAL9602
2023-11-16T20:24:31.218Z,1700166271.218 [NAL9602](INFO): NAL9602 initialized
2023-11-16T20:26:33.231Z,1700166393.231 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2023-11-16T20:26:33.231Z,1700166393.231 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-11-16T20:26:33.232Z,1700166393.232 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 8
2023-11-16T20:26:33.232Z,1700166393.232 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-11-16T20:26:33.243Z,1700166393.243 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-11-16T20:26:33.243Z,1700166393.243 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-11-16T20:26:33.653Z,1700166393.653 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-11-16T20:26:33.653Z,1700166393.653 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2023-11-16T20:26:33.654Z,1700166393.654 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-11-16T20:26:33.654Z,1700166393.654 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 8
2023-11-16T20:26:34.037Z,1700166394.037 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-11-16T20:28:11.406Z,1700166491.406 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-11-16T20:28:11.406Z,1700166491.406 [Default:CheckIn:C.Wait] Stopped
2023-11-16T20:28:11.406Z,1700166491.406 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-11-16T20:28:11.406Z,1700166491.406 [Default:CheckIn:D] Running Loop=1
2023-11-16T20:28:11.811Z,1700166491.811 [Default:CheckIn:D] Stopped
2023-11-16T20:28:11.811Z,1700166491.811 [Default:CheckIn:E] Running Loop=1
2023-11-16T20:28:12.216Z,1700166492.216 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 22.045559 min 
2023-11-16T20:28:12.216Z,1700166492.216 [Default:CheckIn:E] Stopped
2023-11-16T20:28:12.216Z,1700166492.216 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-11-16T20:28:12.216Z,1700166492.216 [Default:CheckIn] Stopped
2023-11-16T20:28:12.216Z,1700166492.216 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-11-16T20:28:12.217Z,1700166492.217 [Default:CheckIn](INFO): Running loop #3
2023-11-16T20:28:12.217Z,1700166492.217 [Default:CheckIn] Running Loop=3
2023-11-16T20:28:12.217Z,1700166492.217 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-11-16T20:28:12.217Z,1700166492.217 [Default:CheckIn:Read_GPS] Running Loop=1
2023-11-16T20:29:34.246Z,1700166574.246 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2023-11-16T20:29:34.246Z,1700166574.246 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-11-16T20:29:34.247Z,1700166574.247 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 9
2023-11-16T20:29:34.247Z,1700166574.247 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-11-16T20:29:34.258Z,1700166574.258 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-11-16T20:29:34.258Z,1700166574.258 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-11-16T20:29:34.655Z,1700166574.655 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-11-16T20:29:34.655Z,1700166574.655 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2023-11-16T20:29:34.655Z,1700166574.655 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-11-16T20:29:34.655Z,1700166574.655 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 9
2023-11-16T20:29:35.058Z,1700166575.058 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-11-16T20:32:35.285Z,1700166755.285 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2023-11-16T20:32:35.285Z,1700166755.285 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-11-16T20:32:35.286Z,1700166755.286 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 10
2023-11-16T20:32:35.286Z,1700166755.286 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-11-16T20:32:35.297Z,1700166755.297 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-11-16T20:32:35.297Z,1700166755.297 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-11-16T20:32:35.676Z,1700166755.676 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-11-16T20:32:35.676Z,1700166755.676 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2023-11-16T20:32:35.676Z,1700166755.676 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-11-16T20:32:35.677Z,1700166755.677 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 10
2023-11-16T20:32:36.081Z,1700166756.081 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-11-16T20:33:12.446Z,1700166792.446 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-11-16T20:28:12.2Z
2023-11-16T20:33:12.446Z,1700166792.446 [Default:CheckIn:Read_GPS] Stopped
2023-11-16T20:33:12.446Z,1700166792.446 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-11-16T20:33:20.801Z,1700166800.801 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20231116T200214/Courier0010.lzma
2023-11-16T20:33:21.802Z,1700166801.802 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Courier0010.lzma.bak
2023-11-16T20:33:21.802Z,1700166801.802 [DataOverHttps](INFO): SBD MOMSN=19071334
2023-11-16T20:33:42.272Z,1700166822.272 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20231116T200214/Express0011.lzma
2023-11-16T20:33:43.274Z,1700166823.274 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Express0011.lzma.bak
2023-11-16T20:33:43.274Z,1700166823.274 [DataOverHttps](INFO): SBD MOMSN=19071336
2023-11-16T20:33:47.275Z,1700166827.275 [Default:CheckIn:Read_Iridium] Stopped
2023-11-16T20:33:47.275Z,1700166827.275 [Default:CheckIn:C.Wait] Running Loop=1
2023-11-16T20:33:47.275Z,1700166827.275 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-11-16T20:34:32.118Z,1700166872.118 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-11-16T20:34:32.118Z,1700166872.118 [NAL9602] Data Fault, FailCount= 3
2023-11-16T20:34:32.118Z,1700166872.118 [NAL9602](ERROR): Data Fault
2023-11-16T20:34:32.167Z,1700166872.167 [CBIT](ERROR): Data Fault in component: NAL9602
2023-11-16T20:34:32.522Z,1700166872.522 [NAL9602](INFO): Powering down
2023-11-16T20:34:33.357Z,1700166873.357 [CBIT](INFO): Clearing failed state for component NAL9602
2023-11-16T20:34:33.357Z,1700166873.357 [NAL9602] No Fault, FailCount= 3
2023-11-16T20:35:02.822Z,1700166902.822 [NAL9602](INFO): Powering up NAL9602
2023-11-16T20:35:13.734Z,1700166913.734 [NAL9602](INFO): NAL9602 initialized
2023-11-16T20:35:36.354Z,1700166936.354 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11
2023-11-16T20:35:36.354Z,1700166936.354 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-11-16T20:35:36.355Z,1700166936.355 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 11
2023-11-16T20:35:36.355Z,1700166936.355 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-11-16T20:35:36.406Z,1700166936.406 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-11-16T20:35:36.406Z,1700166936.406 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-11-16T20:35:36.792Z,1700166936.792 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-11-16T20:35:36.792Z,1700166936.792 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11
2023-11-16T20:35:36.793Z,1700166936.793 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-11-16T20:35:36.793Z,1700166936.793 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 11
2023-11-16T20:35:37.172Z,1700166937.172 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-11-16T20:38:37.408Z,1700167117.408 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12
2023-11-16T20:38:37.408Z,1700167117.408 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-11-16T20:38:37.409Z,1700167117.409 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 12
2023-11-16T20:38:37.409Z,1700167117.409 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-11-16T20:38:37.420Z,1700167117.420 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-11-16T20:38:37.420Z,1700167117.420 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-11-16T20:38:37.810Z,1700167117.810 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-11-16T20:38:37.810Z,1700167117.810 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12
2023-11-16T20:38:37.810Z,1700167117.810 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-11-16T20:38:37.810Z,1700167117.810 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 12
2023-11-16T20:38:38.240Z,1700167118.240 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-11-16T20:38:47.954Z,1700167127.954 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-11-16T20:38:47.954Z,1700167127.954 [Default:CheckIn:C.Wait] Stopped
2023-11-16T20:38:47.954Z,1700167127.954 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-11-16T20:38:47.954Z,1700167127.954 [Default:CheckIn:D] Running Loop=1
2023-11-16T20:38:48.331Z,1700167128.331 [Default:CheckIn:D] Stopped
2023-11-16T20:38:48.331Z,1700167128.331 [Default:CheckIn:E] Running Loop=1
2023-11-16T20:38:48.727Z,1700167128.727 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 32.654222 min 
2023-11-16T20:38:48.727Z,1700167128.727 [Default:CheckIn:E] Stopped
2023-11-16T20:38:48.727Z,1700167128.727 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-11-16T20:38:48.727Z,1700167128.727 [Default:CheckIn] Stopped
2023-11-16T20:38:48.727Z,1700167128.727 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-11-16T20:38:48.728Z,1700167128.728 [Default:CheckIn](INFO): Running loop #4
2023-11-16T20:38:48.728Z,1700167128.728 [Default:CheckIn] Running Loop=4
2023-11-16T20:38:48.728Z,1700167128.728 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-11-16T20:38:48.728Z,1700167128.728 [Default:CheckIn:Read_GPS] Running Loop=1
2023-11-16T20:40:20.004Z,1700167220.004 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204019.00,A,3648.15987,N,12147.28702,W,0.156,0.00,161123,,,A*73
2023-11-16T20:40:20.048Z,1700167220.048 [NAL9602](INFO): GPS fix at 20231116T204019: (36.802664, -121.788117)
2023-11-16T20:40:20.069Z,1700167220.069 [Default:CheckIn:Read_GPS] Stopped
2023-11-16T20:40:20.069Z,1700167220.069 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-11-16T20:40:31.356Z,1700167231.356 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20231116T200214/Courier0013.lzma
2023-11-16T20:40:32.358Z,1700167232.358 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Courier0013.lzma.bak
2023-11-16T20:40:32.358Z,1700167232.358 [DataOverHttps](INFO): SBD MOMSN=19071349
2023-11-16T20:40:51.016Z,1700167251.016 [DataOverHttps](INFO): Sending 285 bytes from file Logs/20231116T200214/Express0014.lzma
2023-11-16T20:40:52.018Z,1700167252.018 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Express0014.lzma.bak
2023-11-16T20:40:52.019Z,1700167252.019 [DataOverHttps](INFO): SBD MOMSN=19071352
2023-11-16T20:40:52.330Z,1700167252.330 [NAL9602](INFO): Not Powering down - fast GPS
2023-11-16T20:40:56.028Z,1700167256.028 [Default:CheckIn:Read_Iridium] Stopped
2023-11-16T20:40:56.028Z,1700167256.028 [Default:CheckIn:C.Wait] Running Loop=1
2023-11-16T20:40:56.028Z,1700167256.028 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-11-16T20:45:56.647Z,1700167556.647 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-11-16T20:45:56.647Z,1700167556.647 [Default:CheckIn:C.Wait] Stopped
2023-11-16T20:45:56.647Z,1700167556.647 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-11-16T20:45:56.647Z,1700167556.647 [Default:CheckIn:D] Running Loop=1
2023-11-16T20:45:57.037Z,1700167557.037 [Default:CheckIn:D] Stopped
2023-11-16T20:45:57.037Z,1700167557.037 [Default:CheckIn:E] Running Loop=1
2023-11-16T20:45:57.470Z,1700167557.470 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.799325 min 
2023-11-16T20:45:57.470Z,1700167557.470 [Default:CheckIn:E] Stopped
2023-11-16T20:45:57.471Z,1700167557.471 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-11-16T20:45:57.471Z,1700167557.471 [Default:CheckIn] Stopped
2023-11-16T20:45:57.471Z,1700167557.471 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-11-16T20:45:57.471Z,1700167557.471 [Default:CheckIn](INFO): Running loop #5
2023-11-16T20:45:57.471Z,1700167557.471 [Default:CheckIn] Running Loop=5
2023-11-16T20:45:57.471Z,1700167557.471 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-11-16T20:45:57.471Z,1700167557.471 [Default:CheckIn:Read_GPS] Running Loop=1
2023-11-16T20:45:59.423Z,1700167559.423 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204558.00,A,3648.16262,N,12147.28883,W,0.058,299.19,161123,,,D*76
2023-11-16T20:45:59.425Z,1700167559.425 [NAL9602](INFO): GPS fix at 20231116T204558: (36.802710, -121.788147)
2023-11-16T20:45:59.487Z,1700167559.487 [Default:CheckIn:Read_GPS] Stopped
2023-11-16T20:45:59.487Z,1700167559.487 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-11-16T20:46:10.503Z,1700167570.503 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231116T200214/Courier0016.lzma
2023-11-16T20:46:11.506Z,1700167571.506 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Courier0016.lzma.bak
2023-11-16T20:46:11.506Z,1700167571.506 [DataOverHttps](INFO): SBD MOMSN=19071366
2023-11-16T20:46:31.452Z,1700167591.452 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20231116T200214/Express0017.lzma
2023-11-16T20:46:32.454Z,1700167592.454 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Express0017.lzma.bak
2023-11-16T20:46:32.454Z,1700167592.454 [DataOverHttps](INFO): SBD MOMSN=19071369
2023-11-16T20:46:36.702Z,1700167596.702 [Default:CheckIn:Read_Iridium] Stopped
2023-11-16T20:46:36.702Z,1700167596.702 [Default:CheckIn:C.Wait] Running Loop=1
2023-11-16T20:46:36.702Z,1700167596.702 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-11-16T20:48:07.567Z,1700167687.567 [NAL9602](INFO): SBD MO Status=2, MOMSN=14020, MT Status=2, MTMSN=0
2023-11-16T20:48:07.567Z,1700167687.567 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-11-16T20:51:01.342Z,1700167861.342 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-11-16T20:51:32.045Z,1700167892.045 [NAL9602](INFO): Not Powering down - fast GPS
2023-11-16T20:51:37.320Z,1700167897.320 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-11-16T20:51:37.320Z,1700167897.320 [Default:CheckIn:C.Wait] Stopped
2023-11-16T20:51:37.320Z,1700167897.320 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-11-16T20:51:37.320Z,1700167897.320 [Default:CheckIn:D] Running Loop=1
2023-11-16T20:51:37.712Z,1700167897.712 [Default:CheckIn:D] Stopped
2023-11-16T20:51:37.712Z,1700167897.712 [Default:CheckIn:E] Running Loop=1
2023-11-16T20:51:38.122Z,1700167898.122 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.477238 min 
2023-11-16T20:51:38.122Z,1700167898.122 [Default:CheckIn:E] Stopped
2023-11-16T20:51:38.122Z,1700167898.122 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-11-16T20:51:38.122Z,1700167898.122 [Default:CheckIn] Stopped
2023-11-16T20:51:38.122Z,1700167898.122 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-11-16T20:51:38.122Z,1700167898.122 [Default:CheckIn](INFO): Running loop #6
2023-11-16T20:51:38.122Z,1700167898.122 [Default:CheckIn] Running Loop=6
2023-11-16T20:51:38.123Z,1700167898.123 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-11-16T20:51:38.123Z,1700167898.123 [Default:CheckIn:Read_GPS] Running Loop=1
2023-11-16T20:51:40.135Z,1700167900.135 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205139.00,A,3648.16198,N,12147.28075,W,0.253,227.77,161123,,,D*77
2023-11-16T20:51:40.137Z,1700167900.137 [NAL9602](INFO): GPS fix at 20231116T205139: (36.802700, -121.788012)
2023-11-16T20:51:40.150Z,1700167900.150 [Default:CheckIn:Read_GPS] Stopped
2023-11-16T20:51:40.150Z,1700167900.150 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-11-16T20:51:49.580Z,1700167909.580 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20231116T200214/Courier0019.lzma
2023-11-16T20:51:50.582Z,1700167910.582 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Courier0019.lzma.bak
2023-11-16T20:51:50.582Z,1700167910.582 [DataOverHttps](INFO): SBD MOMSN=19071404
2023-11-16T20:52:10.890Z,1700167930.890 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-11-16T20:52:10.969Z,1700167930.969 [NAL9602](ERROR): received: 
+CSQ:0

OK020, 2, 0, 0, 0

OK
2023-11-16T20:52:15.649Z,1700167935.649 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20231116T200214/Express0020.lzma
2023-11-16T20:52:16.650Z,1700167936.650 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Express0020.lzma.bak
2023-11-16T20:52:16.650Z,1700167936.650 [DataOverHttps](INFO): SBD MOMSN=19071407
2023-11-16T20:52:20.996Z,1700167940.996 [Default:CheckIn:Read_Iridium] Stopped
2023-11-16T20:52:20.996Z,1700167940.996 [Default:CheckIn:C.Wait] Running Loop=1
2023-11-16T20:52:20.996Z,1700167940.996 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-11-16T20:56:42.374Z,1700168202.374 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-11-16T20:57:13.077Z,1700168233.077 [NAL9602](INFO): Not Powering down - fast GPS
2023-11-16T20:57:21.577Z,1700168241.577 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-11-16T20:57:21.577Z,1700168241.577 [Default:CheckIn:C.Wait] Stopped
2023-11-16T20:57:21.577Z,1700168241.577 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-11-16T20:57:21.577Z,1700168241.577 [Default:CheckIn:D] Running Loop=1
2023-11-16T20:57:21.988Z,1700168241.988 [Default:CheckIn:D] Stopped
2023-11-16T20:57:21.988Z,1700168241.988 [Default:CheckIn:E] Running Loop=1
2023-11-16T20:57:22.381Z,1700168242.381 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 51.215177 min 
2023-11-16T20:57:22.381Z,1700168242.381 [Default:CheckIn:E] Stopped
2023-11-16T20:57:22.381Z,1700168242.381 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-11-16T20:57:22.381Z,1700168242.381 [Default:CheckIn] Stopped
2023-11-16T20:57:22.381Z,1700168242.381 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-11-16T20:57:22.382Z,1700168242.382 [Default:CheckIn](INFO): Running loop #7
2023-11-16T20:57:22.382Z,1700168242.382 [Default:CheckIn] Running Loop=7
2023-11-16T20:57:22.382Z,1700168242.382 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-11-16T20:57:22.382Z,1700168242.382 [Default:CheckIn:Read_GPS] Running Loop=1
2023-11-16T20:57:24.391Z,1700168244.391 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205723.00,A,3648.16074,N,12147.28570,W,0.117,227.77,161123,,,A*7F
2023-11-16T20:57:24.393Z,1700168244.393 [NAL9602](INFO): GPS fix at 20231116T205723: (36.802679, -121.788095)
2023-11-16T20:57:24.405Z,1700168244.405 [Default:CheckIn:Read_GPS] Stopped
2023-11-16T20:57:24.405Z,1700168244.405 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-11-16T20:57:32.940Z,1700168252.940 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231116T200214/Courier0022.lzma
2023-11-16T20:57:33.942Z,1700168253.942 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Courier0022.lzma.bak
2023-11-16T20:57:33.942Z,1700168253.942 [DataOverHttps](INFO): SBD MOMSN=19071411
2023-11-16T20:57:55.162Z,1700168275.162 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-11-16T20:57:55.237Z,1700168275.237 [NAL9602](ERROR): received: 
+CSQ:0

OK020, 2, 0, 0, 0

OK
2023-11-16T20:57:57.748Z,1700168277.748 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20231116T200214/Express0023.lzma
2023-11-16T20:57:58.750Z,1700168278.750 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Express0023.lzma.bak
2023-11-16T20:57:58.751Z,1700168278.751 [DataOverHttps](INFO): SBD MOMSN=19071414
2023-11-16T20:58:06.102Z,1700168286.102 [Default:CheckIn:Read_Iridium] Stopped
2023-11-16T20:58:06.102Z,1700168286.102 [Default:CheckIn:C.Wait] Running Loop=1
2023-11-16T20:58:06.102Z,1700168286.102 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-11-16T21:02:26.261Z,1700168546.261 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-11-16T21:02:56.969Z,1700168576.969 [NAL9602](INFO): Not Powering down - fast GPS
2023-11-16T21:03:06.672Z,1700168586.672 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-11-16T21:03:06.672Z,1700168586.672 [Default:CheckIn:C.Wait] Stopped
2023-11-16T21:03:06.672Z,1700168586.672 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-11-16T21:03:06.672Z,1700168586.672 [Default:CheckIn:D] Running Loop=1
2023-11-16T21:03:07.081Z,1700168587.081 [Default:CheckIn:D] Stopped
2023-11-16T21:03:07.081Z,1700168587.081 [Default:CheckIn:E] Running Loop=1
2023-11-16T21:03:07.502Z,1700168587.502 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 56.966720 min 
2023-11-16T21:03:07.502Z,1700168587.502 [Default:CheckIn:E] Stopped
2023-11-16T21:03:07.502Z,1700168587.502 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-11-16T21:03:07.502Z,1700168587.502 [Default:CheckIn] Stopped
2023-11-16T21:03:07.502Z,1700168587.502 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-11-16T21:03:07.503Z,1700168587.503 [Default:CheckIn](INFO): Running loop #8
2023-11-16T21:03:07.503Z,1700168587.503 [Default:CheckIn] Running Loop=8
2023-11-16T21:03:07.503Z,1700168587.503 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-11-16T21:03:07.503Z,1700168587.503 [Default:CheckIn:Read_GPS] Running Loop=1
2023-11-16T21:03:09.496Z,1700168589.496 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210308.00,A,3648.16579,N,12147.28928,W,0.214,178.46,161123,,,A*74
2023-11-16T21:03:09.498Z,1700168589.498 [NAL9602](INFO): GPS fix at 20231116T210308: (36.802763, -121.788155)
2023-11-16T21:03:09.539Z,1700168589.539 [Default:CheckIn:Read_GPS] Stopped
2023-11-16T21:03:09.539Z,1700168589.539 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-11-16T21:03:18.150Z,1700168598.150 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20231116T200214/Courier0025.lzma
2023-11-16T21:03:19.150Z,1700168599.150 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Courier0025.lzma.bak
2023-11-16T21:03:19.150Z,1700168599.150 [DataOverHttps](INFO): SBD MOMSN=19071429
2023-11-16T21:03:24.874Z,1700168604.874 [CBIT](IMPORTANT): Beginning ground fault scan
2023-11-16T21:03:27.741Z,1700168607.741 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2023-11-16T21:03:35.810Z,1700168615.810 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.917621
CHAN A1 (24V) N/A reporting off
CHAN A2 (12V): 0.939084
CHAN A3 (5V): 0.989210
CHAN B0 (3.3V): 0.922985
CHAN B1 (3.15aV): 1.006641
CHAN B2 (3.15bV): 1.006091
CHAN B3 (GND): 0.570014
OPEN: 0.036500
Full Scale: +/- 1 mA
2023-11-16T21:03:38.520Z,1700168618.520 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20231116T200214/Express0026.lzma
2023-11-16T21:03:39.522Z,1700168619.522 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Express0026.lzma.bak
2023-11-16T21:03:39.522Z,1700168619.522 [DataOverHttps](INFO): SBD MOMSN=19071432
2023-11-16T21:03:40.194Z,1700168620.194 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-11-16T21:03:40.276Z,1700168620.276 [NAL9602](ERROR): received: 
+CSQ:0

OK020, 2, 0, 0, 0

OK
2023-11-16T21:03:43.858Z,1700168623.858 [Default:CheckIn:Read_Iridium] Stopped
2023-11-16T21:03:43.858Z,1700168623.858 [Default:CheckIn:C.Wait] Running Loop=1
2023-11-16T21:03:43.859Z,1700168623.859 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-11-16T21:08:11.354Z,1700168891.354 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-11-16T21:08:42.053Z,1700168922.053 [NAL9602](INFO): Not Powering down - fast GPS
2023-11-16T21:08:44.489Z,1700168924.489 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-11-16T21:08:44.489Z,1700168924.489 [Default:CheckIn:C.Wait] Stopped
2023-11-16T21:08:44.489Z,1700168924.489 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-11-16T21:08:44.489Z,1700168924.489 [Default:CheckIn:D] Running Loop=1
2023-11-16T21:08:44.910Z,1700168924.910 [Default:CheckIn:D] Stopped
2023-11-16T21:08:44.910Z,1700168924.910 [Default:CheckIn:E] Running Loop=1
2023-11-16T21:08:45.350Z,1700168925.350 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 62.597217 min 
2023-11-16T21:08:45.350Z,1700168925.350 [Default:CheckIn:E] Stopped
2023-11-16T21:08:45.350Z,1700168925.350 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-11-16T21:08:45.351Z,1700168925.351 [Default:CheckIn] Stopped
2023-11-16T21:08:45.351Z,1700168925.351 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-11-16T21:08:45.351Z,1700168925.351 [Default:CheckIn](INFO): Running loop #9
2023-11-16T21:08:45.351Z,1700168925.351 [Default:CheckIn] Running Loop=9
2023-11-16T21:08:45.351Z,1700168925.351 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-11-16T21:08:45.351Z,1700168925.351 [Default:CheckIn:Read_GPS] Running Loop=1
2023-11-16T21:08:47.312Z,1700168927.312 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210846.00,A,3648.16187,N,12147.28274,W,0.175,178.46,161123,,,D*73
2023-11-16T21:08:47.315Z,1700168927.315 [NAL9602](INFO): GPS fix at 20231116T210846: (36.802698, -121.788046)
2023-11-16T21:08:47.327Z,1700168927.327 [Default:CheckIn:Read_GPS] Stopped
2023-11-16T21:08:47.327Z,1700168927.327 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-11-16T21:08:49.423Z,1700168929.423 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231116T200214/Courier0028.lzma
2023-11-16T21:08:50.438Z,1700168930.438 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Courier0028.lzma.bak
2023-11-16T21:08:50.438Z,1700168930.438 [DataOverHttps](INFO): SBD MOMSN=19071439
2023-11-16T21:09:09.049Z,1700168949.049 [DataOverHttps](INFO): Sending 396 bytes from file Logs/20231116T200214/Express0029.lzma
2023-11-16T21:09:10.050Z,1700168950.050 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Express0029.lzma.bak
2023-11-16T21:09:10.050Z,1700168950.050 [DataOverHttps](INFO): SBD MOMSN=19071442
2023-11-16T21:09:14.451Z,1700168954.451 [Default:CheckIn:Read_Iridium] Stopped
2023-11-16T21:09:14.451Z,1700168954.451 [Default:CheckIn:C.Wait] Running Loop=1
2023-11-16T21:09:14.451Z,1700168954.451 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-11-16T21:09:18.062Z,1700168958.062 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-11-16T21:09:18.144Z,1700168958.144 [NAL9602](ERROR): received: 
+CSQ:0

OK020, 2, 0, 0, 0

OK
2023-11-16T21:13:49.729Z,1700169229.729 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-11-16T21:14:15.213Z,1700169255.213 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-11-16T21:14:15.213Z,1700169255.213 [Default:CheckIn:C.Wait] Stopped
2023-11-16T21:14:15.213Z,1700169255.213 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-11-16T21:14:15.213Z,1700169255.213 [Default:CheckIn:D] Running Loop=1
2023-11-16T21:14:15.633Z,1700169255.633 [Default:CheckIn:D] Stopped
2023-11-16T21:14:15.633Z,1700169255.633 [Default:CheckIn:E] Running Loop=1
2023-11-16T21:14:16.014Z,1700169256.014 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 68.109265 min 
2023-11-16T21:14:16.014Z,1700169256.014 [Default:CheckIn:E] Stopped
2023-11-16T21:14:16.014Z,1700169256.014 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-11-16T21:14:16.014Z,1700169256.014 [Default:CheckIn] Stopped
2023-11-16T21:14:16.014Z,1700169256.014 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-11-16T21:14:16.014Z,1700169256.014 [Default:CheckIn](INFO): Running loop #10
2023-11-16T21:14:16.014Z,1700169256.014 [Default:CheckIn] Running Loop=10
2023-11-16T21:14:16.014Z,1700169256.014 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-11-16T21:14:16.015Z,1700169256.015 [Default:CheckIn:Read_GPS] Running Loop=1
2023-11-16T21:14:18.014Z,1700169258.014 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211417.00,A,3648.16312,N,12147.27929,W,0.292,191.60,161123,,,D*71
2023-11-16T21:14:18.019Z,1700169258.019 [NAL9602](INFO): GPS fix at 20231116T211417: (36.802719, -121.787988)
2023-11-16T21:14:18.031Z,1700169258.031 [Default:CheckIn:Read_GPS] Stopped
2023-11-16T21:14:18.032Z,1700169258.032 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-11-16T21:14:26.872Z,1700169266.872 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231116T200214/Courier0031.lzma
2023-11-16T21:14:27.874Z,1700169267.874 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Courier0031.lzma.bak
2023-11-16T21:14:27.874Z,1700169267.874 [DataOverHttps](INFO): SBD MOMSN=19071448
2023-11-16T21:14:46.725Z,1700169286.725 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20231116T200214/Express0032.lzma
2023-11-16T21:14:47.726Z,1700169287.726 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Express0032.lzma.bak
2023-11-16T21:14:47.726Z,1700169287.726 [DataOverHttps](INFO): SBD MOMSN=19071451
2023-11-16T21:14:50.353Z,1700169290.353 [NAL9602](INFO): Not Powering down - fast GPS
2023-11-16T21:14:52.123Z,1700169292.123 [Default:CheckIn:Read_Iridium] Stopped
2023-11-16T21:14:52.123Z,1700169292.123 [Default:CheckIn:C.Wait] Running Loop=1
2023-11-16T21:14:52.123Z,1700169292.123 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-11-16T21:17:07.078Z,1700169427.078 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2023-11-16T21:17:08.685Z,1700169428.685 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2023-11-16T21:17:25.998Z,1700169445.998 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2023-11-16T21:17:26.018Z,1700169446.018 [BPC1](INFO): Received data from all battery sticks.
2023-11-16T21:19:52.721Z,1700169592.721 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-11-16T21:19:52.721Z,1700169592.721 [Default:CheckIn:C.Wait] Stopped
2023-11-16T21:19:52.721Z,1700169592.721 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-11-16T21:19:52.721Z,1700169592.721 [Default:CheckIn:D] Running Loop=1
2023-11-16T21:19:53.176Z,1700169593.176 [Default:CheckIn:D] Stopped
2023-11-16T21:19:53.176Z,1700169593.176 [Default:CheckIn:E] Running Loop=1
2023-11-16T21:19:53.551Z,1700169593.551 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 73.734985 min 
2023-11-16T21:19:53.551Z,1700169593.551 [Default:CheckIn:E] Stopped
2023-11-16T21:19:53.551Z,1700169593.551 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-11-16T21:19:53.551Z,1700169593.551 [Default:CheckIn] Stopped
2023-11-16T21:19:53.551Z,1700169593.551 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-11-16T21:19:53.551Z,1700169593.551 [Default:CheckIn](INFO): Running loop #11
2023-11-16T21:19:53.551Z,1700169593.551 [Default:CheckIn] Running Loop=11
2023-11-16T21:19:53.551Z,1700169593.551 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-11-16T21:19:53.551Z,1700169593.551 [Default:CheckIn:Read_GPS] Running Loop=1
2023-11-16T21:19:55.523Z,1700169595.523 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211954.00,A,3648.16140,N,12147.27647,W,0.117,191.60,161123,,,D*77
2023-11-16T21:19:55.525Z,1700169595.525 [NAL9602](INFO): GPS fix at 20231116T211954: (36.802690, -121.787941)
2023-11-16T21:19:55.545Z,1700169595.545 [Default:CheckIn:Read_GPS] Stopped
2023-11-16T21:19:55.545Z,1700169595.545 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-11-16T21:20:09.547Z,1700169609.547 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20231116T200214/Courier0034.lzma
2023-11-16T21:20:10.550Z,1700169610.550 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Courier0034.lzma.bak
2023-11-16T21:20:10.550Z,1700169610.550 [DataOverHttps](INFO): SBD MOMSN=19071458
2023-11-16T21:20:29.144Z,1700169629.144 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20231116T200214/Express0035.lzma
2023-11-16T21:20:30.146Z,1700169630.146 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Express0035.lzma.bak
2023-11-16T21:20:30.146Z,1700169630.146 [DataOverHttps](INFO): SBD MOMSN=19071461
2023-11-16T21:20:35.292Z,1700169635.292 [Default:CheckIn:Read_Iridium] Stopped
2023-11-16T21:20:35.292Z,1700169635.292 [Default:CheckIn:C.Wait] Running Loop=1
2023-11-16T21:20:35.292Z,1700169635.292 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-11-16T21:23:58.486Z,1700169838.486 [NAL9602](INFO): SBD MO Status=2, MOMSN=14020, MT Status=2, MTMSN=0
2023-11-16T21:23:58.486Z,1700169838.486 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-11-16T21:24:57.470Z,1700169897.470 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-11-16T21:25:28.172Z,1700169928.172 [NAL9602](INFO): Not Powering down - fast GPS
2023-11-16T21:25:35.865Z,1700169935.865 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-11-16T21:25:35.865Z,1700169935.865 [Default:CheckIn:C.Wait] Stopped
2023-11-16T21:25:35.865Z,1700169935.865 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-11-16T21:25:35.865Z,1700169935.865 [Default:CheckIn:D] Running Loop=1
2023-11-16T21:25:36.274Z,1700169936.274 [Default:CheckIn:D] Stopped
2023-11-16T21:25:36.274Z,1700169936.274 [Default:CheckIn:E] Running Loop=1
2023-11-16T21:25:36.687Z,1700169936.687 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 79.453280 min 
2023-11-16T21:25:36.687Z,1700169936.687 [Default:CheckIn:E] Stopped
2023-11-16T21:25:36.687Z,1700169936.687 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-11-16T21:25:36.687Z,1700169936.687 [Default:CheckIn] Stopped
2023-11-16T21:25:36.687Z,1700169936.687 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-11-16T21:25:36.687Z,1700169936.687 [Default:CheckIn](INFO): Running loop #12
2023-11-16T21:25:36.688Z,1700169936.688 [Default:CheckIn] Running Loop=12
2023-11-16T21:25:36.688Z,1700169936.688 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-11-16T21:25:36.688Z,1700169936.688 [Default:CheckIn:Read_GPS] Running Loop=1
2023-11-16T21:25:38.680Z,1700169938.680 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212537.00,A,3648.16403,N,12147.28689,W,0.117,123.10,161123,,,D*7C
2023-11-16T21:25:38.682Z,1700169938.682 [NAL9602](INFO): GPS fix at 20231116T212537: (36.802734, -121.788115)
2023-11-16T21:25:38.695Z,1700169938.695 [Default:CheckIn:Read_GPS] Stopped
2023-11-16T21:25:38.695Z,1700169938.695 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-11-16T21:25:47.516Z,1700169947.516 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231116T200214/Courier0037.lzma
2023-11-16T21:25:48.518Z,1700169948.518 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Courier0037.lzma.bak
2023-11-16T21:25:48.518Z,1700169948.518 [DataOverHttps](INFO): SBD MOMSN=19071469
2023-11-16T21:26:09.442Z,1700169969.442 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-11-16T21:26:09.524Z,1700169969.524 [NAL9602](ERROR): received: 
+CSQ:0

OK020, 2, 0, 0, 0

OK
2023-11-16T21:26:11.548Z,1700169971.548 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20231116T200214/Express0038.lzma
2023-11-16T21:26:12.550Z,1700169972.550 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Express0038.lzma.bak
2023-11-16T21:26:12.550Z,1700169972.550 [DataOverHttps](INFO): SBD MOMSN=19071472
2023-11-16T21:26:19.992Z,1700169979.992 [Default:CheckIn:Read_Iridium] Stopped
2023-11-16T21:26:19.992Z,1700169979.992 [Default:CheckIn:C.Wait] Running Loop=1
2023-11-16T21:26:19.993Z,1700169979.993 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-11-16T21:30:41.338Z,1700170241.338 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-11-16T21:31:12.041Z,1700170272.041 [NAL9602](INFO): Not Powering down - fast GPS
2023-11-16T21:31:20.541Z,1700170280.541 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-11-16T21:31:20.541Z,1700170280.541 [Default:CheckIn:C.Wait] Stopped
2023-11-16T21:31:20.541Z,1700170280.541 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-11-16T21:31:20.541Z,1700170280.541 [Default:CheckIn:D] Running Loop=1
2023-11-16T21:31:20.946Z,1700170280.946 [Default:CheckIn:D] Stopped
2023-11-16T21:31:20.946Z,1700170280.946 [Default:CheckIn:E] Running Loop=1
2023-11-16T21:31:21.361Z,1700170281.361 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 85.197811 min 
2023-11-16T21:31:21.361Z,1700170281.361 [Default:CheckIn:E] Stopped
2023-11-16T21:31:21.361Z,1700170281.361 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-11-16T21:31:21.361Z,1700170281.361 [Default:CheckIn] Stopped
2023-11-16T21:31:21.361Z,1700170281.361 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-11-16T21:31:21.362Z,1700170281.362 [Default:CheckIn](INFO): Running loop #13
2023-11-16T21:31:21.362Z,1700170281.362 [Default:CheckIn] Running Loop=13
2023-11-16T21:31:21.362Z,1700170281.362 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-11-16T21:31:21.362Z,1700170281.362 [Default:CheckIn:Read_GPS] Running Loop=1
2023-11-16T21:31:23.355Z,1700170283.355 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213122.00,A,3648.15664,N,12147.27937,W,0.739,43.14,161123,,,D*41
2023-11-16T21:31:23.358Z,1700170283.358 [NAL9602](INFO): GPS fix at 20231116T213122: (36.802611, -121.787989)
2023-11-16T21:31:23.403Z,1700170283.403 [Default:CheckIn:Read_GPS] Stopped
2023-11-16T21:31:23.403Z,1700170283.403 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-11-16T21:31:31.943Z,1700170291.943 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231116T200214/Courier0040.lzma
2023-11-16T21:31:32.946Z,1700170292.946 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Courier0040.lzma.bak
2023-11-16T21:31:32.946Z,1700170292.946 [DataOverHttps](INFO): SBD MOMSN=19071552
2023-11-16T21:31:52.804Z,1700170312.804 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20231116T200214/Express0041.lzma
2023-11-16T21:31:53.806Z,1700170313.806 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Express0041.lzma.bak
2023-11-16T21:31:53.806Z,1700170313.806 [DataOverHttps](INFO): SBD MOMSN=19071555
2023-11-16T21:31:54.058Z,1700170314.058 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-11-16T21:31:54.132Z,1700170314.132 [NAL9602](ERROR): received: 
+CSQ:0

OK020, 2, 0, 0, 0

OK
2023-11-16T21:31:58.121Z,1700170318.121 [Default:CheckIn:Read_Iridium] Stopped
2023-11-16T21:31:58.121Z,1700170318.121 [Default:CheckIn:C.Wait] Running Loop=1
2023-11-16T21:31:58.121Z,1700170318.121 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-11-16T21:34:23.135Z,1700170463.135 [NAL9602](INFO): SBD MO Status=2, MOMSN=14020, MT Status=2, MTMSN=0
2023-11-16T21:34:23.135Z,1700170463.135 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-11-16T21:36:25.542Z,1700170585.542 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-11-16T21:36:56.245Z,1700170616.245 [NAL9602](INFO): Not Powering down - fast GPS
2023-11-16T21:36:58.686Z,1700170618.686 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-11-16T21:36:58.686Z,1700170618.686 [Default:CheckIn:C.Wait] Stopped
2023-11-16T21:36:58.686Z,1700170618.686 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-11-16T21:36:58.686Z,1700170618.686 [Default:CheckIn:D] Running Loop=1
2023-11-16T21:36:59.084Z,1700170619.084 [Default:CheckIn:D] Stopped
2023-11-16T21:36:59.084Z,1700170619.084 [Default:CheckIn:E] Running Loop=1
2023-11-16T21:36:59.493Z,1700170619.493 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 90.833439 min 
2023-11-16T21:36:59.493Z,1700170619.493 [Default:CheckIn:E] Stopped
2023-11-16T21:36:59.494Z,1700170619.494 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-11-16T21:36:59.494Z,1700170619.494 [Default:CheckIn] Stopped
2023-11-16T21:36:59.494Z,1700170619.494 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-11-16T21:36:59.494Z,1700170619.494 [Default:CheckIn](INFO): Running loop #14
2023-11-16T21:36:59.494Z,1700170619.494 [Default:CheckIn] Running Loop=14
2023-11-16T21:36:59.494Z,1700170619.494 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-11-16T21:36:59.494Z,1700170619.494 [Default:CheckIn:Read_GPS] Running Loop=1
2023-11-16T21:37:01.504Z,1700170621.504 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213700.00,A,3648.16402,N,12147.28688,W,0.253,96.22,161123,,,D*46
2023-11-16T21:37:01.506Z,1700170621.506 [NAL9602](INFO): GPS fix at 20231116T213700: (36.802734, -121.788115)
2023-11-16T21:37:01.518Z,1700170621.518 [Default:CheckIn:Read_GPS] Stopped
2023-11-16T21:37:01.518Z,1700170621.518 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-11-16T21:37:10.203Z,1700170630.203 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20231116T200214/Courier0043.lzma
2023-11-16T21:37:11.206Z,1700170631.206 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Courier0043.lzma.bak
2023-11-16T21:37:11.206Z,1700170631.206 [DataOverHttps](INFO): SBD MOMSN=19071562
2023-11-16T21:37:32.096Z,1700170652.096 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20231116T200214/Express0044.lzma
2023-11-16T21:37:32.202Z,1700170652.202 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-11-16T21:37:32.280Z,1700170652.280 [NAL9602](ERROR): received: 
+CSQ:1

OK020, 2, 0, 0, 0

OK
2023-11-16T21:37:33.098Z,1700170653.098 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Express0044.lzma.bak
2023-11-16T21:37:33.099Z,1700170653.099 [DataOverHttps](INFO): SBD MOMSN=19071565
2023-11-16T21:37:37.519Z,1700170657.519 [Default:CheckIn:Read_Iridium] Stopped
2023-11-16T21:37:37.519Z,1700170657.519 [Default:CheckIn:C.Wait] Running Loop=1
2023-11-16T21:37:37.519Z,1700170657.519 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-11-16T21:42:03.285Z,1700170923.285 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-11-16T21:42:33.989Z,1700170953.989 [NAL9602](INFO): Not Powering down - fast GPS
2023-11-16T21:42:38.046Z,1700170958.046 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-11-16T21:42:38.046Z,1700170958.046 [Default:CheckIn:C.Wait] Stopped
2023-11-16T21:42:38.046Z,1700170958.046 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-11-16T21:42:38.046Z,1700170958.046 [Default:CheckIn:D] Running Loop=1
2023-11-16T21:42:38.457Z,1700170958.457 [Default:CheckIn:D] Stopped
2023-11-16T21:42:38.457Z,1700170958.457 [Default:CheckIn:E] Running Loop=1
2023-11-16T21:42:38.852Z,1700170958.852 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 96.489665 min 
2023-11-16T21:42:38.852Z,1700170958.852 [Default:CheckIn:E] Stopped
2023-11-16T21:42:38.852Z,1700170958.852 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-11-16T21:42:38.852Z,1700170958.852 [Default:CheckIn] Stopped
2023-11-16T21:42:38.852Z,1700170958.852 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-11-16T21:42:38.852Z,1700170958.852 [Default:CheckIn](INFO): Running loop #15
2023-11-16T21:42:38.852Z,1700170958.852 [Default:CheckIn] Running Loop=15
2023-11-16T21:42:38.853Z,1700170958.853 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-11-16T21:42:38.853Z,1700170958.853 [Default:CheckIn:Read_GPS] Running Loop=1
2023-11-16T21:42:40.860Z,1700170960.860 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214240.00,A,3648.15363,N,12147.28670,W,0.233,176.38,161123,,,D*76
2023-11-16T21:42:40.862Z,1700170960.862 [NAL9602](INFO): GPS fix at 20231116T214240: (36.802560, -121.788112)
2023-11-16T21:42:40.874Z,1700170960.874 [Default:CheckIn:Read_GPS] Stopped
2023-11-16T21:42:40.874Z,1700170960.874 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-11-16T21:42:49.391Z,1700170969.391 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20231116T200214/Courier0046.lzma
2023-11-16T21:42:50.394Z,1700170970.394 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Courier0046.lzma.bak
2023-11-16T21:42:50.394Z,1700170970.394 [DataOverHttps](INFO): SBD MOMSN=19071641
2023-11-16T21:43:09.033Z,1700170989.033 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20231116T200214/Express0047.lzma
2023-11-16T21:43:10.040Z,1700170990.040 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Express0047.lzma.bak
2023-11-16T21:43:10.041Z,1700170990.041 [DataOverHttps](INFO): SBD MOMSN=19071671
2023-11-16T21:43:11.582Z,1700170991.582 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-11-16T21:43:11.660Z,1700170991.660 [NAL9602](ERROR): received: 
+CSQ:0

OK020, 2, 0, 0, 0

OK
2023-11-16T21:43:14.445Z,1700170994.445 [Default:CheckIn:Read_Iridium] Stopped
2023-11-16T21:43:14.445Z,1700170994.445 [Default:CheckIn:C.Wait] Running Loop=1
2023-11-16T21:43:14.445Z,1700170994.445 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-11-16T21:43:37.858Z,1700171017.858 [NAL9602](INFO): SBD MO Status=2, MOMSN=14020, MT Status=2, MTMSN=0
2023-11-16T21:43:37.858Z,1700171017.858 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-11-16T21:44:02.087Z,1700171042.087 [NAL9602](INFO): SBD MO Status=2, MOMSN=14020, MT Status=2, MTMSN=0
2023-11-16T21:44:02.088Z,1700171042.088 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-11-16T21:44:36.431Z,1700171076.431 [NAL9602](INFO): SBD MO Status=2, MOMSN=14020, MT Status=2, MTMSN=0
2023-11-16T21:44:36.431Z,1700171076.431 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-11-16T21:45:29.347Z,1700171129.347 [NAL9602](INFO): SBD MO Status=0, MOMSN=14020, MT Status=0, MTMSN=0
2023-11-16T21:45:29.347Z,1700171129.347 [NAL9602](INFO): No messages in MT queue
2023-11-16T21:46:00.062Z,1700171160.062 [NAL9602](INFO): Not Powering down - fast GPS
2023-11-16T21:48:15.059Z,1700171295.059 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-11-16T21:48:15.059Z,1700171295.059 [Default:CheckIn:C.Wait] Stopped
2023-11-16T21:48:15.059Z,1700171295.059 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-11-16T21:48:15.059Z,1700171295.059 [Default:CheckIn:D] Running Loop=1
2023-11-16T21:48:15.426Z,1700171295.426 [Default:CheckIn:D] Stopped
2023-11-16T21:48:15.426Z,1700171295.426 [Default:CheckIn:E] Running Loop=1
2023-11-16T21:48:15.816Z,1700171295.816 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 102.105811 min 
2023-11-16T21:48:15.817Z,1700171295.817 [Default:CheckIn:E] Stopped
2023-11-16T21:48:15.817Z,1700171295.817 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-11-16T21:48:15.817Z,1700171295.817 [Default:CheckIn] Stopped
2023-11-16T21:48:15.817Z,1700171295.817 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-11-16T21:48:15.817Z,1700171295.817 [Default:CheckIn](INFO): Running loop #16
2023-11-16T21:48:15.817Z,1700171295.817 [Default:CheckIn] Running Loop=16
2023-11-16T21:48:15.817Z,1700171295.817 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-11-16T21:48:15.817Z,1700171295.817 [Default:CheckIn:Read_GPS] Running Loop=1
2023-11-16T21:48:17.831Z,1700171297.831 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214817.00,A,3648.16349,N,12147.28334,W,0.233,176.38,161123,,,D*70
2023-11-16T21:48:17.833Z,1700171297.833 [NAL9602](INFO): GPS fix at 20231116T214817: (36.802725, -121.788056)
2023-11-16T21:48:17.845Z,1700171297.845 [Default:CheckIn:Read_GPS] Stopped
2023-11-16T21:48:17.845Z,1700171297.845 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-11-16T21:48:27.176Z,1700171307.176 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231116T200214/Courier0049.lzma
2023-11-16T21:48:28.178Z,1700171308.178 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Courier0049.lzma.bak
2023-11-16T21:48:28.178Z,1700171308.178 [DataOverHttps](INFO): SBD MOMSN=19071682
2023-11-16T21:48:48.868Z,1700171328.868 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20231116T200214/Express0050.lzma
2023-11-16T21:48:49.870Z,1700171329.870 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Express0050.lzma.bak
2023-11-16T21:48:49.870Z,1700171329.870 [DataOverHttps](INFO): SBD MOMSN=19071685
2023-11-16T21:48:54.246Z,1700171334.246 [Default:CheckIn:Read_Iridium] Stopped
2023-11-16T21:48:54.246Z,1700171334.246 [Default:CheckIn:C.Wait] Running Loop=1
2023-11-16T21:48:54.246Z,1700171334.246 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-11-16T21:52:48.514Z,1700171568.514 [NAL9602](INFO): SBD MO Status=0, MOMSN=14021, MT Status=0, MTMSN=0
2023-11-16T21:52:48.514Z,1700171568.514 [NAL9602](INFO): No messages in MT queue
2023-11-16T21:53:19.217Z,1700171599.217 [NAL9602](INFO): Not Powering down - fast GPS
2023-11-16T21:53:54.779Z,1700171634.779 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-11-16T21:53:54.779Z,1700171634.779 [Default:CheckIn:C.Wait] Stopped
2023-11-16T21:53:54.780Z,1700171634.780 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-11-16T21:53:54.780Z,1700171634.780 [Default:CheckIn:D] Running Loop=1
2023-11-16T21:53:55.189Z,1700171635.189 [Default:CheckIn:D] Stopped
2023-11-16T21:53:55.189Z,1700171635.189 [Default:CheckIn:E] Running Loop=1
2023-11-16T21:53:55.593Z,1700171635.593 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 107.768530 min 
2023-11-16T21:53:55.593Z,1700171635.593 [Default:CheckIn:E] Stopped
2023-11-16T21:53:55.593Z,1700171635.593 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-11-16T21:53:55.593Z,1700171635.593 [Default:CheckIn] Stopped
2023-11-16T21:53:55.593Z,1700171635.593 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-11-16T21:53:55.594Z,1700171635.594 [Default:CheckIn](INFO): Running loop #17
2023-11-16T21:53:55.594Z,1700171635.594 [Default:CheckIn] Running Loop=17
2023-11-16T21:53:55.594Z,1700171635.594 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-11-16T21:53:55.594Z,1700171635.594 [Default:CheckIn:Read_GPS] Running Loop=1
2023-11-16T21:53:57.599Z,1700171637.599 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215356.00,A,3648.16202,N,12147.28635,W,0.214,317.67,161123,,,D*7F
2023-11-16T21:53:57.602Z,1700171637.602 [NAL9602](INFO): GPS fix at 20231116T215356: (36.802700, -121.788106)
2023-11-16T21:53:57.615Z,1700171637.615 [Default:CheckIn:Read_GPS] Stopped
2023-11-16T21:53:57.615Z,1700171637.615 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-11-16T21:54:06.487Z,1700171646.487 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20231116T200214/Courier0052.lzma
2023-11-16T21:54:07.490Z,1700171647.490 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Courier0052.lzma.bak
2023-11-16T21:54:07.490Z,1700171647.490 [DataOverHttps](INFO): SBD MOMSN=19071748
2023-11-16T21:54:27.497Z,1700171667.497 [NAL9602](INFO): SBD MO Status=2, MOMSN=14022, MT Status=2, MTMSN=0
2023-11-16T21:54:27.497Z,1700171667.497 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-11-16T21:54:27.784Z,1700171667.784 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20231116T200214/Express0053.lzma
2023-11-16T21:54:28.787Z,1700171668.787 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Express0053.lzma.bak
2023-11-16T21:54:28.787Z,1700171668.787 [DataOverHttps](INFO): SBD MOMSN=19071751
2023-11-16T21:54:33.191Z,1700171673.191 [Default:CheckIn:Read_Iridium] Stopped
2023-11-16T21:54:33.191Z,1700171673.191 [Default:CheckIn:C.Wait] Running Loop=1
2023-11-16T21:54:33.191Z,1700171673.191 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-11-16T21:54:36.382Z,1700171676.382 [NAL9602](INFO): SBD MO Status=0, MOMSN=14022, MT Status=0, MTMSN=0
2023-11-16T21:54:36.382Z,1700171676.382 [NAL9602](INFO): No messages in MT queue
2023-11-16T21:55:07.085Z,1700171707.085 [NAL9602](INFO): Not Powering down - fast GPS
2023-11-16T21:59:33.749Z,1700171973.749 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-11-16T21:59:33.749Z,1700171973.749 [Default:CheckIn:C.Wait] Stopped
2023-11-16T21:59:33.749Z,1700171973.749 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-11-16T21:59:33.749Z,1700171973.749 [Default:CheckIn:D] Running Loop=1
2023-11-16T21:59:34.156Z,1700171974.156 [Default:CheckIn:D] Stopped
2023-11-16T21:59:34.156Z,1700171974.156 [Default:CheckIn:E] Running Loop=1
2023-11-16T21:59:34.557Z,1700171974.557 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 113.417977 min 
2023-11-16T21:59:34.557Z,1700171974.557 [Default:CheckIn:E] Stopped
2023-11-16T21:59:34.558Z,1700171974.558 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-11-16T21:59:34.558Z,1700171974.558 [Default:CheckIn] Stopped
2023-11-16T21:59:34.558Z,1700171974.558 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-11-16T21:59:34.558Z,1700171974.558 [Default:CheckIn](INFO): Running loop #18
2023-11-16T21:59:34.558Z,1700171974.558 [Default:CheckIn] Running Loop=18
2023-11-16T21:59:34.558Z,1700171974.558 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-11-16T21:59:34.558Z,1700171974.558 [Default:CheckIn:Read_GPS] Running Loop=1
2023-11-16T21:59:36.567Z,1700171976.567 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215935.00,A,3648.16465,N,12147.28182,W,0.292,317.67,161123,,,D*72
2023-11-16T21:59:36.569Z,1700171976.569 [NAL9602](INFO): GPS fix at 20231116T215935: (36.802744, -121.788030)
2023-11-16T21:59:36.582Z,1700171976.582 [Default:CheckIn:Read_GPS] Stopped
2023-11-16T21:59:36.582Z,1700171976.582 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-11-16T21:59:45.591Z,1700171985.591 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231116T200214/Courier0055.lzma
2023-11-16T21:59:46.594Z,1700171986.594 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Courier0055.lzma.bak
2023-11-16T21:59:46.594Z,1700171986.594 [DataOverHttps](INFO): SBD MOMSN=19071771
2023-11-16T22:00:07.375Z,1700172007.375 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20231116T200214/Express0056.lzma
2023-11-16T22:00:08.374Z,1700172008.374 [DataOverHttps](INFO): Moved sent file to Logs/20231116T200214/Express0056.lzma.bak
2023-11-16T22:00:08.374Z,1700172008.374 [DataOverHttps](INFO): SBD MOMSN=19071774
2023-11-16T22:00:12.546Z,1700172012.546 [Default:CheckIn:Read_Iridium] Stopped
2023-11-16T22:00:12.546Z,1700172012.546 [Default:CheckIn:C.Wait] Running Loop=1
2023-11-16T22:00:12.547Z,1700172012.547 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-11-16T22:01:56.351Z,1700172116.351 [NAL9602](INFO): SBD MO Status=2, MOMSN=14023, MT Status=2, MTMSN=0
2023-11-16T22:01:56.351Z,1700172116.351 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-11-16T22:02:54.522Z,1700172174.522 [NAL9602](INFO): SBD MO Status=2, MOMSN=14023, MT Status=2, MTMSN=0
2023-11-16T22:02:54.522Z,1700172174.522 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-11-16T22:03:19.583Z,1700172199.583 [NAL9602](INFO): SBD MO Status=2, MOMSN=14023, MT Status=2, MTMSN=0
2023-11-16T22:03:19.583Z,1700172199.583 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-11-16T22:03:27.669Z,1700172207.669 [DataOverHttps](IMPORTANT): SBD MTMSN=20231116T220326
2023-11-16T22:03:35.000Z,1700172215.000 [DataOverHttps](INFO): Received command: restart sys
2023-11-16T22:03:35.057Z,1700172215.057 [CommandExec](IMPORTANT): got command restart system
2023-11-16T22:03:36.214Z,1700172216.214 [CBIT](IMPORTANT): Beginning ground fault scan
2023-11-16T22:03:39.018Z,1700172219.018 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2023-11-16T22:03:47.087Z,1700172227.087 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.918571
CHAN A1 (24V) N/A reporting off
CHAN A2 (12V): 0.942598
CHAN A3 (5V): 0.990890
CHAN B0 (3.3V): 0.939121
CHAN B1 (3.15aV): 1.009352
CHAN B2 (3.15bV): 1.009952
CHAN B3 (GND): 0.556073
OPEN: 0.037037
Full Scale: +/- 1 mA
2023-11-16T22:04:01.191Z,1700172241.191 [NAL9602](INFO): SBD MO Status=2, MOMSN=14023, MT Status=2, MTMSN=0
2023-11-16T22:04:01.191Z,1700172241.191 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-11-16T22:04:16.547Z,1700172256.547 [NAL9602](INFO): SBD MO Status=0, MOMSN=14023, MT Status=0, MTMSN=0
2023-11-16T22:04:16.547Z,1700172256.547 [NAL9602](INFO): No messages in MT queue
2023-11-16T22:04:47.244Z,1700172287.244 [NAL9602](INFO): Not Powering down - fast GPS
2023-11-16T22:05:13.116Z,1700172313.116 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-11-16T22:05:13.117Z,1700172313.117 [Default:CheckIn:C.Wait] Stopped
2023-11-16T22:05:13.117Z,1700172313.117 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-11-16T22:05:13.117Z,1700172313.117 [Default:CheckIn:D] Running Loop=1
2023-11-16T22:05:13.518Z,1700172313.518 [Default:CheckIn:D] Stopped
2023-11-16T22:05:13.518Z,1700172313.518 [Default:CheckIn:E] Running Loop=1
2023-11-16T22:05:13.933Z,1700172313.933 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 119.074015 min 
2023-11-16T22:05:13.933Z,1700172313.933 [Default:CheckIn:E] Stopped
2023-11-16T22:05:13.933Z,1700172313.933 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-11-16T22:05:13.933Z,1700172313.933 [Default:CheckIn] Stopped
2023-11-16T22:05:13.934Z,1700172313.934 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-11-16T22:05:13.934Z,1700172313.934 [Default:CheckIn](INFO): Running loop #19
2023-11-16T22:05:13.934Z,1700172313.934 [Default:CheckIn] Running Loop=19
2023-11-16T22:05:13.934Z,1700172313.934 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-11-16T22:05:13.934Z,1700172313.934 [Default:CheckIn:Read_GPS] Running Loop=1
2023-11-16T22:05:15.939Z,1700172315.939 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220515.00,A,3648.15756,N,12147.28623,W,0.078,43.85,161123,,,D*4E
2023-11-16T22:05:15.941Z,1700172315.941 [NAL9602](INFO): GPS fix at 20231116T220515: (36.802626, -121.788104)
2023-11-16T22:05:15.979Z,1700172315.979 [Default:CheckIn:Read_GPS] Stopped
2023-11-16T22:05:15.979Z,1700172315.979 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-11-16T22:05:23.115Z,1700172323.115 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231116T200214/Courier0058.l