2021-09-30T19:56:08.005Z,1633031768.005 [Supervisor](DEBUG): Initializing supervisor.
2021-09-30T19:56:08.010Z,1633031768.010 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2021-09-30T19:56:08.011Z,1633031768.011 [SyncHandler](INFO): Protected caller Thread ID is 2317
2021-09-30T19:56:08.011Z,1633031768.011 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2021-09-30T19:56:08.012Z,1633031768.012 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2021-09-30T19:56:08.012Z,1633031768.012 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2318
2021-09-30T19:56:08.017Z,1633031768.017 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2021-09-30T19:56:08.035Z,1633031768.035 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2021-09-30T19:56:08.036Z,1633031768.036 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2021-09-30T19:56:08.037Z,1633031768.037 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 2319
2021-09-30T19:56:08.041Z,1633031768.041 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2021-09-30T19:56:08.042Z,1633031768.042 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2021-09-30T19:56:08.042Z,1633031768.042 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2320
2021-09-30T19:56:08.045Z,1633031768.045 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2021-09-30T19:56:08.046Z,1633031768.046 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2021-09-30T19:56:08.046Z,1633031768.046 [logger ThreadHandler](INFO): Protected caller Thread ID is 2321
2021-09-30T19:56:08.050Z,1633031768.050 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2021-09-30T19:56:08.050Z,1633031768.050 [Supervisor](INFO): Looking for Config files in directory: Config/
2021-09-30T19:56:08.052Z,1633031768.052 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2021-09-30T19:56:08.535Z,1633031768.535 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2021-09-30T19:56:08.536Z,1633031768.536 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2021-09-30T19:56:08.681Z,1633031768.681 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2021-09-30T19:56:08.711Z,1633031768.711 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2021-09-30T19:56:08.793Z,1633031768.793 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2021-09-30T19:56:09.010Z,1633031769.010 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2021-09-30T19:56:09.010Z,1633031769.010 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2021-09-30T19:56:09.090Z,1633031769.090 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2021-09-30T19:56:09.187Z,1633031769.187 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2021-09-30T19:56:09.188Z,1633031769.188 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2021-09-30T19:56:09.528Z,1633031769.528 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2021-09-30T19:56:09.529Z,1633031769.529 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2021-09-30T19:56:09.653Z,1633031769.653 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2021-09-30T19:56:09.654Z,1633031769.654 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2021-09-30T19:56:10.164Z,1633031770.164 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2021-09-30T19:56:10.165Z,1633031770.165 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2021-09-30T19:56:10.366Z,1633031770.366 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2021-09-30T19:56:10.366Z,1633031770.366 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2021-09-30T19:56:10.729Z,1633031770.729 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2021-09-30T19:56:10.730Z,1633031770.730 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2021-09-30T19:56:10.964Z,1633031770.964 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2021-09-30T19:56:10.964Z,1633031770.964 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2021-09-30T19:56:11.073Z,1633031771.073 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2021-09-30T19:56:11.074Z,1633031771.074 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2021-09-30T19:56:11.728Z,1633031771.728 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2021-09-30T19:56:11.729Z,1633031771.729 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2021-09-30T19:56:12.992Z,1633031772.992 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2021-09-30T19:56:12.992Z,1633031772.992 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2021-09-30T19:56:13.199Z,1633031773.199 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2021-09-30T19:56:13.201Z,1633031773.201 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/
2021-09-30T19:56:13.203Z,1633031773.203 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/vehicle.cfg
2021-09-30T19:56:13.402Z,1633031773.402 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/secure.cfg
2021-09-30T19:56:13.486Z,1633031773.486 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Science.cfg
2021-09-30T19:56:13.621Z,1633031773.621 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Simulator.cfg
2021-09-30T19:56:13.708Z,1633031773.708 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Battery.cfg
2021-09-30T19:56:13.965Z,1633031773.965 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2021-09-30T19:56:13.966Z,1633031773.966 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/logger.cfg
2021-09-30T19:56:14.069Z,1633031774.069 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Servo.cfg
2021-09-30T19:56:14.181Z,1633031774.181 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Navigation.cfg
2021-09-30T19:56:14.275Z,1633031774.275 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Sensor.cfg
2021-09-30T19:56:14.418Z,1633031774.418 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Control.cfg
2021-09-30T19:56:14.517Z,1633031774.517 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/BIT.cfg
2021-09-30T19:56:14.611Z,1633031774.611 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/root/
2021-09-30T19:56:14.611Z,1633031774.611 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2021-09-30T19:56:14.628Z,1633031774.628 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2021-09-30T19:56:14.645Z,1633031774.645 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2021-09-30T19:56:14.646Z,1633031774.646 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2021-09-30T19:56:14.763Z,1633031774.763 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2021-09-30T19:56:14.764Z,1633031774.764 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2021-09-30T19:56:14.833Z,1633031774.833 [VerticalControl](DEBUG): Construct VerticalControl.
2021-09-30T19:56:14.895Z,1633031774.895 [VerticalControl] Loaded
2021-09-30T19:56:14.895Z,1633031774.895 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2021-09-30T19:56:14.898Z,1633031774.898 [HorizontalControl](DEBUG): Construct HorizontalControl.
2021-09-30T19:56:14.936Z,1633031774.936 [HorizontalControl] Loaded
2021-09-30T19:56:14.937Z,1633031774.937 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2021-09-30T19:56:14.939Z,1633031774.939 [SpeedControl](DEBUG): Construct SpeedControl.
2021-09-30T19:56:14.942Z,1633031774.942 [SpeedControl] Loaded
2021-09-30T19:56:14.942Z,1633031774.942 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2021-09-30T19:56:14.945Z,1633031774.945 [LoopControl](DEBUG): Construct LoopControl.
2021-09-30T19:56:14.946Z,1633031774.946 [LoopControl] Loaded
2021-09-30T19:56:14.946Z,1633031774.946 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2021-09-30T19:56:14.946Z,1633031774.946 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2021-09-30T19:56:14.947Z,1633031774.947 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2021-09-30T19:56:15.124Z,1633031775.124 [BuoyancyServo] Loaded
2021-09-30T19:56:15.124Z,1633031775.124 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2021-09-30T19:56:15.144Z,1633031775.144 [ElevatorServo] Loaded
2021-09-30T19:56:15.144Z,1633031775.144 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2021-09-30T19:56:15.162Z,1633031775.162 [MassServo] Loaded
2021-09-30T19:56:15.162Z,1633031775.162 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2021-09-30T19:56:15.180Z,1633031775.180 [RudderServo] Loaded
2021-09-30T19:56:15.180Z,1633031775.180 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2021-09-30T19:56:15.197Z,1633031775.197 [ThrusterHE] Loaded
2021-09-30T19:56:15.197Z,1633031775.197 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2021-09-30T19:56:15.198Z,1633031775.198 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2021-09-30T19:56:15.198Z,1633031775.198 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2021-09-30T19:56:15.258Z,1633031775.258 [DepthRateCalculator] Loaded
2021-09-30T19:56:15.258Z,1633031775.258 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2021-09-30T19:56:15.263Z,1633031775.263 [PitchRateCalculator] Loaded
2021-09-30T19:56:15.263Z,1633031775.263 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2021-09-30T19:56:15.273Z,1633031775.273 [SpeedCalculator] Loaded
2021-09-30T19:56:15.274Z,1633031775.274 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2021-09-30T19:56:15.287Z,1633031775.287 [TempGradientCalculator] Loaded
2021-09-30T19:56:15.287Z,1633031775.287 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2021-09-30T19:56:15.292Z,1633031775.292 [YawRateCalculator] Loaded
2021-09-30T19:56:15.292Z,1633031775.292 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2021-09-30T19:56:15.309Z,1633031775.309 [ElevatorOffsetCalculator] Loaded
2021-09-30T19:56:15.310Z,1633031775.310 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2021-09-30T19:56:15.310Z,1633031775.310 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2021-09-30T19:56:15.311Z,1633031775.311 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2021-09-30T19:56:15.410Z,1633031775.410 [DeadReckonUsingMultipleVelocitySources] Loaded
2021-09-30T19:56:15.410Z,1633031775.410 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2021-09-30T19:56:15.423Z,1633031775.423 [NavChart] Loaded
2021-09-30T19:56:15.423Z,1633031775.423 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2021-09-30T19:56:15.429Z,1633031775.429 [UniversalFixResidualReporter] Loaded
2021-09-30T19:56:15.429Z,1633031775.429 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2021-09-30T19:56:15.430Z,1633031775.430 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2021-09-30T19:56:15.430Z,1633031775.430 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2021-09-30T19:56:15.912Z,1633031775.912 [AHRS_M2] Loaded
2021-09-30T19:56:15.912Z,1633031775.912 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2021-09-30T19:56:15.942Z,1633031775.942 [BackseatComponent] Loaded
2021-09-30T19:56:15.942Z,1633031775.942 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2021-09-30T19:56:15.943Z,1633031775.943 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 4089D4E0
2021-09-30T19:56:15.943Z,1633031775.943 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 2403
2021-09-30T19:56:15.946Z,1633031775.946 [LcmUniversalReporter] Loaded
2021-09-30T19:56:15.946Z,1633031775.946 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2021-09-30T19:56:16.738Z,1633031776.738 [BPC1] Loaded
2021-09-30T19:56:16.738Z,1633031776.738 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2021-09-30T19:56:16.811Z,1633031776.811 [DataOverHttps] Loaded
2021-09-30T19:56:16.811Z,1633031776.811 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2021-09-30T19:56:16.812Z,1633031776.812 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408CD4E0
2021-09-30T19:56:16.813Z,1633031776.813 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 2404
2021-09-30T19:56:16.833Z,1633031776.833 [Depth_Keller] Loaded
2021-09-30T19:56:16.833Z,1633031776.833 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2021-09-30T19:56:16.837Z,1633031776.837 [DropWeight] Loaded
2021-09-30T19:56:16.838Z,1633031776.838 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2021-09-30T19:56:16.896Z,1633031776.896 [NAL9602] Loaded
2021-09-30T19:56:16.897Z,1633031776.897 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2021-09-30T19:56:16.925Z,1633031776.925 [Onboard] Loaded
2021-09-30T19:56:16.926Z,1633031776.926 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2021-09-30T19:56:16.927Z,1633031776.927 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408FD4E0
2021-09-30T19:56:16.927Z,1633031776.927 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 2405
2021-09-30T19:56:16.940Z,1633031776.940 [Power24vConverter] Loaded
2021-09-30T19:56:16.940Z,1633031776.940 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2021-09-30T19:56:16.953Z,1633031776.953 [Radio_Surface] Loaded
2021-09-30T19:56:16.953Z,1633031776.953 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2021-09-30T19:56:16.954Z,1633031776.954 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4092D4E0
2021-09-30T19:56:16.954Z,1633031776.954 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2406
2021-09-30T19:56:16.955Z,1633031776.955 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2021-09-30T19:56:16.956Z,1633031776.956 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2021-09-30T19:56:17.270Z,1633031777.270 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2021-09-30T19:56:17.271Z,1633031777.271 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2021-09-30T19:56:17.712Z,1633031777.712 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2021-09-30T19:56:17.712Z,1633031777.712 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2021-09-30T19:56:17.754Z,1633031777.754 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2021-09-30T19:56:17.754Z,1633031777.754 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2021-09-30T19:56:17.972Z,1633031777.972 [CTD_Seabird] Loaded
2021-09-30T19:56:17.973Z,1633031777.973 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2021-09-30T19:56:17.974Z,1633031777.974 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A4D4E0
2021-09-30T19:56:17.974Z,1633031777.974 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 2407
2021-09-30T19:56:18.006Z,1633031778.006 [ESPComponent] Loaded
2021-09-30T19:56:18.006Z,1633031778.006 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2021-09-30T19:56:18.026Z,1633031778.026 [PAR_Licor] Loaded
2021-09-30T19:56:18.026Z,1633031778.026 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2021-09-30T19:56:18.058Z,1633031778.058 [WetLabsBB2FL] Loaded
2021-09-30T19:56:18.058Z,1633031778.058 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2021-09-30T19:56:18.059Z,1633031778.059 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A7D4E0
2021-09-30T19:56:18.059Z,1633031778.059 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 2408
2021-09-30T19:56:18.060Z,1633031778.060 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2021-09-30T19:56:18.061Z,1633031778.061 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2021-09-30T19:56:18.434Z,1633031778.434 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2021-09-30T19:56:18.435Z,1633031778.435 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2021-09-30T19:56:18.608Z,1633031778.608 [SBIT](DEBUG): Construct Startup Built In Test.
2021-09-30T19:56:18.618Z,1633031778.618 [SBIT] Loaded
2021-09-30T19:56:18.618Z,1633031778.618 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2021-09-30T19:56:18.621Z,1633031778.621 [IBIT](DEBUG): Construct Initiated Built In Test.
2021-09-30T19:56:18.634Z,1633031778.634 [IBIT] Loaded
2021-09-30T19:56:18.634Z,1633031778.634 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2021-09-30T19:56:18.640Z,1633031778.640 [CBIT](DEBUG): Construct Continuous Built In Test.
2021-09-30T19:56:18.741Z,1633031778.741 [CBIT] Loaded
2021-09-30T19:56:18.741Z,1633031778.741 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2021-09-30T19:56:18.742Z,1633031778.742 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2021-09-30T19:56:18.748Z,1633031778.748 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2021-09-30T19:56:18.751Z,1633031778.751 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2021-09-30T19:56:18.762Z,1633031778.762 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2021-09-30T19:56:18.763Z,1633031778.763 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B644E0
2021-09-30T19:56:18.764Z,1633031778.764 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2409
2021-09-30T19:56:18.768Z,1633031778.768 [Supervisor](INFO): Main Thread ID is 829
2021-09-30T19:56:18.768Z,1633031778.768 [Supervisor](DEBUG): Running supervisor.
2021-09-30T19:56:18.769Z,1633031778.769 [CommandExec ThreadHandler](INFO): Handler Thread ID is 2410
2021-09-30T19:56:18.770Z,1633031778.770 [CommandExec](INFO): Initializing the command executive.
2021-09-30T19:56:18.771Z,1633031778.771 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2411
2021-09-30T19:56:18.774Z,1633031778.774 [controlThread ThreadHandler](INFO): Handler Thread ID is 2412
2021-09-30T19:56:18.775Z,1633031778.775 [controlThread](DEBUG): Initializing ControlThread
2021-09-30T19:56:18.776Z,1633031778.776 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2021-09-30T19:56:18.778Z,1633031778.778 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2021-09-30T19:56:18.778Z,1633031778.778 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2021-09-30T19:56:18.779Z,1633031778.779 [LoopControl](DEBUG): Initialize LoopControlComponent.
2021-09-30T19:56:18.780Z,1633031778.780 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2021-09-30T19:56:18.781Z,1633031778.781 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2021-09-30T19:56:18.781Z,1633031778.781 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2021-09-30T19:56:18.781Z,1633031778.781 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2021-09-30T19:56:18.782Z,1633031778.782 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2021-09-30T19:56:18.782Z,1633031778.782 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2021-09-30T19:56:18.783Z,1633031778.783 [NavChart](DEBUG): Initialize NavChart Navigation.
2021-09-30T19:56:18.784Z,1633031778.784 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2021-09-30T19:56:18.792Z,1633031778.792 [SBIT](INFO): Initialize SBIT Component.
2021-09-30T19:56:18.793Z,1633031778.793 [SBIT](IMPORTANT): git: 2021-09-30
2021-09-30T19:56:18.793Z,1633031778.793 [SBIT](INFO): git hash: 686aa089dd190911c79334edbea69c626bd81f34
2021-09-30T19:56:18.793Z,1633031778.793 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2021-09-30T19:56:18.794Z,1633031778.794 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2021-09-30T19:56:18.796Z,1633031778.796 [logger ThreadHandler](INFO): Handler Thread ID is 2413
2021-09-30T19:56:18.812Z,1633031778.812 [SBIT](INFO): Beginning SBIT in 75.000000 seconds.
2021-09-30T19:56:18.812Z,1633031778.812 [IBIT](INFO): Initialize IBIT Component.
2021-09-30T19:56:18.813Z,1633031778.813 [CBIT](DEBUG): Initialize CBIT Component.
2021-09-30T19:56:18.820Z,1633031778.820 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 2414
2021-09-30T19:56:18.824Z,1633031778.824 [CBIT](DEBUG): Initialized mux pins.
2021-09-30T19:56:18.825Z,1633031778.825 [CBIT](DEBUG): Initializing the watchdog timer.
2021-09-30T19:56:18.832Z,1633031778.832 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 2415
2021-09-30T19:56:18.833Z,1633031778.833 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2021-09-30T19:56:18.844Z,1633031778.844 [Onboard ThreadHandler](INFO): Handler Thread ID is 2416
2021-09-30T19:56:18.848Z,1633031778.848 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2021-09-30T19:56:18.849Z,1633031778.849 [CBIT](DEBUG): Initializing heartbeat.
2021-09-30T19:56:18.865Z,1633031778.865 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2417
2021-09-30T19:56:18.880Z,1633031778.880 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 2418
2021-09-30T19:56:18.881Z,1633031778.881 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2021-09-30T19:56:18.885Z,1633031778.885 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 2420
2021-09-30T19:56:18.888Z,1633031778.888 [WetLabsBB2FL](INFO): Powering up
2021-09-30T19:56:18.890Z,1633031778.890 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2422
2021-09-30T19:56:18.898Z,1633031778.898 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2021-09-30T19:56:18.898Z,1633031778.898 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2021-09-30T19:56:18.898Z,1633031778.898 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2021-09-30T19:56:18.898Z,1633031778.898 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2021-09-30T19:56:18.899Z,1633031778.899 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2021-09-30T19:56:18.899Z,1633031778.899 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2021-09-30T19:56:18.899Z,1633031778.899 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2021-09-30T19:56:18.899Z,1633031778.899 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2021-09-30T19:56:18.899Z,1633031778.899 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2021-09-30T19:56:18.899Z,1633031778.899 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2021-09-30T19:56:18.900Z,1633031778.900 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2021-09-30T19:56:18.900Z,1633031778.900 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2021-09-30T19:56:18.900Z,1633031778.900 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2021-09-30T19:56:18.901Z,1633031778.901 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2021-09-30T19:56:18.901Z,1633031778.901 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2021-09-30T19:56:18.901Z,1633031778.901 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2021-09-30T19:56:18.920Z,1633031778.920 [CBIT](DEBUG): Deactivating GF circuits.
2021-09-30T19:56:18.920Z,1633031778.920 [CBIT](DEBUG): Deactivating emergency mode.
2021-09-30T19:56:18.956Z,1633031778.956 [CBIT](DEBUG): Backplane powered.
2021-09-30T19:56:18.957Z,1633031778.957 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2021-09-30T19:56:18.985Z,1633031778.985 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2021-09-30T19:56:19.006Z,1633031779.006 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

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

    <Aggregate Id="StartupSatComms">

        <Sequence/>

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

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

    </Aggregate>

</Mission>


2021-09-30T19:56:19.006Z,1633031779.006 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2021-09-30T19:56:19.101Z,1633031779.101 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2021-09-30T19:56:19.103Z,1633031779.103 [Default:A.Wait](DEBUG): Construct Wait.
2021-09-30T19:56:19.137Z,1633031779.137 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2021-09-30T19:56:19.158Z,1633031779.158 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2021-09-30T19:56:19.196Z,1633031779.196 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2021-09-30T19:56:19.202Z,1633031779.202 [Default:E.Execute](DEBUG): Construct Execute.
2021-09-30T19:56:19.222Z,1633031779.222 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

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

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

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

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

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

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

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

    </Aggregate>

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

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

</Mission>


2021-09-30T19:56:19.227Z,1633031779.227 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2021-09-30T19:56:19.250Z,1633031779.250 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2021-09-30T19:56:19.268Z,1633031779.268 [Radio_Surface](INFO): Powering up
2021-09-30T19:56:19.334Z,1633031779.334 [Power24vConverter](INFO): Powering up.
2021-09-30T19:56:19.425Z,1633031779.425 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2021-09-30T19:56:19.433Z,1633031779.433 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2021-09-30T19:56:19.434Z,1633031779.434 [ElevatorServo](DEBUG): Initializing EZServoServo.
2021-09-30T19:56:19.440Z,1633031779.440 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2021-09-30T19:56:19.441Z,1633031779.441 [MassServo](DEBUG): Initializing EZServoServo.
2021-09-30T19:56:19.449Z,1633031779.449 [MassServo](DEBUG): Initializing MassServo.
2021-09-30T19:56:19.450Z,1633031779.450 [RudderServo](DEBUG): Initializing EZServoServo.
2021-09-30T19:56:19.456Z,1633031779.456 [RudderServo](DEBUG): Initializing RudderServo.
2021-09-30T19:56:19.457Z,1633031779.457 [ThrusterHE](DEBUG): Initializing EZServoServo.
2021-09-30T19:56:19.464Z,1633031779.464 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2021-09-30T19:56:20.372Z,1633031780.372 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2021-09-30T19:56:20.372Z,1633031780.372 [RudderServo](FAULT): Rudder failed to initialize
2021-09-30T19:56:20.373Z,1633031780.373 [RudderServo] Communications Fault, FailCount= 1
2021-09-30T19:56:20.373Z,1633031780.373 [RudderServo](ERROR): Communications Fault
2021-09-30T19:56:20.389Z,1633031780.389 [CBIT](ERROR): Communications Fault in component: RudderServo
2021-09-30T19:56:20.593Z,1633031780.593 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2021-09-30T19:56:20.593Z,1633031780.593 [RudderServo](INFO): Powering down
2021-09-30T19:56:20.996Z,1633031780.996 [WetLabsBB2FL](INFO): Powering down
2021-09-30T19:56:21.277Z,1633031781.277 [RudderServo](DEBUG): Initializing EZServoServo.
2021-09-30T19:56:21.397Z,1633031781.397 [RudderServo](DEBUG): Initializing RudderServo.
2021-09-30T19:56:21.401Z,1633031781.401 [CBIT](INFO): Clearing failed state for component RudderServo
2021-09-30T19:56:21.401Z,1633031781.401 [RudderServo] No Fault, FailCount= 1
2021-09-30T19:56:25.912Z,1633031785.912 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2021-09-30T19:56:47.118Z,1633031807.118 [NAL9602](INFO): Powering up NAL9602
2021-09-30T19:56:58.026Z,1633031818.026 [NAL9602](INFO): NAL9602 initialized
2021-09-30T19:57:34.408Z,1633031854.408 [SBIT](IMPORTANT): Beginning Startup BIT
2021-09-30T19:57:34.412Z,1633031854.412 [CBIT](IMPORTANT): Beginning ground fault scan
2021-09-30T19:57:45.335Z,1633031865.335 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.222844
CHAN A1 (24V): -0.020656
CHAN A2 (12V): 0.148898
CHAN A3 (5V): 0.043659
CHAN B0 (3.3V): 0.029506
CHAN B1 (3.15aV): 0.029246
CHAN B2 (3.15bV): 0.029720
CHAN B3 (GND): -0.009147
OPEN: 0.012765
Full Scale: +/- 1 mA
2021-09-30T19:58:28.538Z,1633031908.538 [SBIT](IMPORTANT): SBIT PASSED
2021-09-30T19:58:28.539Z,1633031908.539 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2021-09-30T19:58:28.539Z,1633031908.539 [SBIT](IMPORTANT): AHRS_M2.loadAtStartup=1 bool;

2021-09-30T19:58:28.540Z,1633031908.540 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=8 count;

2021-09-30T19:58:28.540Z,1633031908.540 [SBIT](IMPORTANT): BPC1.batterySamplingInterval=1 minute;

2021-09-30T19:58:28.540Z,1633031908.540 [SBIT](IMPORTANT): BPC1.batteryStickCommsTimeout=10 second;

2021-09-30T19:58:28.540Z,1633031908.540 [SBIT](IMPORTANT): BackseatComponent.loadAtStartup=1 bool;

2021-09-30T19:58:28.540Z,1633031908.540 [SBIT](IMPORTANT): CBIT.gf24Offset=-18.106 microampere;

2021-09-30T19:58:28.540Z,1633031908.540 [SBIT](IMPORTANT): CBIT.stopDepth=295 meter;

2021-09-30T19:58:28.540Z,1633031908.540 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool;

2021-09-30T19:58:28.541Z,1633031908.541 [SBIT](IMPORTANT): ESPComponent.loadAtStartup=1 bool;

2021-09-30T19:58:28.541Z,1633031908.541 [SBIT](IMPORTANT): ESPComponent.simulateHardware=1 bool;

2021-09-30T19:58:28.541Z,1633031908.541 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water;

2021-09-30T19:58:28.541Z,1633031908.541 [SBIT](IMPORTANT): Express linearApproximation platform_pitch_angle 5.000000 degree;

2021-09-30T19:58:28.541Z,1633031908.541 [SBIT](IMPORTANT): Express none platform_roll_angle;

2021-09-30T19:58:28.541Z,1633031908.541 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=242.233074 cubic_centimeter;

2021-09-30T19:58:28.541Z,1633031908.541 [SBIT](IMPORTANT): VerticalControl.massDefault=13.940048 millimeter;

2021-09-30T19:58:28.971Z,1633031908.971 [MissionManager](IMPORTANT): Started mission Startup
2021-09-30T19:58:28.974Z,1633031908.974 [Startup] Running Loop=1
2021-09-30T19:58:28.975Z,1633031908.975 [Startup](DEBUG): Aggregate::initialize Startup
2021-09-30T19:58:28.975Z,1633031908.975 [Startup:A.GoToSurface] Running Loop=1
2021-09-30T19:58:28.975Z,1633031908.975 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-09-30T19:58:28.975Z,1633031908.975 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-09-30T19:58:28.976Z,1633031908.976 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-09-30T19:58:28.976Z,1633031908.976 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-09-30T19:58:28.977Z,1633031908.977 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-09-30T19:58:28.977Z,1633031908.977 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-09-30T19:58:28.979Z,1633031908.979 [Startup:StartupSatComms] Running Loop=1
2021-09-30T19:58:28.979Z,1633031908.979 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2021-09-30T19:58:28.979Z,1633031908.979 [Startup:StartupSatComms:A] Running Loop=1
2021-09-30T19:58:29.343Z,1633031909.343 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2021-09-30T19:58:46.303Z,1633031926.303 [NAL9602](INFO): SBD MO Status=2, MOMSN=5757, MT Status=2, MTMSN=0
2021-09-30T19:58:46.303Z,1633031926.303 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-09-30T19:59:19.037Z,1633031959.037 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2021-09-30T19:59:19.037Z,1633031959.037 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-09-30T19:59:19.048Z,1633031959.048 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-09-30T19:59:19.455Z,1633031959.455 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-09-30T19:59:19.455Z,1633031959.455 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2021-09-30T19:59:29.134Z,1633031969.134 [Startup:StartupSatComms:A](INFO): Timed out from 2021-09-30T19:58:28.0Z
2021-09-30T19:59:29.134Z,1633031969.134 [Startup:StartupSatComms:A] Stopped
2021-09-30T19:59:29.134Z,1633031969.134 [Startup:StartupSatComms:B] Running Loop=1
2021-09-30T19:59:29.538Z,1633031969.538 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-09-30T19:59:30.339Z,1633031970.339 [NAL9602](INFO): SBD MO Status=2, MOMSN=5757, MT Status=2, MTMSN=0
2021-09-30T19:59:30.339Z,1633031970.339 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-09-30T19:59:44.350Z,1633031984.350 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004255
2021-09-30T19:59:51.599Z,1633031991.599 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20210930T161106/Courier0106.lzma
2021-09-30T19:59:52.602Z,1633031992.602 [DataOverHttps](INFO): Moved sent file to Logs/20210930T161106/Courier0106.lzma.bak
2021-09-30T19:59:52.602Z,1633031992.602 [DataOverHttps](INFO): SBD MOMSN=15951068
2021-09-30T20:00:08.040Z,1633032008.040 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20210930T195607/Courier0000.lzma
2021-09-30T20:00:09.038Z,1633032009.038 [DataOverHttps](INFO): Moved sent file to Logs/20210930T195607/Courier0000.lzma.bak
2021-09-30T20:00:09.038Z,1633032009.038 [DataOverHttps](INFO): SBD MOMSN=15951071
2021-09-30T20:00:24.662Z,1633032024.662 [DataOverHttps](INFO): Sending 1450 bytes from file Logs/20210930T161106/Express0107.lzma
2021-09-30T20:00:25.662Z,1633032025.662 [DataOverHttps](INFO): Moved sent file to Logs/20210930T161106/Express0107.lzma.bak
2021-09-30T20:00:25.662Z,1633032025.662 [DataOverHttps](INFO): SBD MOMSN=15951074
2021-09-30T20:00:29.430Z,1633032029.430 [Startup:StartupSatComms:B](INFO): Timed out from 2021-09-30T19:59:29.1Z
2021-09-30T20:00:29.430Z,1633032029.430 [Startup:StartupSatComms:B] Stopped
2021-09-30T20:00:29.430Z,1633032029.430 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2021-09-30T20:00:29.431Z,1633032029.431 [Startup:StartupSatComms] Stopped
2021-09-30T20:00:29.431Z,1633032029.431 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2021-09-30T20:00:29.436Z,1633032029.436 [Startup](INFO): Completed Startup
2021-09-30T20:00:29.436Z,1633032029.436 [MissionManager](INFO): Startup is completed.
2021-09-30T20:00:29.436Z,1633032029.436 [MissionManager](INFO): Uninitializing Mission Startup
2021-09-30T20:00:29.436Z,1633032029.436 [Startup] Stopped
2021-09-30T20:00:29.437Z,1633032029.437 [Startup](DEBUG): Aggregate::uninitialize Startup
2021-09-30T20:00:29.437Z,1633032029.437 [Startup:A.GoToSurface] Stopped
2021-09-30T20:00:29.437Z,1633032029.437 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-09-30T20:00:29.821Z,1633032029.821 [MissionManager](IMPORTANT): Started mission Default
2021-09-30T20:00:29.822Z,1633032029.822 [Default] Running Loop=1
2021-09-30T20:00:29.822Z,1633032029.822 [Default](DEBUG): Aggregate::initialize Default
2021-09-30T20:00:29.822Z,1633032029.822 [Default:B.GoToSurface] Running Loop=1
2021-09-30T20:00:29.822Z,1633032029.822 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-09-30T20:00:29.822Z,1633032029.822 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-09-30T20:00:29.823Z,1633032029.823 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-09-30T20:00:29.823Z,1633032029.823 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-09-30T20:00:29.823Z,1633032029.823 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-09-30T20:00:29.823Z,1633032029.823 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-09-30T20:00:29.881Z,1633032029.881 [Default:A.Wait] Running Loop=1
2021-09-30T20:00:29.881Z,1633032029.881 [Default:A.Wait](DEBUG): Initialize Wait Component.
2021-09-30T20:00:43.186Z,1633032043.186 [Default:A.Wait](INFO): Done Waiting.
2021-09-30T20:00:43.186Z,1633032043.186 [Default:A.Wait] Stopped
2021-09-30T20:00:43.186Z,1633032043.186 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2021-09-30T20:00:43.579Z,1633032043.579 [Default:CheckIn] Running Loop=1
2021-09-30T20:00:43.579Z,1633032043.579 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-09-30T20:00:43.579Z,1633032043.579 [Default:CheckIn:Read_GPS] Running Loop=1
2021-09-30T20:00:43.967Z,1633032043.967 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2021-09-30T20:00:45.707Z,1633032045.707 [DataOverHttps](INFO): Sending 70 bytes from file Logs/20210930T161106/Express0110.lzma
2021-09-30T20:00:46.710Z,1633032046.710 [DataOverHttps](INFO): Moved sent file to Logs/20210930T161106/Express0110.lzma.bak
2021-09-30T20:00:46.710Z,1633032046.710 [DataOverHttps](INFO): SBD MOMSN=15951407
2021-09-30T20:00:52.043Z,1633032052.043 [NAL9602](INFO): SBD MO Status=2, MOMSN=5757, MT Status=2, MTMSN=0
2021-09-30T20:00:52.043Z,1633032052.043 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-09-30T20:02:01.127Z,1633032121.127 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-09-30T20:02:07.995Z,1633032127.995 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200207.00,A,3648.16777,N,12147.28368,W,0.369,0.00,300921,,,A*71
2021-09-30T20:02:07.999Z,1633032127.999 [NAL9602](INFO): GPS fix at 20210930T200207: (36.802796, -121.788061)
2021-09-30T20:02:08.054Z,1633032128.054 [Default:CheckIn:Read_GPS] Stopped
2021-09-30T20:02:08.054Z,1633032128.054 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-09-30T20:02:08.446Z,1633032128.446 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-09-30T20:02:17.615Z,1633032137.615 [DataOverHttps](INFO): Sending 224 bytes from file Logs/20210930T195607/Courier0004.lzma
2021-09-30T20:02:18.618Z,1633032138.618 [DataOverHttps](INFO): Moved sent file to Logs/20210930T195607/Courier0004.lzma.bak
2021-09-30T20:02:18.618Z,1633032138.618 [DataOverHttps](INFO): SBD MOMSN=15951409
2021-09-30T20:02:38.318Z,1633032158.318 [DataOverHttps](INFO): Sending 1054 bytes from file Logs/20210930T195607/Express0001.lzma
2021-09-30T20:02:39.318Z,1633032159.318 [DataOverHttps](INFO): Moved sent file to Logs/20210930T195607/Express0001.lzma.bak
2021-09-30T20:02:39.318Z,1633032159.318 [DataOverHttps](INFO): SBD MOMSN=15951412
2021-09-30T20:02:40.361Z,1633032160.361 [NAL9602](INFO): Not Powering down - fast GPS
2021-09-30T20:02:56.216Z,1633032176.216 [DataOverHttps](INFO): Sending 330 bytes from file Logs/20210930T195607/Express0005.lzma
2021-09-30T20:02:57.218Z,1633032177.218 [DataOverHttps](INFO): Moved sent file to Logs/20210930T195607/Express0005.lzma.bak
2021-09-30T20:02:57.218Z,1633032177.218 [DataOverHttps](INFO): SBD MOMSN=15951439
2021-09-30T20:02:58.973Z,1633032178.973 [Default:CheckIn:Read_Iridium] Stopped
2021-09-30T20:02:58.974Z,1633032178.974 [Default:CheckIn:C.Wait] Running Loop=1
2021-09-30T20:02:58.974Z,1633032178.974 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-09-30T20:03:07.524Z,1633032187.524 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-09-30T20:06:20.163Z,1633032380.163 [Power24vConverter](INFO): Powering down.
2021-09-30T20:07:59.619Z,1633032479.619 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-09-30T20:07:59.620Z,1633032479.620 [Default:CheckIn:C.Wait] Stopped
2021-09-30T20:07:59.620Z,1633032479.620 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-09-30T20:07:59.620Z,1633032479.620 [Default:CheckIn:D] Running Loop=1
2021-09-30T20:08:00.021Z,1633032480.021 [Default:CheckIn:D] Stopped
2021-09-30T20:08:00.021Z,1633032480.021 [Default:CheckIn:E] Running Loop=1
2021-09-30T20:08:00.436Z,1633032480.436 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 7.503322 min 
2021-09-30T20:08:00.436Z,1633032480.436 [Default:CheckIn:E] Stopped
2021-09-30T20:08:00.436Z,1633032480.436 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-09-30T20:08:00.436Z,1633032480.436 [Default:CheckIn] Stopped
2021-09-30T20:08:00.437Z,1633032480.437 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-09-30T20:08:00.437Z,1633032480.437 [Default:CheckIn](INFO): Running loop #2
2021-09-30T20:08:00.437Z,1633032480.437 [Default:CheckIn] Running Loop=2
2021-09-30T20:08:00.437Z,1633032480.437 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-09-30T20:08:00.437Z,1633032480.437 [Default:CheckIn:Read_GPS] Running Loop=1
2021-09-30T20:08:02.443Z,1633032482.443 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200801.00,A,3648.16620,N,12147.29272,W,0.175,0.00,300921,,,A*7A
2021-09-30T20:08:02.446Z,1633032482.446 [NAL9602](INFO): GPS fix at 20210930T200801: (36.802770, -121.788212)
2021-09-30T20:08:02.489Z,1633032482.489 [Default:CheckIn:Read_GPS] Stopped
2021-09-30T20:08:02.489Z,1633032482.489 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-09-30T20:08:09.619Z,1633032489.619 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20210930T195607/Courier0007.lzma
2021-09-30T20:08:10.622Z,1633032490.622 [DataOverHttps](INFO): Moved sent file to Logs/20210930T195607/Courier0007.lzma.bak
2021-09-30T20:08:10.622Z,1633032490.622 [DataOverHttps](INFO): SBD MOMSN=15951443
2021-09-30T20:08:26.596Z,1633032506.596 [DataOverHttps](INFO): Sending 172 bytes from file Logs/20210930T195607/Express0008.lzma
2021-09-30T20:08:27.598Z,1633032507.598 [DataOverHttps](INFO): Moved sent file to Logs/20210930T195607/Express0008.lzma.bak
2021-09-30T20:08:27.598Z,1633032507.598 [DataOverHttps](INFO): SBD MOMSN=15951446
2021-09-30T20:08:29.985Z,1633032509.985 [Default:CheckIn:Read_Iridium] Stopped
2021-09-30T20:08:29.985Z,1633032509.985 [Default:CheckIn:C.Wait] Running Loop=1
2021-09-30T20:08:29.986Z,1633032509.986 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-09-30T20:08:33.358Z,1633032513.358 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2021-09-30T20:08:33.450Z,1633032513.450 [NAL9602](ERROR): received: 
+CSQ:0

OK57, 2, 0, 0, 0

OK
2021-09-30T20:09:00.774Z,1633032540.774 [NAL9602](INFO): SBD MO Status=2, MOMSN=5757, MT Status=2, MTMSN=0
2021-09-30T20:09:00.775Z,1633032540.775 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-09-30T20:10:32.405Z,1633032632.405 [CommandExec](IMPORTANT): got command failComponent
2021-09-30T20:10:32.405Z,1633032632.405 [CommandExec](IMPORTANT): Failed components:
2021-09-30T20:10:32.405Z,1633032632.405 [CommandExec](IMPORTANT): No failed Components.
2021-09-30T20:13:04.101Z,1633032784.101 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-09-30T20:13:30.470Z,1633032810.470 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-09-30T20:13:30.470Z,1633032810.470 [Default:CheckIn:C.Wait] Stopped
2021-09-30T20:13:30.470Z,1633032810.470 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-09-30T20:13:30.471Z,1633032810.471 [Default:CheckIn:D] Running Loop=1
2021-09-30T20:13:30.851Z,1633032810.851 [Default:CheckIn:D] Stopped
2021-09-30T20:13:30.852Z,1633032810.852 [Default:CheckIn:E] Running Loop=1
2021-09-30T20:13:31.210Z,1633032811.210 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 13.017163 min 
2021-09-30T20:13:31.210Z,1633032811.210 [Default:CheckIn:E] Stopped
2021-09-30T20:13:31.210Z,1633032811.210 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-09-30T20:13:31.210Z,1633032811.210 [Default:CheckIn] Stopped
2021-09-30T20:13:31.210Z,1633032811.210 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-09-30T20:13:31.211Z,1633032811.211 [Default:CheckIn](INFO): Running loop #3
2021-09-30T20:13:31.211Z,1633032811.211 [Default:CheckIn] Running Loop=3
2021-09-30T20:13:31.211Z,1633032811.211 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-09-30T20:13:31.211Z,1633032811.211 [Default:CheckIn:Read_GPS] Running Loop=1
2021-09-30T20:13:33.191Z,1633032813.191 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201332.00,A,3648.16678,N,12147.28389,W,0.194,0.00,300921,,,A*76
2021-09-30T20:13:33.194Z,1633032813.194 [NAL9602](INFO): GPS fix at 20210930T201332: (36.802780, -121.788065)
2021-09-30T20:13:33.204Z,1633032813.204 [Default:CheckIn:Read_GPS] Stopped
2021-09-30T20:13:33.204Z,1633032813.204 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-09-30T20:13:44.459Z,1633032824.459 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210930T195607/Courier0010.lzma
2021-09-30T20:13:45.462Z,1633032825.462 [DataOverHttps](INFO): Moved sent file to Logs/20210930T195607/Courier0010.lzma.bak
2021-09-30T20:13:45.462Z,1633032825.462 [DataOverHttps](INFO): SBD MOMSN=15951449
2021-09-30T20:14:01.356Z,1633032841.356 [DataOverHttps](INFO): Sending 291 bytes from file Logs/20210930T195607/Express0011.lzma
2021-09-30T20:14:02.358Z,1633032842.358 [DataOverHttps](INFO): Moved sent file to Logs/20210930T195607/Express0011.lzma.bak
2021-09-30T20:14:02.358Z,1633032842.358 [DataOverHttps](INFO): SBD MOMSN=15951452
2021-09-30T20:14:04.309Z,1633032844.309 [Default:CheckIn:Read_Iridium] Stopped
2021-09-30T20:14:04.309Z,1633032844.309 [Default:CheckIn:C.Wait] Running Loop=1
2021-09-30T20:14:04.309Z,1633032844.309 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-09-30T20:14:05.502Z,1633032845.502 [NAL9602](INFO): Not Powering down - fast GPS
2021-09-30T20:16:42.830Z,1633033002.830 [CommandExec](IMPORTANT): got command show variable battery
2021-09-30T20:16:42.834Z,1633033002.834 [CommandExec](IMPORTANT): platform_battery_charge (unknown)
2021-09-30T20:16:42.834Z,1633033002.834 [CommandExec](IMPORTANT): platform_battery_charge_usage (unknown)
2021-09-30T20:16:42.835Z,1633033002.835 [CommandExec](IMPORTANT): platform_battery_energy_usage (unknown)
2021-09-30T20:16:42.835Z,1633033002.835 [CommandExec](IMPORTANT): platform_battery_voltage (volt)
2021-09-30T20:16:42.835Z,1633033002.835 [CommandExec](IMPORTANT): platform_battery_fully_charged (unknown)
2021-09-30T20:16:42.836Z,1633033002.836 [CommandExec](IMPORTANT): platform_battery_discharging (unknown)
2021-09-30T20:16:42.940Z,1633033002.940 [CommandExec](IMPORTANT): BPC1.batteryMissingStickThreshold (count)
2021-09-30T20:16:42.941Z,1633033002.941 [CommandExec](IMPORTANT): BPC1.batteryMuxCycleTime (minute)
2021-09-30T20:16:42.941Z,1633033002.941 [CommandExec](IMPORTANT): BPC1.batterySamplingInterval (hour)
2021-09-30T20:16:42.942Z,1633033002.942 [CommandExec](IMPORTANT): BPC1.batteryStickCommsTimeout (hour)
2021-09-30T20:16:42.948Z,1633033002.948 [CommandExec](IMPORTANT): OnboardBattery.mainBatterySysNode (none)
2021-09-30T20:16:42.948Z,1633033002.948 [CommandExec](IMPORTANT): OnboardBattery.backupBatterySysNode (none)
2021-09-30T20:16:42.955Z,1633033002.955 [CommandExec](IMPORTANT): IBIT.batteryCapacityThreshold (ampere_hour)
2021-09-30T20:16:42.956Z,1633033002.956 [CommandExec](IMPORTANT): IBIT.batteryVoltageThreshold (volt)
2021-09-30T20:16:42.957Z,1633033002.957 [CommandExec](IMPORTANT): Config/Battery.stick1 (none)
2021-09-30T20:16:42.957Z,1633033002.957 [CommandExec](IMPORTANT): Config/Battery.stick2 (none)
2021-09-30T20:16:42.957Z,1633033002.957 [CommandExec](IMPORTANT): Config/Battery.stick3 (none)
2021-09-30T20:16:42.958Z,1633033002.958 [CommandExec](IMPORTANT): Config/Battery.stick4 (none)
2021-09-30T20:16:42.958Z,1633033002.958 [CommandExec](IMPORTANT): Config/Battery.stick5 (none)
2021-09-30T20:16:42.959Z,1633033002.959 [CommandExec](IMPORTANT): Config/Battery.stick6 (none)
2021-09-30T20:16:42.959Z,1633033002.959 [CommandExec](IMPORTANT): Config/Battery.stick7 (none)
2021-09-30T20:16:42.960Z,1633033002.960 [CommandExec](IMPORTANT): Config/Battery.stick8 (none)
2021-09-30T20:16:42.960Z,1633033002.960 [CommandExec](IMPORTANT): Config/Battery.stick9 (none)
2021-09-30T20:16:42.960Z,1633033002.960 [CommandExec](IMPORTANT): Config/Battery.stick10 (none)
2021-09-30T20:16:42.961Z,1633033002.961 [CommandExec](IMPORTANT): Config/Battery.stick11 (none)
2021-09-30T20:16:42.961Z,1633033002.961 [CommandExec](IMPORTANT): Config/Battery.stick12 (none)
2021-09-30T20:16:42.961Z,1633033002.961 [CommandExec](IMPORTANT): Config/Battery.stick13 (none)
2021-09-30T20:16:42.962Z,1633033002.962 [CommandExec](IMPORTANT): Config/Battery.stick14 (none)
2021-09-30T20:16:42.962Z,1633033002.962 [CommandExec](IMPORTANT): Config/Battery.stick15 (none)
2021-09-30T20:16:42.963Z,1633033002.963 [CommandExec](IMPORTANT): Config/Battery.stick16 (none)
2021-09-30T20:16:42.963Z,1633033002.963 [CommandExec](IMPORTANT): Config/Battery.stick17 (none)
2021-09-30T20:16:42.963Z,1633033002.963 [CommandExec](IMPORTANT): Config/Battery.stick18 (none)
2021-09-30T20:16:43.008Z,1633033003.008 [CommandExec](IMPORTANT): Config/Battery.stick19 (none)
2021-09-30T20:16:43.008Z,1633033003.008 [CommandExec](IMPORTANT): Config/Battery.stick20 (none)
2021-09-30T20:16:43.009Z,1633033003.009 [CommandExec](IMPORTANT): Config/Battery.stick21 (none)
2021-09-30T20:16:43.009Z,1633033003.009 [CommandExec](IMPORTANT): Config/Battery.stick22 (none)
2021-09-30T20:16:43.009Z,1633033003.009 [CommandExec](IMPORTANT): Config/Battery.stick23 (none)
2021-09-30T20:16:43.010Z,1633033003.010 [CommandExec](IMPORTANT): Config/Battery.stick24 (none)
2021-09-30T20:16:43.010Z,1633033003.010 [CommandExec](IMPORTANT): Config/Battery.stick25 (none)
2021-09-30T20:16:43.010Z,1633033003.010 [CommandExec](IMPORTANT): Config/Battery.stick26 (none)
2021-09-30T20:16:43.011Z,1633033003.011 [CommandExec](IMPORTANT): Config/Battery.stick27 (none)
2021-09-30T20:16:43.011Z,1633033003.011 [CommandExec](IMPORTANT): Config/Battery.stick28 (none)
2021-09-30T20:16:43.012Z,1633033003.012 [CommandExec](IMPORTANT): Config/Battery.stick29 (none)
2021-09-30T20:16:43.012Z,1633033003.012 [CommandExec](IMPORTANT): Config/Battery.stick30 (none)
2021-09-30T20:16:43.012Z,1633033003.012 [CommandExec](IMPORTANT): Config/Battery.stick31 (none)
2021-09-30T20:16:43.013Z,1633033003.013 [CommandExec](IMPORTANT): Config/Battery.stick32 (none)
2021-09-30T20:16:43.013Z,1633033003.013 [CommandExec](IMPORTANT): Config/Battery.stick33 (none)
2021-09-30T20:16:43.014Z,1633033003.014 [CommandExec](IMPORTANT): Config/Battery.stick34 (none)
2021-09-30T20:16:43.014Z,1633033003.014 [CommandExec](IMPORTANT): Config/Battery.stick35 (none)
2021-09-30T20:16:43.014Z,1633033003.014 [CommandExec](IMPORTANT): Config/Battery.stick36 (none)
2021-09-30T20:16:43.015Z,1633033003.015 [CommandExec](IMPORTANT): Config/Battery.stick37 (none)
2021-09-30T20:16:43.015Z,1633033003.015 [CommandExec](IMPORTANT): Config/Battery.stick38 (none)
2021-09-30T20:16:43.015Z,1633033003.015 [CommandExec](IMPORTANT): Config/Battery.stick39 (none)
2021-09-30T20:16:43.030Z,1633033003.030 [CommandExec](IMPORTANT): Config/Battery.stick40 (none)
2021-09-30T20:16:43.030Z,1633033003.030 [CommandExec](IMPORTANT): Config/Battery.stick41 (none)
2021-09-30T20:16:43.031Z,1633033003.031 [CommandExec](IMPORTANT): Config/Battery.stick42 (none)
2021-09-30T20:16:43.031Z,1633033003.031 [CommandExec](IMPORTANT): Config/Battery.stick43 (none)
2021-09-30T20:16:43.032Z,1633033003.032 [CommandExec](IMPORTANT): Config/Battery.stick44 (none)
2021-09-30T20:16:43.032Z,1633033003.032 [CommandExec](IMPORTANT): Config/Battery.stick45 (none)
2021-09-30T20:16:43.032Z,1633033003.032 [CommandExec](IMPORTANT): Config/Battery.stick46 (none)
2021-09-30T20:16:43.033Z,1633033003.033 [CommandExec](IMPORTANT): Config/Battery.stick47 (none)
2021-09-30T20:16:43.033Z,1633033003.033 [CommandExec](IMPORTANT): Config/Battery.stick48 (none)
2021-09-30T20:16:43.034Z,1633033003.034 [CommandExec](IMPORTANT): Config/Battery.stick49 (none)
2021-09-30T20:16:43.034Z,1633033003.034 [CommandExec](IMPORTANT): Config/Battery.stick50 (none)
2021-09-30T20:16:43.034Z,1633033003.034 [CommandExec](IMPORTANT): Config/Battery.stick51 (none)
2021-09-30T20:16:43.035Z,1633033003.035 [CommandExec](IMPORTANT): Config/Battery.stick52 (none)
2021-09-30T20:16:43.035Z,1633033003.035 [CommandExec](IMPORTANT): Config/Battery.stick53 (none)
2021-09-30T20:16:43.035Z,1633033003.035 [CommandExec](IMPORTANT): Config/Battery.stick54 (none)
2021-09-30T20:16:43.059Z,1633033003.059 [CommandExec](IMPORTANT): Config/Battery.stick55 (none)
2021-09-30T20:16:43.059Z,1633033003.059 [CommandExec](IMPORTANT): Config/Battery.stick56 (none)
2021-09-30T20:16:43.059Z,1633033003.059 [CommandExec](IMPORTANT): Config/Battery.stick57 (none)
2021-09-30T20:16:43.060Z,1633033003.060 [CommandExec](IMPORTANT): Config/Battery.stick58 (none)
2021-09-30T20:16:43.060Z,1633033003.060 [CommandExec](IMPORTANT): Config/Battery.stick59 (none)
2021-09-30T20:16:43.061Z,1633033003.061 [CommandExec](IMPORTANT): Config/Battery.stick60 (none)
2021-09-30T20:16:43.061Z,1633033003.061 [CommandExec](IMPORTANT): Config/Battery.stick61 (none)
2021-09-30T20:16:43.061Z,1633033003.061 [CommandExec](IMPORTANT): Config/Battery.stick62 (none)
2021-09-30T20:16:43.091Z,1633033003.091 [CommandExec](IMPORTANT): BPC1.reserve_battery_charge (ampere_hour)
2021-09-30T20:16:43.091Z,1633033003.091 [CommandExec](IMPORTANT): BPC1.reserve_battery_voltage (volt)
2021-09-30T20:16:43.133Z,1633033003.133 [CommandExec](IMPORTANT): BPC1.platform_battery_charge (ampere_hour)
2021-09-30T20:16:43.134Z,1633033003.134 [CommandExec](IMPORTANT): BPC1.platform_battery_voltage (volt)
2021-09-30T20:16:43.263Z,1633033003.263 [CommandExec](IMPORTANT): Onboard.platform_battery_voltage (volt)
2021-09-30T20:16:43.263Z,1633033003.263 [CommandExec](IMPORTANT): Onboard.MainBatteryVoltage (volt)
2021-09-30T20:16:43.264Z,1633033003.264 [CommandExec](IMPORTANT): Onboard.BackupBatteryVoltage (volt)
2021-09-30T20:16:43.264Z,1633033003.264 [CommandExec](IMPORTANT): Onboard.BatteryCurrent (milliampere)
2021-09-30T20:16:54.397Z,1633033014.397 [CommandExec](IMPORTANT): got command get BPC1.platform_battery_charge
2021-09-30T20:16:54.398Z,1633033014.398 [CommandExec](IMPORTANT): BPC1.platform_battery_charge nan Ah
2021-09-30T20:17:01.596Z,1633033021.596 [CommandExec](IMPORTANT): got command failComponent
2021-09-30T20:17:01.597Z,1633033021.597 [CommandExec](IMPORTANT): Failed components:
2021-09-30T20:17:01.597Z,1633033021.597 [CommandExec](IMPORTANT): No failed Components.
2021-09-30T20:17:10.375Z,1633033030.375 [CommandExec](IMPORTANT): got command failComponent hardware BPC1
2021-09-30T20:17:10.375Z,1633033030.375 [BPC1] Hardware Fault, FailCount= 1
2021-09-30T20:17:10.375Z,1633033030.375 [BPC1](ERROR): Hardware Fault
2021-09-30T20:17:10.376Z,1633033030.376 [CommandExec](IMPORTANT): BPC1 failureMode is Hardware Fault
2021-09-30T20:17:10.609Z,1633033030.609 [CBIT](ERROR): Hardware Fault in component: BPC1
2021-09-30T20:17:18.825Z,1633033038.825 [CommandExec](IMPORTANT): got command failComponent
2021-09-30T20:17:18.825Z,1633033038.825 [CommandExec](IMPORTANT): Failed components:
2021-09-30T20:17:18.825Z,1633033038.825 [CommandExec](IMPORTANT): BPC1: Hardware Fault
2021-09-30T20:17:25.722Z,1633033045.722 [CommandExec](IMPORTANT): got command failComponent none BPC1
2021-09-30T20:17:25.722Z,1633033045.722 [BPC1] No Fault, FailCount= 1
2021-09-30T20:17:25.723Z,1633033045.723 [CommandExec](IMPORTANT): BPC1 failureMode is No Fault
2021-09-30T20:18:09.489Z,1633033089.489 [CommandExec](IMPORTANT): got command failComponent
2021-09-30T20:18:09.489Z,1633033089.489 [CommandExec](IMPORTANT): Failed components:
2021-09-30T20:18:09.489Z,1633033089.489 [CommandExec](IMPORTANT): No failed Components.
2021-09-30T20:19:04.962Z,1633033144.962 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-09-30T20:19:04.962Z,1633033144.962 [Default:CheckIn:C.Wait] Stopped
2021-09-30T20:19:04.962Z,1633033144.962 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-09-30T20:19:04.962Z,1633033144.962 [Default:CheckIn:D] Running Loop=1
2021-09-30T20:19:05.453Z,1633033145.453 [Default:CheckIn:D] Stopped
2021-09-30T20:19:05.453Z,1633033145.453 [Default:CheckIn:E] Running Loop=1
2021-09-30T20:19:05.819Z,1633033145.819 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 18.593852 min 
2021-09-30T20:19:05.819Z,1633033145.819 [Default:CheckIn:E] Stopped
2021-09-30T20:19:05.819Z,1633033145.819 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-09-30T20:19:05.819Z,1633033145.819 [Default:CheckIn] Stopped
2021-09-30T20:19:05.819Z,1633033145.819 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-09-30T20:19:05.872Z,1633033145.872 [Default:CheckIn](INFO): Running loop #4
2021-09-30T20:19:05.872Z,1633033145.872 [Default:CheckIn] Running Loop=4
2021-09-30T20:19:05.872Z,1633033145.872 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-09-30T20:19:05.874Z,1633033145.874 [Default:CheckIn:Read_GPS] Running Loop=1
2021-09-30T20:19:07.778Z,1633033147.778 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201907.00,A,3648.16564,N,12147.28359,W,0.194,0.00,300921,,,A*79
2021-09-30T20:19:07.781Z,1633033147.781 [NAL9602](INFO): GPS fix at 20210930T201907: (36.802761, -121.788060)
2021-09-30T20:19:07.800Z,1633033147.800 [Default:CheckIn:Read_GPS] Stopped
2021-09-30T20:19:07.800Z,1633033147.800 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-09-30T20:19:16.396Z,1633033156.396 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20210930T195607/Courier0013.lzma
2021-09-30T20:19:17.398Z,1633033157.398 [DataOverHttps](INFO): Moved sent file to Logs/20210930T195607/Courier0013.lzma.bak
2021-09-30T20:19:17.398Z,1633033157.398 [DataOverHttps](INFO): SBD MOMSN=15951459
2021-09-30T20:19:33.181Z,1633033173.181 [DataOverHttps](INFO): Sending 866 bytes from file Logs/20210930T195607/Express0014.lzma
2021-09-30T20:19:34.182Z,1633033174.182 [DataOverHttps](INFO): Moved sent file to Logs/20210930T195607/Express0014.lzma.bak
2021-09-30T20:19:34.182Z,1633033174.182 [DataOverHttps](INFO): SBD MOMSN=15951462
2021-09-30T20:19:36.105Z,1633033176.105 [Default:CheckIn:Read_Iridium] Stopped
2021-09-30T20:19:36.105Z,1633033176.105 [Default:CheckIn:C.Wait] Running Loop=1
2021-09-30T20:19:36.105Z,1633033176.105 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-09-30T20:19:38.525Z,1633033178.525 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2021-09-30T20:19:38.600Z,1633033178.600 [NAL9602](ERROR): received: 
+CSQ:0

OK57, 2, 0, 0, 0

OK
2021-09-30T20:22:07.805Z,1633033327.805 [CommandExec](IMPORTANT): got command get BPC1.platform_battery_charge
2021-09-30T20:22:07.806Z,1633033327.806 [CommandExec](IMPORTANT): BPC1.platform_battery_charge nan Ah
2021-09-30T20:22:16.250Z,1633033336.250 [CommandExec](IMPORTANT): got command get BPC1.platform_battery_charge
2021-09-30T20:22:16.251Z,1633033336.251 [CommandExec](IMPORTANT): BPC1.platform_battery_charge nan Ah
2021-09-30T20:24:10.465Z,1633033450.465 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-09-30T20:24:36.769Z,1633033476.769 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-09-30T20:24:36.769Z,1633033476.769 [Default:CheckIn:C.Wait] Stopped
2021-09-30T20:24:36.769Z,1633033476.769 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-09-30T20:24:36.769Z,1633033476.769 [Default:CheckIn:D] Running Loop=1
2021-09-30T20:24:37.152Z,1633033477.152 [Default:CheckIn:D] Stopped
2021-09-30T20:24:37.152Z,1633033477.152 [Default:CheckIn:E] Running Loop=1
2021-09-30T20:24:37.553Z,1633033477.553 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 24.122174 min 
2021-09-30T20:24:37.553Z,1633033477.553 [Default:CheckIn:E] Stopped
2021-09-30T20:24:37.554Z,1633033477.554 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-09-30T20:24:37.554Z,1633033477.554 [Default:CheckIn] Stopped
2021-09-30T20:24:37.554Z,1633033477.554 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-09-30T20:24:37.554Z,1633033477.554 [Default:CheckIn](INFO): Running loop #5
2021-09-30T20:24:37.554Z,1633033477.554 [Default:CheckIn] Running Loop=5
2021-09-30T20:24:37.554Z,1633033477.554 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-09-30T20:24:37.554Z,1633033477.554 [Default:CheckIn:Read_GPS] Running Loop=1
2021-09-30T20:24:39.555Z,1633033479.555 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202438.00,A,3648.16596,N,12147.28858,W,0.700,0.00,300921,,,A*77
2021-09-30T20:24:39.557Z,1633033479.557 [NAL9602](INFO): GPS fix at 20210930T202438: (36.802766, -121.788143)
2021-09-30T20:24:39.568Z,1633033479.568 [Default:CheckIn:Read_GPS] Stopped
2021-09-30T20:24:39.568Z,1633033479.568 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-09-30T20:24:47.395Z,1633033487.395 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20210930T195607/Courier0016.lzma
2021-09-30T20:24:48.398Z,1633033488.398 [DataOverHttps](INFO): Moved sent file to Logs/20210930T195607/Courier0016.lzma.bak
2021-09-30T20:24:48.398Z,1633033488.398 [DataOverHttps](INFO): SBD MOMSN=15951565
2021-09-30T20:25:05.136Z,1633033505.136 [DataOverHttps](INFO): Sending 285 bytes from file Logs/20210930T195607/Express0017.lzma
2021-09-30T20:25:06.138Z,1633033506.138 [DataOverHttps](INFO): Moved sent file to Logs/20210930T195607/Express0017.lzma.bak
2021-09-30T20:25:06.138Z,1633033506.138 [DataOverHttps](INFO): SBD MOMSN=15951568
2021-09-30T20:25:08.323Z,1633033508.323 [Default:CheckIn:Read_Iridium] Stopped
2021-09-30T20:25:08.323Z,1633033508.323 [Default:CheckIn:C.Wait] Running Loop=1
2021-09-30T20:25:08.323Z,1633033508.323 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-09-30T20:25:11.509Z,1633033511.509 [NAL9602](INFO): Not Powering down - fast GPS
2021-09-30T20:30:08.965Z,1633033808.965 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-09-30T20:30:08.965Z,1633033808.965 [Default:CheckIn:C.Wait] Stopped
2021-09-30T20:30:08.965Z,1633033808.965 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-09-30T20:30:08.966Z,1633033808.966 [Default:CheckIn:D] Running Loop=1
2021-09-30T20:30:09.380Z,1633033809.380 [Default:CheckIn:D] Stopped
2021-09-30T20:30:09.380Z,1633033809.380 [Default:CheckIn:E] Running Loop=1
2021-09-30T20:30:09.772Z,1633033809.772 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 29.659308 min 
2021-09-30T20:30:09.772Z,1633033809.772 [Default:CheckIn:E] Stopped
2021-09-30T20:30:09.772Z,1633033809.772 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-09-30T20:30:09.772Z,1633033809.772 [Default:CheckIn] Stopped
2021-09-30T20:30:09.772Z,1633033809.772 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-09-30T20:30:09.773Z,1633033809.773 [Default:CheckIn](INFO): Running loop #6
2021-09-30T20:30:09.773Z,1633033809.773 [Default:CheckIn] Running Loop=6
2021-09-30T20:30:09.773Z,1633033809.773 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-09-30T20:30:09.773Z,1633033809.773 [Default:CheckIn:Read_GPS] Running Loop=1
2021-09-30T20:30:11.787Z,1633033811.787 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203011.00,A,3648.16208,N,12147.28049,W,0.311,7.16,300921,,,A*75
2021-09-30T20:30:11.789Z,1633033811.789 [NAL9602](INFO): GPS fix at 20210930T203011: (36.802701, -121.788008)
2021-09-30T20:30:11.800Z,1633033811.800 [Default:CheckIn:Read_GPS] Stopped
2021-09-30T20:30:11.800Z,1633033811.800 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-09-30T20:30:18.879Z,1633033818.879 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20210930T195607/Courier0019.lzma
2021-09-30T20:30:19.882Z,1633033819.882 [DataOverHttps](INFO): Moved sent file to Logs/20210930T195607/Courier0019.lzma.bak
2021-09-30T20:30:19.882Z,1633033819.882 [DataOverHttps](INFO): SBD MOMSN=15951576
2021-09-30T20:30:39.648Z,1633033839.648 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20210930T195607/Express0020.lzma
2021-09-30T20:30:40.651Z,1633033840.651 [DataOverHttps](INFO): Moved sent file to Logs/20210930T195607/Express0020.lzma.bak
2021-09-30T20:30:40.651Z,1633033840.651 [DataOverHttps](INFO): SBD MOMSN=15951579
2021-09-30T20:30:42.553Z,1633033842.553 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2021-09-30T20:30:42.628Z,1633033842.628 [NAL9602](ERROR): received: 
+CSQ:0

OK57, 2, 0, 0, 0

OK
2021-09-30T20:30:43.017Z,1633033843.017 [Default:CheckIn:Read_Iridium] Stopped
2021-09-30T20:30:43.017Z,1633033843.017 [Default:CheckIn:C.Wait] Running Loop=1
2021-09-30T20:30:43.017Z,1633033843.017 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-09-30T20:35:00.751Z,1633034100.751 [NAL9602](INFO): SBD MO Status=2, MOMSN=5757, MT Status=2, MTMSN=0
2021-09-30T20:35:00.751Z,1633034100.751 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-09-30T20:35:14.490Z,1633034114.490 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-09-30T20:35:43.587Z,1633034143.587 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-09-30T20:35:43.587Z,1633034143.587 [Default:CheckIn:C.Wait] Stopped
2021-09-30T20:35:43.587Z,1633034143.587 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-09-30T20:35:43.587Z,1633034143.587 [Default:CheckIn:D] Running Loop=1
2021-09-30T20:35:43.991Z,1633034143.991 [Default:CheckIn:D] Stopped
2021-09-30T20:35:43.991Z,1633034143.991 [Default:CheckIn:E] Running Loop=1
2021-09-30T20:35:44.404Z,1633034144.404 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 35.236153 min 
2021-09-30T20:35:44.404Z,1633034144.404 [Default:CheckIn:E] Stopped
2021-09-30T20:35:44.404Z,1633034144.404 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-09-30T20:35:44.404Z,1633034144.404 [Default:CheckIn] Stopped
2021-09-30T20:35:44.404Z,1633034144.404 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-09-30T20:35:44.404Z,1633034144.404 [Default:CheckIn](INFO): Running loop #7
2021-09-30T20:35:44.405Z,1633034144.405 [Default:CheckIn] Running Loop=7
2021-09-30T20:35:44.405Z,1633034144.405 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-09-30T20:35:44.405Z,1633034144.405 [Default:CheckIn:Read_GPS] Running Loop=1
2021-09-30T20:35:46.416Z,1633034146.416 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203545.00,A,3648.16531,N,12147.28317,W,0.311,7.16,300921,,,A*74
2021-09-30T20:35:46.419Z,1633034146.419 [NAL9602](INFO): GPS fix at 20210930T203545: (36.802755, -121.788053)
2021-09-30T20:35:46.430Z,1633034146.430 [Default:CheckIn:Read_GPS] Stopped
2021-09-30T20:35:46.431Z,1633034146.431 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-09-30T20:35:53.771Z,1633034153.771 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20210930T195607/Courier0022.lzma
2021-09-30T20:35:54.770Z,1633034154.770 [DataOverHttps](INFO): Moved sent file to Logs/20210930T195607/Courier0022.lzma.bak
2021-09-30T20:35:54.770Z,1633034154.770 [DataOverHttps](INFO): SBD MOMSN=15951582
2021-09-30T20:36:10.752Z,1633034170.752 [DataOverHttps](INFO): Sending 217 bytes from file Logs/20210930T195607/Express0023.lzma
2021-09-30T20:36:11.754Z,1633034171.754 [DataOverHttps](INFO): Moved sent file to Logs/20210930T195607/Express0023.lzma.bak
2021-09-30T20:36:11.754Z,1633034171.754 [DataOverHttps](INFO): SBD MOMSN=15951585
2021-09-30T20:36:13.487Z,1633034173.487 [Default:CheckIn:Read_Iridium] Stopped
2021-09-30T20:36:13.487Z,1633034173.487 [Default:CheckIn:C.Wait] Running Loop=1
2021-09-30T20:36:13.487Z,1633034173.487 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-09-30T20:36:18.329Z,1633034178.329 [NAL9602](INFO): Not Powering down - fast GPS
2021-09-30T20:37:02.069Z,1633034222.069 [CommandExec](IMPORTANT): got command show variable Mux
2021-09-30T20:37:02.119Z,1633034222.119 [CommandExec](IMPORTANT): BPC1.batteryMuxCycleTime (minute)
2021-09-30T20:37:10.772Z,1633034230.772 [CommandExec](IMPORTANT): got command get BPC1.batteryMuxCycleTime
2021-09-30T20:37:10.773Z,1633034230.773 [CommandExec](IMPORTANT): BPC1.batteryMuxCycleTime 10.000000 min
2021-09-30T20:37:19.796Z,1633034239.796 [CommandExec](IMPORTANT): got command failComponent
2021-09-30T20:37:19.797Z,1633034239.797 [CommandExec](IMPORTANT): Failed components:
2021-09-30T20:37:19.797Z,1633034239.797 [CommandExec](IMPORTANT): No failed Components.
2021-09-30T20:37:24.588Z,1633034244.588 [CommandExec](IMPORTANT): got command failComponent
2021-09-30T20:37:24.589Z,1633034244.589 [CommandExec](IMPORTANT): Failed components:
2021-09-30T20:37:24.589Z,1633034244.589 [CommandExec](IMPORTANT): No failed Components.
2021-09-30T20:39:00.285Z,1633034340.285 [CommandExec](IMPORTANT): got command configSet list
2021-09-30T20:39:00.285Z,1633034340.285 [CommandExec](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2021-09-30T20:39:00.286Z,1633034340.286 [CommandExec](IMPORTANT): AHRS_M2.loadAtStartup=1 bool;

2021-09-30T20:39:00.286Z,1633034340.286 [CommandExec](IMPORTANT): BPC1.batteryMissingStickThreshold=8 count;

2021-09-30T20:39:00.286Z,1633034340.286 [CommandExec](IMPORTANT): BPC1.batterySamplingInterval=1 minute;

2021-09-30T20:39:00.287Z,1633034340.287 [CommandExec](IMPORTANT): BPC1.batteryStickCommsTimeout=10 second;

2021-09-30T20:39:00.287Z,1633034340.287 [CommandExec](IMPORTANT): BackseatComponent.loadAtStartup=1 bool;

2021-09-30T20:39:00.287Z,1633034340.287 [CommandExec](IMPORTANT): CBIT.gf24Offset=-18.106 microampere;

2021-09-30T20:39:00.287Z,1633034340.287 [CommandExec](IMPORTANT): CBIT.stopDepth=295 meter;

2021-09-30T20:39:00.287Z,1633034340.287 [CommandExec](IMPORTANT): DAT.loadAtStartup=0 bool;

2021-09-30T20:39:00.287Z,1633034340.287 [CommandExec](IMPORTANT): ESPComponent.loadAtStartup=1 bool;

2021-09-30T20:39:00.287Z,1633034340.287 [CommandExec](IMPORTANT): ESPComponent.simulateHardware=1 bool;

2021-09-30T20:39:00.287Z,1633034340.287 [CommandExec](IMPORTANT): Express none WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water;

2021-09-30T20:39:00.288Z,1633034340.288 [CommandExec](IMPORTANT): Express linearApproximation platform_pitch_angle 5.000000 degree;

2021-09-30T20:39:00.288Z,1633034340.288 [CommandExec](IMPORTANT): Express none platform_roll_angle;

2021-09-30T20:39:00.288Z,1633034340.288 [CommandExec](IMPORTANT): VerticalControl.buoyancyNeutral=242.233074 cubic_centimeter;

2021-09-30T20:39:00.288Z,1633034340.288 [CommandExec](IMPORTANT): VerticalControl.massDefault=13.940048 millimeter;

2021-09-30T20:41:14.113Z,1633034474.113 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-09-30T20:41:14.113Z,1633034474.113 [Default:CheckIn:C.Wait] Stopped
2021-09-30T20:41:14.113Z,1633034474.113 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-09-30T20:41:14.114Z,1633034474.114 [Default:CheckIn:D] Running Loop=1
2021-09-30T20:41:14.503Z,1633034474.503 [Default:CheckIn:D] Stopped
2021-09-30T20:41:14.503Z,1633034474.503 [Default:CheckIn:E] Running Loop=1
2021-09-30T20:41:14.907Z,1633034474.907 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 40.744694 min 
2021-09-30T20:41:14.908Z,1633034474.908 [Default:CheckIn:E] Stopped
2021-09-30T20:41:14.908Z,1633034474.908 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-09-30T20:41:14.908Z,1633034474.908 [Default:CheckIn] Stopped
2021-09-30T20:41:14.908Z,1633034474.908 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-09-30T20:41:14.908Z,1633034474.908 [Default:CheckIn](INFO): Running loop #8
2021-09-30T20:41:14.908Z,1633034474.908 [Default:CheckIn] Running Loop=8
2021-09-30T20:41:14.909Z,1633034474.909 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-09-30T20:41:14.909Z,1633034474.909 [Default:CheckIn:Read_GPS] Running Loop=1
2021-09-30T20:41:16.939Z,1633034476.939 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204116.00,A,3648.17071,N,12147.28692,W,0.603,7.16,300921,,,A*7F
2021-09-30T20:41:16.941Z,1633034476.941 [NAL9602](INFO): GPS fix at 20210930T204116: (36.802845, -121.788115)
2021-09-30T20:41:16.952Z,1633034476.952 [Default:CheckIn:Read_GPS] Stopped
2021-09-30T20:41:16.953Z,1633034476.953 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-09-30T20:41:24.267Z,1633034484.267 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210930T195607/Courier0025.lzma
2021-09-30T20:41:25.270Z,1633034485.270 [DataOverHttps](INFO): Moved sent file to Logs/20210930T195607/Courier0025.lzma.bak
2021-09-30T20:41:25.270Z,1633034485.270 [DataOverHttps](INFO): SBD MOMSN=15951589
2021-09-30T20:41:28.713Z,1633034488.713 [CommandExec](IMPORTANT): got command failComponent
2021-09-30T20:41:28.713Z,1633034488.713 [CommandExec](IMPORTANT): Failed components:
2021-09-30T20:41:28.713Z,1633034488.713 [CommandExec](IMPORTANT): No failed Components.
2021-09-30T20:41:47.385Z,1633034507.385 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2021-09-30T20:41:47.464Z,1633034507.464 [NAL9602](ERROR): received: 
+CSQ:0

OK57, 2, 0, 0, 0

OK
2021-09-30T20:41:50.038Z,1633034510.038 [CommandExec](IMPORTANT): got command get BPC1.platform_battery_voltage
2021-09-30T20:41:50.039Z,1633034510.039 [CommandExec](IMPORTANT): BPC1.platform_battery_voltage nan V
2021-09-30T20:41:57.342Z,1633034517.342 [DataOverHttps](INFO): Sending 733 bytes from file Logs/20210930T195607/Express0026.lzma
2021-09-30T20:41:58.342Z,1633034518.342 [DataOverHttps](INFO): Moved sent file to Logs/20210930T195607/Express0026.lzma.bak
2021-09-30T20:41:58.342Z,1633034518.342 [DataOverHttps](INFO): SBD MOMSN=15951592
2021-09-30T20:42:01.206Z,1633034521.206 [CommandExec](IMPORTANT): got command get depth
2021-09-30T20:42:01.207Z,1633034521.207 [CommandExec](IMPORTANT): depth -0.089385 m
2021-09-30T20:42:01.982Z,1633034521.982 [Default:CheckIn:Read_Iridium] Stopped
2021-09-30T20:42:01.982Z,1633034521.982 [Default:CheckIn:C.Wait] Running Loop=1
2021-09-30T20:42:01.982Z,1633034521.982 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-09-30T20:42:12.186Z,1633034532.186 [CommandExec](IMPORTANT): got command get depth
2021-09-30T20:42:12.187Z,1633034532.187 [CommandExec](IMPORTANT): depth -0.110353 m
2021-09-30T20:46:19.368Z,1633034779.368 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-09-30T20:46:50.141Z,1633034810.141 [NAL9602](INFO): Not Powering down - fast GPS
2021-09-30T20:47:02.676Z,1633034822.676 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-09-30T20:47:02.676Z,1633034822.676 [Default:CheckIn:C.Wait] Stopped
2021-09-30T20:47:02.676Z,1633034822.676 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-09-30T20:47:02.676Z,1633034822.676 [Default:CheckIn:D] Running Loop=1
2021-09-30T20:47:03.082Z,1633034823.082 [Default:CheckIn:D] Stopped
2021-09-30T20:47:03.082Z,1633034823.082 [Default:CheckIn:E] Running Loop=1
2021-09-30T20:47:03.502Z,1633034823.502 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 46.554342 min 
2021-09-30T20:47:03.502Z,1633034823.502 [Default:CheckIn:E] Stopped
2021-09-30T20:47:03.502Z,1633034823.502 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-09-30T20:47:03.502Z,1633034823.502 [Default:CheckIn] Stopped
2021-09-30T20:47:03.502Z,1633034823.502 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-09-30T20:47:03.503Z,1633034823.503 [Default:CheckIn](INFO): Running loop #9
2021-09-30T20:47:03.503Z,1633034823.503 [Default:CheckIn] Running Loop=9
2021-09-30T20:47:03.503Z,1633034823.503 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-09-30T20:47:03.503Z,1633034823.503 [Default:CheckIn:Read_GPS] Running Loop=1
2021-09-30T20:47:05.493Z,1633034825.493 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204704.00,A,3648.16786,N,12147.28407,W,0.467,0.00,300921,,,A*7A
2021-09-30T20:47:05.495Z,1633034825.495 [NAL9602](INFO): GPS fix at 20210930T204704: (36.802798, -121.788068)
2021-09-30T20:47:05.515Z,1633034825.515 [Default:CheckIn:Read_GPS] Stopped
2021-09-30T20:47:05.515Z,1633034825.515 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-09-30T20:47:14.895Z,1633034834.895 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210930T195607/Courier0028.lzma
2021-09-30T20:47:15.898Z,1633034835.898 [DataOverHttps](INFO): Moved sent file to Logs/20210930T195607/Courier0028.lzma.bak
2021-09-30T20:47:15.898Z,1633034835.898 [DataOverHttps](INFO): SBD MOMSN=15951622
2021-09-30T20:47:31.816Z,1633034851.816 [DataOverHttps](INFO): Sending 354 bytes from file Logs/20210930T195607/Express0029.lzma
2021-09-30T20:47:32.818Z,1633034852.818 [DataOverHttps](INFO): Moved sent file to Logs/20210930T195607/Express0029.lzma.bak
2021-09-30T20:47:32.818Z,1633034852.818 [DataOverHttps](INFO): SBD MOMSN=15951625
2021-09-30T20:47:34.638Z,1633034854.638 [Default:CheckIn:Read_Iridium] Stopped
2021-09-30T20:47:34.638Z,1633034854.638 [Default:CheckIn:C.Wait] Running Loop=1
2021-09-30T20:47:34.638Z,1633034854.638 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-09-30T20:47:36.241Z,1633034856.241 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2021-09-30T20:47:36.320Z,1633034856.320 [NAL9602](ERROR): received: 
+CSQ:0

OK57, 2, 0, 0, 0

OK
2021-09-30T20:47:50.475Z,1633034870.475 [CommandExec](IMPORTANT): got command restart application
2021-09-30T20:47:51.480Z,1633034871.480 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2021-09-30T20:47:51.480Z,1633034871.480 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2021-09-30T20:47:51.480Z,1633034871.480 [CommandExec](INFO): Uninitializing the command executive.
2021-09-30T20:47:51.481Z,1633034871.481 [CommandExec](INFO): Uninitializing the command scheduler.
2021-09-30T20:47:51.481Z,1633034871.481 [CommandExec ThreadHandler](INFO): Thread cancelled.
2021-09-30T20:47:51.668Z,1633034871.668 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2021-09-30T20:47:51.669Z,1633034871.669 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2021-09-30T20:47:51.670Z,1633034871.670 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-09-30T20:47:51.671Z,1633034871.671 [NavChartDb](INFO): Join timeout helper Thread ID is 2701
2021-09-30T20:47:51.716Z,1633034871.716 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2021-09-30T20:47:51.717Z,1633034871.717 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-09-30T20:47:51.733Z,1633034871.733 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2021-09-30T20:47:51.733Z,1633034871.733 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2021-09-30T20:47:51.733Z,1633034871.733 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 2702
2021-09-30T20:47:52.144Z,1633034872.144 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2021-09-30T20:47:52.144Z,1633034872.144 [WetLabsBB2FL](INFO): Powering down
2021-09-30T20:47:52.145Z,1633034872.145 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2021-09-30T20:47:52.160Z,1633034872.160 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2021-09-30T20:47:52.160Z,1633034872.160 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-09-30T20:47:52.160Z,1633034872.160 [CTD_Seabird](INFO): Join timeout helper Thread ID is 2703
2021-09-30T20:47:52.512Z,1633034872.512 [CTD_Seabird](INFO): Powering down
2021-09-30T20:47:52.524Z,1633034872.524 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2021-09-30T20:47:52.524Z,1633034872.524 [CTD_Seabird](INFO): Powering down
2021-09-30T20:47:52.536Z,1633034872.536 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-09-30T20:47:52.541Z,1633034872.541 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2021-09-30T20:47:52.542Z,1633034872.542 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-09-30T20:47:52.542Z,1633034872.542 [Radio_Surface](INFO): Join timeout helper Thread ID is 2704
2021-09-30T20:47:52.744Z,1633034872.744 [Radio_Surface](INFO): Powering down
2021-09-30T20:47:52.745Z,1633034872.745 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2021-09-30T20:47:52.745Z,1633034872.745 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-09-30T20:47:52.764Z,1633034872.764 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2021-09-30T20:47:52.764Z,1633034872.764 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-09-30T20:47:52.764Z,1633034872.764 [Onboard](INFO): Join timeout helper Thread ID is 2705
2021-09-30T20:47:53.345Z,1633034873.345 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2021-09-30T20:47:56.588Z,1633034876.588 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2021-09-30T20:47:56.588Z,1633034876.588 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-09-30T20:47:56.593Z,1633034876.593 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2021-09-30T20:47:56.593Z,1633034876.593 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-09-30T20:47:56.593Z,1633034876.593 [DataOverHttps](INFO): Join timeout helper Thread ID is 2706
2021-09-30T20:47:57.360Z,1633034877.360 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2021-09-30T20:47:57.360Z,1633034877.360 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-09-30T20:47:57.365Z,1633034877.365 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2021-09-30T20:47:57.365Z,1633034877.365 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2021-09-30T20:47:57.365Z,1633034877.365 [BackseatComponent](INFO): Join timeout helper Thread ID is 2707
2021-09-30T20:47:57.540Z,1633034877.540 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2021-09-30T20:47:57.540Z,1633034877.540 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2021-09-30T20:47:57.549Z,1633034877.549 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2021-09-30T20:47:57.549Z,1633034877.549 [logger ThreadHandler](INFO): Thread cancelled.
2021-09-30T20:47:57.549Z,1633034877.549 [logger](INFO): Join timeout helper Thread ID is 2708
2021-09-30T20:47:57.552Z,1633034877.552 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2021-09-30T20:47:57.552Z,1633034877.552 [logger ThreadHandler](INFO): Thread cancelled.
2021-09-30T20:47:57.568Z,1633034877.568 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2021-09-30T20:47:57.569Z,1633034877.569 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-09-30T20:47:57.569Z,1633034877.569 [CommandLine](INFO): Join timeout helper Thread ID is 2709
2021-09-30T20:47:57.652Z,1633034877.652 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2021-09-30T20:47:57.652Z,1633034877.652 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-09-30T20:47:57.654Z,1633034877.654 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2021-09-30T20:47:57.654Z,1633034877.654 [CommandExec ThreadHandler](INFO): Thread cancelled.
2021-09-30T20:47:57.654Z,1633034877.654 [CommandExec](INFO): Join timeout helper Thread ID is 2710
2021-09-30T20:47:57.657Z,1633034877.657 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2021-09-30T20:47:57.657Z,1633034877.657 [controlThread ThreadHandler](INFO): Thread cancelled.
2021-09-30T20:47:57.657Z,1633034877.657 [controlThread](INFO): Join timeout helper Thread ID is 2711
2021-09-30T20:47:57.680Z,1633034877.680 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2021-09-30T20:47:57.681Z,1633034877.681 [controlThread](DEBUG): Uninitializing ControlThread
2021-09-30T20:47:57.681Z,1633034877.681 [AHRS_M2](INFO): Powering down
2021-09-30T20:47:57.753Z,1633034877.753 [NAL9602](INFO): Powering down
2021-09-30T20:47:57.755Z,1633034877.755 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2021-09-30T20:47:57.756Z,1633034877.756 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2021-09-30T20:47:57.757Z,1633034877.757 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2021-09-30T20:47:57.757Z,1633034877.757 [MissionManager](INFO): Uninitializing Mission Default
2021-09-30T20:47:57.757Z,1633034877.757 [Default] Stopped
2021-09-30T20:47:57.757Z,1633034877.757 [Default](DEBUG): Aggregate::uninitialize Default
2021-09-30T20:47:57.757Z,1633034877.757 [Default:B.GoToSurface] Stopped
2021-09-30T20:47:57.758Z,1633034877.758 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-09-30T20:47:57.758Z,1633034877.758 [Default:CheckIn] Stopped
2021-09-30T20:47:57.758Z,1633034877.758 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-09-30T20:47:57.758Z,1633034877.758 [Default:CheckIn:C.Wait] Stopped
2021-09-30T20:47:57.758Z,1633034877.758 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-09-30T20:47:57.761Z,1633034877.761 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2021-09-30T20:47:57.761Z,1633034877.761 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2021-09-30T20:47:57.762Z,1633034877.762 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2021-09-30T20:47:57.762Z,1633034877.762 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2021-09-30T20:47:57.762Z,1633034877.762 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2021-09-30T20:47:57.762Z,1633034877.762 [BuoyancyServo](INFO): Powering down
2021-09-30T20:47:57.776Z,1633034877.776 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2021-09-30T20:47:57.776Z,1633034877.776 [ElevatorServo](INFO): Powering down
2021-09-30T20:47:57.777Z,1633034877.777 [MassServo](DEBUG): Uninitialize Mass Servo.
2021-09-30T20:47:57.777Z,1633034877.777 [MassServo](INFO): Powering down
2021-09-30T20:47:57.778Z,1633034877.778 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2021-09-30T20:47:57.778Z,1633034877.778 [RudderServo](INFO): Powering down
2021-09-30T20:47:57.779Z,1633034877.779 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2021-09-30T20:47:57.779Z,1633034877.779 [ThrusterHE](INFO): Powering down
2021-09-30T20:47:57.780Z,1633034877.780 [SBIT](DEBUG): Uninitialize SBIT Component.
2021-09-30T20:47:57.780Z,1633034877.780 [IBIT](DEBUG): Uninitialize IBIT Component.
2021-09-30T20:47:57.780Z,1633034877.780 [CBIT](DEBUG): Uninitialize CBIT Component.
2021-09-30T20:47:57.781Z,1633034877.781 [CBIT](DEBUG): Powering off loads.
2021-09-30T20:47:57.792Z,1633034877.792 [CBIT](DEBUG): Disabling WDT.
2021-09-30T20:47:57.804Z,1633034877.804 [CBIT](DEBUG): Opening all GF detection circuits.
2021-09-30T20:47:57.805Z,1633034877.805 [controlThread ThreadHandler](INFO): Thread cancelled.
2021-09-30T20:47:57.874Z,1633034877.874 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-09-30T20:47:57.878Z,1633034877.878 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-09-30T20:47:57.884Z,1633034877.884 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-09-30T20:47:57.929Z,1633034877.929 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2021-09-30T20:47:57.969Z,1633034877.969 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2021-09-30T20:47:57.974Z,1633034877.974 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-09-30T20:47:58.011Z,1633034878.011 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-09-30T20:47:58.086Z,1633034878.086 [logger ThreadHandler](INFO): Thread cancelled.