2022-12-20T18:58:23.460Z,1671562703.460 [Supervisor](DEBUG): Initializing supervisor.
2022-12-20T18:58:23.464Z,1671562703.464 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2022-12-20T18:58:23.465Z,1671562703.465 [SyncHandler](INFO): Protected caller Thread ID is 835
2022-12-20T18:58:23.465Z,1671562703.465 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2022-12-20T18:58:23.466Z,1671562703.466 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2022-12-20T18:58:23.466Z,1671562703.466 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 836
2022-12-20T18:58:23.471Z,1671562703.471 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2022-12-20T18:58:23.489Z,1671562703.489 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2022-12-20T18:58:23.490Z,1671562703.490 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2022-12-20T18:58:23.491Z,1671562703.491 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 837
2022-12-20T18:58:23.495Z,1671562703.495 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2022-12-20T18:58:23.496Z,1671562703.496 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2022-12-20T18:58:23.496Z,1671562703.496 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 838
2022-12-20T18:58:23.499Z,1671562703.499 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2022-12-20T18:58:23.500Z,1671562703.500 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2022-12-20T18:58:23.500Z,1671562703.500 [logger ThreadHandler](INFO): Protected caller Thread ID is 839
2022-12-20T18:58:23.504Z,1671562703.504 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2022-12-20T18:58:23.504Z,1671562703.504 [Supervisor](INFO): Looking for Config files in directory: Config/
2022-12-20T18:58:23.508Z,1671562703.508 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2022-12-20T18:58:24.014Z,1671562704.014 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2022-12-20T18:58:24.016Z,1671562704.016 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2022-12-20T18:58:24.238Z,1671562704.238 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2022-12-20T18:58:24.240Z,1671562704.240 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2022-12-20T18:58:24.323Z,1671562704.323 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2022-12-20T18:58:24.563Z,1671562704.563 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2022-12-20T18:58:24.565Z,1671562704.565 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2022-12-20T18:58:24.646Z,1671562704.646 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2022-12-20T18:58:24.744Z,1671562704.744 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2022-12-20T18:58:24.746Z,1671562704.746 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2022-12-20T18:58:25.120Z,1671562705.120 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2022-12-20T18:58:25.122Z,1671562705.122 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2022-12-20T18:58:25.258Z,1671562705.258 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2022-12-20T18:58:25.260Z,1671562705.260 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2022-12-20T18:58:25.788Z,1671562705.788 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2022-12-20T18:58:25.790Z,1671562705.790 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2022-12-20T18:58:25.996Z,1671562705.996 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2022-12-20T18:58:25.998Z,1671562705.998 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2022-12-20T18:58:26.435Z,1671562706.435 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2022-12-20T18:58:26.436Z,1671562706.436 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2022-12-20T18:58:26.736Z,1671562706.736 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2022-12-20T18:58:26.738Z,1671562706.738 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2022-12-20T18:58:26.855Z,1671562706.855 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2022-12-20T18:58:26.968Z,1671562706.968 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2022-12-20T18:58:28.287Z,1671562708.287 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2022-12-20T18:58:28.288Z,1671562708.288 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2022-12-20T18:58:28.649Z,1671562708.649 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2022-12-20T18:58:28.651Z,1671562708.651 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2022-12-20T18:58:28.884Z,1671562708.884 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2022-12-20T18:58:28.886Z,1671562708.886 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/
2022-12-20T18:58:28.889Z,1671562708.889 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/vehicle.cfg
2022-12-20T18:58:29.090Z,1671562709.090 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/secure.cfg
2022-12-20T18:58:29.175Z,1671562709.175 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Science.cfg
2022-12-20T18:58:29.320Z,1671562709.320 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Simulator.cfg
2022-12-20T18:58:29.408Z,1671562709.408 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Battery.cfg
2022-12-20T18:58:29.678Z,1671562709.678 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2022-12-20T18:58:29.678Z,1671562709.678 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/logger.cfg
2022-12-20T18:58:29.787Z,1671562709.787 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Servo.cfg
2022-12-20T18:58:29.904Z,1671562709.904 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Navigation.cfg
2022-12-20T18:58:30.021Z,1671562710.021 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Sensor.cfg
2022-12-20T18:58:30.173Z,1671562710.173 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Control.cfg
2022-12-20T18:58:30.276Z,1671562710.276 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/BIT.cfg
2022-12-20T18:58:30.372Z,1671562710.372 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2022-12-20T18:58:30.388Z,1671562710.388 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2022-12-20T18:58:30.404Z,1671562710.404 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2022-12-20T18:58:30.405Z,1671562710.405 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2022-12-20T18:58:30.532Z,1671562710.532 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2022-12-20T18:58:30.534Z,1671562710.534 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2022-12-20T18:58:30.602Z,1671562710.602 [VerticalControl](DEBUG): Construct VerticalControl.
2022-12-20T18:58:30.664Z,1671562710.664 [VerticalControl] Loaded
2022-12-20T18:58:30.664Z,1671562710.664 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2022-12-20T18:58:30.667Z,1671562710.667 [HorizontalControl](DEBUG): Construct HorizontalControl.
2022-12-20T18:58:30.709Z,1671562710.709 [HorizontalControl] Loaded
2022-12-20T18:58:30.709Z,1671562710.709 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2022-12-20T18:58:30.711Z,1671562710.711 [SpeedControl](DEBUG): Construct SpeedControl.
2022-12-20T18:58:30.714Z,1671562710.714 [SpeedControl] Loaded
2022-12-20T18:58:30.715Z,1671562710.715 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2022-12-20T18:58:30.717Z,1671562710.717 [LoopControl](DEBUG): Construct LoopControl.
2022-12-20T18:58:30.718Z,1671562710.718 [LoopControl] Loaded
2022-12-20T18:58:30.718Z,1671562710.718 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2022-12-20T18:58:30.719Z,1671562710.719 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2022-12-20T18:58:30.719Z,1671562710.719 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2022-12-20T18:58:30.903Z,1671562710.903 [BuoyancyServo] Loaded
2022-12-20T18:58:30.904Z,1671562710.904 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2022-12-20T18:58:30.924Z,1671562710.924 [ElevatorServo] Loaded
2022-12-20T18:58:30.924Z,1671562710.924 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2022-12-20T18:58:30.944Z,1671562710.944 [MassServo] Loaded
2022-12-20T18:58:30.944Z,1671562710.944 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2022-12-20T18:58:30.962Z,1671562710.962 [RudderServo] Loaded
2022-12-20T18:58:30.963Z,1671562710.963 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2022-12-20T18:58:30.977Z,1671562710.977 [ThrusterHE] Loaded
2022-12-20T18:58:30.978Z,1671562710.978 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2022-12-20T18:58:30.978Z,1671562710.978 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2022-12-20T18:58:30.979Z,1671562710.979 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2022-12-20T18:58:31.050Z,1671562711.050 [DepthRateCalculator] Loaded
2022-12-20T18:58:31.050Z,1671562711.050 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2022-12-20T18:58:31.055Z,1671562711.055 [PitchRateCalculator] Loaded
2022-12-20T18:58:31.055Z,1671562711.055 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2022-12-20T18:58:31.065Z,1671562711.065 [SpeedCalculator] Loaded
2022-12-20T18:58:31.065Z,1671562711.065 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2022-12-20T18:58:31.070Z,1671562711.070 [YawRateCalculator] Loaded
2022-12-20T18:58:31.070Z,1671562711.070 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2022-12-20T18:58:31.089Z,1671562711.089 [ElevatorOffsetCalculator] Loaded
2022-12-20T18:58:31.089Z,1671562711.089 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2022-12-20T18:58:31.089Z,1671562711.089 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2022-12-20T18:58:31.090Z,1671562711.090 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2022-12-20T18:58:31.230Z,1671562711.230 [DeadReckonUsingMultipleVelocitySources] Loaded
2022-12-20T18:58:31.231Z,1671562711.231 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2022-12-20T18:58:31.245Z,1671562711.245 [NavChart] Loaded
2022-12-20T18:58:31.245Z,1671562711.245 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2022-12-20T18:58:31.251Z,1671562711.251 [UniversalFixResidualReporter] Loaded
2022-12-20T18:58:31.251Z,1671562711.251 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2022-12-20T18:58:31.251Z,1671562711.251 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2022-12-20T18:58:31.252Z,1671562711.252 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2022-12-20T18:58:31.967Z,1671562711.967 [AHRS_M2] Loaded
2022-12-20T18:58:31.967Z,1671562711.967 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2022-12-20T18:58:32.216Z,1671562712.216 [BackseatComponent] Loaded
2022-12-20T18:58:32.217Z,1671562712.217 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2022-12-20T18:58:32.218Z,1671562712.218 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408D14E0
2022-12-20T18:58:32.218Z,1671562712.218 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 921
2022-12-20T18:58:32.221Z,1671562712.221 [LcmUniversalReporter] Loaded
2022-12-20T18:58:32.221Z,1671562712.221 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2022-12-20T18:58:33.497Z,1671562713.497 [BPC1] Loaded
2022-12-20T18:58:33.498Z,1671562713.498 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2022-12-20T18:58:33.639Z,1671562713.639 [DataOverHttps] Loaded
2022-12-20T18:58:33.639Z,1671562713.639 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2022-12-20T18:58:33.640Z,1671562713.640 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409014E0
2022-12-20T18:58:33.641Z,1671562713.641 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 922
2022-12-20T18:58:33.662Z,1671562713.662 [Depth_Keller] Loaded
2022-12-20T18:58:33.662Z,1671562713.662 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2022-12-20T18:58:33.667Z,1671562713.667 [DropWeight] Loaded
2022-12-20T18:58:33.667Z,1671562713.667 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2022-12-20T18:58:33.730Z,1671562713.730 [NAL9602] Loaded
2022-12-20T18:58:33.731Z,1671562713.731 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2022-12-20T18:58:33.761Z,1671562713.761 [Onboard] Loaded
2022-12-20T18:58:33.761Z,1671562713.761 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2022-12-20T18:58:33.762Z,1671562713.762 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409314E0
2022-12-20T18:58:33.763Z,1671562713.763 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 923
2022-12-20T18:58:33.775Z,1671562713.775 [Power24vConverter] Loaded
2022-12-20T18:58:33.776Z,1671562713.776 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2022-12-20T18:58:33.790Z,1671562713.790 [Radio_Surface] Loaded
2022-12-20T18:58:33.790Z,1671562713.790 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2022-12-20T18:58:33.791Z,1671562713.791 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409614E0
2022-12-20T18:58:33.792Z,1671562713.792 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 924
2022-12-20T18:58:33.885Z,1671562713.885 [DAT] Loaded
2022-12-20T18:58:33.886Z,1671562713.886 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2022-12-20T18:58:33.887Z,1671562713.887 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 409914E0
2022-12-20T18:58:33.887Z,1671562713.887 [DAT ThreadHandler](INFO): Protected caller Thread ID is 925
2022-12-20T18:58:33.888Z,1671562713.888 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2022-12-20T18:58:33.888Z,1671562713.888 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2022-12-20T18:58:33.970Z,1671562713.970 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2022-12-20T18:58:33.971Z,1671562713.971 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2022-12-20T18:58:34.167Z,1671562714.167 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2022-12-20T18:58:34.168Z,1671562714.168 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2022-12-20T18:58:34.210Z,1671562714.210 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2022-12-20T18:58:34.211Z,1671562714.211 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2022-12-20T18:58:34.430Z,1671562714.430 [CTD_Seabird] Loaded
2022-12-20T18:58:34.430Z,1671562714.430 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2022-12-20T18:58:34.431Z,1671562714.431 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40ABC4E0
2022-12-20T18:58:34.432Z,1671562714.432 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 926
2022-12-20T18:58:34.452Z,1671562714.452 [PAR_Licor] Loaded
2022-12-20T18:58:34.452Z,1671562714.452 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2022-12-20T18:58:34.484Z,1671562714.484 [WetLabsBB2FL] Loaded
2022-12-20T18:58:34.485Z,1671562714.485 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2022-12-20T18:58:34.486Z,1671562714.486 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AEC4E0
2022-12-20T18:58:34.486Z,1671562714.486 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 927
2022-12-20T18:58:34.487Z,1671562714.487 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2022-12-20T18:58:34.488Z,1671562714.488 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2022-12-20T18:58:34.852Z,1671562714.852 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2022-12-20T18:58:34.852Z,1671562714.852 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2022-12-20T18:58:35.026Z,1671562715.026 [SBIT](DEBUG): Construct Startup Built In Test.
2022-12-20T18:58:35.035Z,1671562715.035 [SBIT] Loaded
2022-12-20T18:58:35.035Z,1671562715.035 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2022-12-20T18:58:35.038Z,1671562715.038 [IBIT](DEBUG): Construct Initiated Built In Test.
2022-12-20T18:58:35.052Z,1671562715.052 [IBIT] Loaded
2022-12-20T18:58:35.052Z,1671562715.052 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2022-12-20T18:58:35.058Z,1671562715.058 [CBIT](DEBUG): Construct Continuous Built In Test.
2022-12-20T18:58:35.167Z,1671562715.167 [CBIT] Loaded
2022-12-20T18:58:35.167Z,1671562715.167 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2022-12-20T18:58:35.168Z,1671562715.168 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2022-12-20T18:58:35.174Z,1671562715.174 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2022-12-20T18:58:35.177Z,1671562715.177 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2022-12-20T18:58:35.188Z,1671562715.188 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2022-12-20T18:58:35.189Z,1671562715.189 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BCF4E0
2022-12-20T18:58:35.190Z,1671562715.190 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 928
2022-12-20T18:58:35.194Z,1671562715.194 [Supervisor](INFO): Main Thread ID is 830
2022-12-20T18:58:35.195Z,1671562715.195 [Supervisor](DEBUG): Running supervisor.
2022-12-20T18:58:35.195Z,1671562715.195 [CommandExec ThreadHandler](INFO): Handler Thread ID is 929
2022-12-20T18:58:35.196Z,1671562715.196 [CommandExec](INFO): Initializing the command executive.
2022-12-20T18:58:35.197Z,1671562715.197 [CommandLine ThreadHandler](INFO): Handler Thread ID is 930
2022-12-20T18:58:35.200Z,1671562715.200 [controlThread ThreadHandler](INFO): Handler Thread ID is 931
2022-12-20T18:58:35.200Z,1671562715.200 [controlThread](DEBUG): Initializing ControlThread
2022-12-20T18:58:35.201Z,1671562715.201 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2022-12-20T18:58:35.203Z,1671562715.203 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2022-12-20T18:58:35.203Z,1671562715.203 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2022-12-20T18:58:35.204Z,1671562715.204 [LoopControl](DEBUG): Initialize LoopControlComponent.
2022-12-20T18:58:35.205Z,1671562715.205 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2022-12-20T18:58:35.205Z,1671562715.205 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2022-12-20T18:58:35.205Z,1671562715.205 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2022-12-20T18:58:35.206Z,1671562715.206 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2022-12-20T18:58:35.206Z,1671562715.206 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2022-12-20T18:58:35.207Z,1671562715.207 [NavChart](DEBUG): Initialize NavChart Navigation.
2022-12-20T18:58:35.208Z,1671562715.208 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2022-12-20T18:58:35.216Z,1671562715.216 [SBIT](INFO): Initialize SBIT Component.
2022-12-20T18:58:35.216Z,1671562715.216 [SBIT](IMPORTANT): git: 2022-12-14
2022-12-20T18:58:35.216Z,1671562715.216 [SBIT](INFO): git hash: c3aea31d7798b2e77c1fbaec46e28ec3366e0fcc
2022-12-20T18:58:35.217Z,1671562715.217 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2022-12-20T18:58:35.218Z,1671562715.218 [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
2022-12-20T18:58:35.219Z,1671562715.219 [SBIT](INFO): Beginning SBIT in 99.000000 seconds.
2022-12-20T18:58:35.220Z,1671562715.220 [IBIT](INFO): Initialize IBIT Component.
2022-12-20T18:58:35.221Z,1671562715.221 [CBIT](DEBUG): Initialize CBIT Component.
2022-12-20T18:58:35.221Z,1671562715.221 [logger ThreadHandler](INFO): Handler Thread ID is 932
2022-12-20T18:58:35.231Z,1671562715.231 [CBIT](DEBUG): Initialized mux pins.
2022-12-20T18:58:35.232Z,1671562715.232 [CBIT](DEBUG): Initializing the watchdog timer.
2022-12-20T18:58:35.240Z,1671562715.240 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 933
2022-12-20T18:58:35.252Z,1671562715.252 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 934
2022-12-20T18:58:35.253Z,1671562715.253 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2022-12-20T18:58:35.256Z,1671562715.256 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2022-12-20T18:58:35.256Z,1671562715.256 [CBIT](DEBUG): Initializing heartbeat.
2022-12-20T18:58:35.264Z,1671562715.264 [Onboard ThreadHandler](INFO): Handler Thread ID is 935
2022-12-20T18:58:35.282Z,1671562715.282 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 936
2022-12-20T18:58:35.304Z,1671562715.304 [DAT ThreadHandler](INFO): Handler Thread ID is 937
2022-12-20T18:58:35.305Z,1671562715.305 [DAT](INFO): Powering up
2022-12-20T18:58:35.305Z,1671562715.305 [DAT](DEBUG): Initializing DAT.
2022-12-20T18:58:35.309Z,1671562715.309 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 939
2022-12-20T18:58:35.309Z,1671562715.309 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2022-12-20T18:58:35.313Z,1671562715.313 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 941
2022-12-20T18:58:35.316Z,1671562715.316 [WetLabsBB2FL](INFO): Powering up
2022-12-20T18:58:35.317Z,1671562715.317 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 943
2022-12-20T18:58:35.325Z,1671562715.325 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2022-12-20T18:58:35.325Z,1671562715.325 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2022-12-20T18:58:35.325Z,1671562715.325 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2022-12-20T18:58:35.325Z,1671562715.325 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2022-12-20T18:58:35.325Z,1671562715.325 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2022-12-20T18:58:35.325Z,1671562715.325 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2022-12-20T18:58:35.326Z,1671562715.326 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2022-12-20T18:58:35.326Z,1671562715.326 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2022-12-20T18:58:35.328Z,1671562715.328 [CBIT](DEBUG): Deactivating GF circuits.
2022-12-20T18:58:35.328Z,1671562715.328 [CBIT](DEBUG): Deactivating emergency mode.
2022-12-20T18:58:35.363Z,1671562715.363 [CBIT](DEBUG): Backplane powered.
2022-12-20T18:58:35.365Z,1671562715.365 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2022-12-20T18:58:35.397Z,1671562715.397 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2022-12-20T18:58:35.410Z,1671562715.410 [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>


2022-12-20T18:58:35.411Z,1671562715.411 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2022-12-20T18:58:35.517Z,1671562715.517 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2022-12-20T18:58:35.518Z,1671562715.518 [Default:A.Wait](DEBUG): Construct Wait.
2022-12-20T18:58:35.520Z,1671562715.520 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2022-12-20T18:58:35.572Z,1671562715.572 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2022-12-20T18:58:35.574Z,1671562715.574 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2022-12-20T18:58:35.596Z,1671562715.596 [Default:E.Execute](DEBUG): Construct Execute.
2022-12-20T18:58:35.600Z,1671562715.600 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

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

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

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

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

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

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

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

    </Aggregate>

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

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

</Mission>


2022-12-20T18:58:35.604Z,1671562715.604 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2022-12-20T18:58:35.618Z,1671562715.618 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2022-12-20T18:58:35.688Z,1671562715.688 [Radio_Surface](INFO): Powering up
2022-12-20T18:58:35.785Z,1671562715.785 [Power24vConverter](INFO): Powering up.
2022-12-20T18:58:35.822Z,1671562715.822 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2022-12-20T18:58:35.828Z,1671562715.828 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2022-12-20T18:58:35.829Z,1671562715.829 [ElevatorServo](DEBUG): Initializing EZServoServo.
2022-12-20T18:58:35.836Z,1671562715.836 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2022-12-20T18:58:35.837Z,1671562715.837 [MassServo](DEBUG): Initializing EZServoServo.
2022-12-20T18:58:35.844Z,1671562715.844 [MassServo](DEBUG): Initializing MassServo.
2022-12-20T18:58:35.845Z,1671562715.845 [RudderServo](DEBUG): Initializing EZServoServo.
2022-12-20T18:58:35.852Z,1671562715.852 [RudderServo](DEBUG): Initializing RudderServo.
2022-12-20T18:58:35.853Z,1671562715.853 [ThrusterHE](DEBUG): Initializing EZServoServo.
2022-12-20T18:58:35.860Z,1671562715.860 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2022-12-20T18:58:36.772Z,1671562716.772 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2022-12-20T18:58:36.772Z,1671562716.772 [RudderServo](FAULT): Rudder failed to initialize
2022-12-20T18:58:36.772Z,1671562716.772 [RudderServo] Communications Fault, FailCount= 1
2022-12-20T18:58:36.772Z,1671562716.772 [RudderServo](ERROR): Communications Fault
2022-12-20T18:58:36.776Z,1671562716.776 [CBIT](ERROR): Communications Fault in component: RudderServo
2022-12-20T18:58:37.001Z,1671562717.001 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-12-20T18:58:37.001Z,1671562717.001 [RudderServo](INFO): Powering down
2022-12-20T18:58:37.424Z,1671562717.424 [WetLabsBB2FL](INFO): Powering down
2022-12-20T18:58:37.651Z,1671562717.651 [RudderServo](DEBUG): Initializing EZServoServo.
2022-12-20T18:58:37.772Z,1671562717.772 [RudderServo](DEBUG): Initializing RudderServo.
2022-12-20T18:58:37.776Z,1671562717.776 [CBIT](INFO): Clearing failed state for component RudderServo
2022-12-20T18:58:37.776Z,1671562717.776 [RudderServo] No Fault, FailCount= 1
2022-12-20T18:58:41.632Z,1671562721.632 [ThrusterHE](ERROR): Zero Speed Commanded.
2022-12-20T18:58:47.404Z,1671562727.404 [DAT](INFO): DAT read: 

2022-12-20T18:58:47.405Z,1671562727.405 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series

2022-12-20T18:58:49.168Z,1671562729.168 [DAT](INFO): DAT read: MF Frequency Band

2022-12-20T18:58:49.169Z,1671562729.169 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0

2022-12-20T18:58:49.170Z,1671562729.170 [DAT](INFO): DAT read: Dec 20 2022 18:58:44 

2022-12-20T18:58:50.177Z,1671562730.177 [DAT](INFO): DAT read: Features enabled [Bearing]

2022-12-20T18:58:50.178Z,1671562730.178 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2022-12-20T18:58:50.178Z,1671562730.178 [DAT](INFO): commRate: 800
2022-12-20T18:58:52.243Z,1671562732.243 [DAT](INFO): entering command mode
2022-12-20T18:58:52.444Z,1671562732.444 [DAT](INFO): DAT read: 

2022-12-20T18:58:52.445Z,1671562732.445 [DAT](INFO): DAT read: user:1>

2022-12-20T18:58:52.445Z,1671562732.445 [DAT](INFO): setting verbose to 3
2022-12-20T18:58:52.696Z,1671562732.696 [DAT](INFO): DAT read: user:1>

2022-12-20T18:58:52.698Z,1671562732.698 [DAT](INFO): DAT read: Verbose         | 3           

2022-12-20T18:58:52.698Z,1671562732.698 [DAT](INFO): set verbose to 3
2022-12-20T18:58:52.698Z,1671562732.698 [DAT](INFO): setting DatVerbose to 27440
2022-12-20T18:58:52.948Z,1671562732.948 [DAT](INFO): DAT read: user:2>

2022-12-20T18:58:52.949Z,1671562732.949 [DAT](INFO): DAT read: DatVerbose      | 27440       

2022-12-20T18:58:52.949Z,1671562732.949 [DAT](INFO): set DatVerbose to 27440
2022-12-20T18:58:52.950Z,1671562732.950 [DAT](INFO): setting transmit power to 8
2022-12-20T18:58:53.200Z,1671562733.200 [DAT](INFO): DAT read: user:3>

2022-12-20T18:58:53.201Z,1671562733.201 [DAT](INFO): DAT read: TxPower         | 8 (Max)     

2022-12-20T18:58:53.202Z,1671562733.202 [DAT](INFO): set transmit power to 8
2022-12-20T18:58:53.202Z,1671562733.202 [DAT](INFO): setting local address to 5
2022-12-20T18:58:53.452Z,1671562733.452 [DAT](INFO): DAT read: user:4>

2022-12-20T18:58:53.453Z,1671562733.453 [DAT](INFO): DAT read: LocalAddr       | 5           

2022-12-20T18:58:53.453Z,1671562733.453 [DAT](INFO): set local address to 5
2022-12-20T18:58:53.455Z,1671562733.455 [DAT](INFO): Setting time to: 18:58:53 And date to:12/20/2022
2022-12-20T18:58:53.704Z,1671562733.704 [DAT](INFO): DAT read: user:5>

2022-12-20T18:58:53.705Z,1671562733.705 [DAT](INFO): DAT read: Tue Dec 20, 2022  18:58:53  

2022-12-20T18:58:53.705Z,1671562733.705 [DAT](INFO): Local DAT time set to Tue Dec 20, 2022  18:58:53  

2022-12-20T18:59:03.929Z,1671562743.929 [NAL9602](INFO): Powering up NAL9602
2022-12-20T18:59:14.846Z,1671562754.846 [NAL9602](INFO): NAL9602 initialized
2022-12-20T19:00:14.640Z,1671562814.640 [SBIT](IMPORTANT): Beginning Startup BIT
2022-12-20T19:00:14.644Z,1671562814.644 [CBIT](IMPORTANT): Beginning ground fault scan
2022-12-20T19:00:25.578Z,1671562825.578 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.007932
CHAN A1 (24V): -0.008469
CHAN A2 (12V): -0.004511
CHAN A3 (5V): -0.003473
CHAN B0 (3.3V): -0.001770
CHAN B1 (3.15aV): -0.001503
CHAN B2 (3.15bV): -0.001182
CHAN B3 (GND): -0.000828
OPEN: 0.004347
Full Scale: +/- 1 mA
2022-12-20T19:01:08.435Z,1671562868.435 [SBIT](IMPORTANT): SBIT PASSED
2022-12-20T19:01:08.435Z,1671562868.435 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2022-12-20T19:01:08.455Z,1671562868.455 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=6 count;

2022-12-20T19:01:08.455Z,1671562868.455 [SBIT](IMPORTANT): BackseatComponent.alwaysOn=0 bool;

2022-12-20T19:01:08.455Z,1671562868.455 [SBIT](IMPORTANT): CBIT.runNavErrorCritical=0 bool;

2022-12-20T19:01:08.456Z,1671562868.456 [SBIT](IMPORTANT): CTD_Seabird.minSalinityBound=0 practical_salinity_unit;

2022-12-20T19:01:08.456Z,1671562868.456 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water;

2022-12-20T19:01:08.456Z,1671562868.456 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water;

2022-12-20T19:01:08.456Z,1671562868.456 [SBIT](IMPORTANT): Express linearApproximation platform_roll_angle 5.000000 degree;

2022-12-20T19:01:08.456Z,1671562868.456 [SBIT](IMPORTANT): IBIT.batteryCapacityThreshold=30 ampere_hour;

2022-12-20T19:01:08.456Z,1671562868.456 [SBIT](IMPORTANT): IBIT.batteryVoltageThreshold=12 volt;

2022-12-20T19:01:08.456Z,1671562868.456 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=324.282117 cubic_centimeter;

2022-12-20T19:01:08.457Z,1671562868.457 [SBIT](IMPORTANT): VerticalControl.massDefault=20 millimeter;

2022-12-20T19:01:08.822Z,1671562868.822 [MissionManager](IMPORTANT): Started mission Startup
2022-12-20T19:01:08.822Z,1671562868.822 [Startup] Running Loop=1
2022-12-20T19:01:08.822Z,1671562868.822 [Startup](DEBUG): Aggregate::initialize Startup
2022-12-20T19:01:08.822Z,1671562868.822 [Startup:A.GoToSurface] Running Loop=1
2022-12-20T19:01:08.822Z,1671562868.822 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-12-20T19:01:08.823Z,1671562868.823 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-12-20T19:01:08.824Z,1671562868.824 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-12-20T19:01:08.824Z,1671562868.824 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-12-20T19:01:08.824Z,1671562868.824 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-12-20T19:01:08.825Z,1671562868.825 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-12-20T19:01:08.826Z,1671562868.826 [Startup:StartupSatComms] Running Loop=1
2022-12-20T19:01:08.826Z,1671562868.826 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2022-12-20T19:01:08.826Z,1671562868.826 [Startup:StartupSatComms:A] Running Loop=1
2022-12-20T19:01:09.193Z,1671562869.193 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2022-12-20T19:01:35.463Z,1671562895.463 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2022-12-20T19:01:35.463Z,1671562895.463 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-12-20T19:01:35.474Z,1671562895.474 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-12-20T19:01:35.870Z,1671562895.870 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-12-20T19:01:35.870Z,1671562895.870 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2022-12-20T19:02:04.362Z,1671562924.362 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004768
2022-12-20T19:02:08.982Z,1671562928.982 [Startup:StartupSatComms:A](INFO): Timed out from 2022-12-20T19:01:08.8Z
2022-12-20T19:02:08.982Z,1671562928.982 [Startup:StartupSatComms:A] Stopped
2022-12-20T19:02:08.982Z,1671562928.982 [Startup:StartupSatComms:B] Running Loop=1
2022-12-20T19:02:09.379Z,1671562929.379 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-12-20T19:02:16.629Z,1671562936.629 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20221220T185317/Courier0000.lzma
2022-12-20T19:02:17.629Z,1671562937.629 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185317/Courier0000.lzma.bak
2022-12-20T19:02:17.630Z,1671562937.630 [DataOverHttps](INFO): SBD MOMSN=17399718
2022-12-20T19:02:34.420Z,1671562954.420 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20221220T185317/Courier0004.lzma
2022-12-20T19:02:35.421Z,1671562955.421 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185317/Courier0004.lzma.bak
2022-12-20T19:02:35.422Z,1671562955.422 [DataOverHttps](INFO): SBD MOMSN=17399721
2022-12-20T19:02:54.092Z,1671562974.092 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20221220T185317/Courier0007.lzma
2022-12-20T19:02:55.093Z,1671562975.093 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185317/Courier0007.lzma.bak
2022-12-20T19:02:55.094Z,1671562975.094 [DataOverHttps](INFO): SBD MOMSN=17399723
2022-12-20T19:03:09.266Z,1671562989.266 [Startup:StartupSatComms:B](INFO): Timed out from 2022-12-20T19:02:08.0Z
2022-12-20T19:03:09.266Z,1671562989.266 [Startup:StartupSatComms:B] Stopped
2022-12-20T19:03:09.266Z,1671562989.266 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2022-12-20T19:03:09.266Z,1671562989.266 [Startup:StartupSatComms] Stopped
2022-12-20T19:03:09.266Z,1671562989.266 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2022-12-20T19:03:09.267Z,1671562989.267 [Startup](INFO): Completed Startup
2022-12-20T19:03:09.267Z,1671562989.267 [MissionManager](INFO): Startup is completed.
2022-12-20T19:03:09.267Z,1671562989.267 [MissionManager](INFO): Uninitializing Mission Startup
2022-12-20T19:03:09.267Z,1671562989.267 [Startup] Stopped
2022-12-20T19:03:09.279Z,1671562989.279 [Startup](DEBUG): Aggregate::uninitialize Startup
2022-12-20T19:03:09.280Z,1671562989.280 [Startup:A.GoToSurface] Stopped
2022-12-20T19:03:09.280Z,1671562989.280 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-12-20T19:03:09.643Z,1671562989.643 [MissionManager](IMPORTANT): Started mission Default
2022-12-20T19:03:09.648Z,1671562989.648 [Default] Running Loop=1
2022-12-20T19:03:09.648Z,1671562989.648 [Default](DEBUG): Aggregate::initialize Default
2022-12-20T19:03:09.648Z,1671562989.648 [Default:B.GoToSurface] Running Loop=1
2022-12-20T19:03:09.648Z,1671562989.648 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-12-20T19:03:09.648Z,1671562989.648 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-12-20T19:03:09.648Z,1671562989.648 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-12-20T19:03:09.649Z,1671562989.649 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-12-20T19:03:09.649Z,1671562989.649 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-12-20T19:03:09.649Z,1671562989.649 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-12-20T19:03:09.650Z,1671562989.650 [Default:A.Wait] Running Loop=1
2022-12-20T19:03:09.650Z,1671562989.650 [Default:A.Wait](DEBUG): Initialize Wait Component.
2022-12-20T19:03:13.691Z,1671562993.691 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20221220T185317/Courier0010.lzma
2022-12-20T19:03:14.693Z,1671562994.693 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185317/Courier0010.lzma.bak
2022-12-20T19:03:14.693Z,1671562994.693 [DataOverHttps](INFO): SBD MOMSN=17399726
2022-12-20T19:03:22.949Z,1671563002.949 [Default:A.Wait](INFO): Done Waiting.
2022-12-20T19:03:22.949Z,1671563002.949 [Default:A.Wait] Stopped
2022-12-20T19:03:22.949Z,1671563002.949 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T19:03:23.342Z,1671563003.342 [Default:CheckIn] Running Loop=1
2022-12-20T19:03:23.342Z,1671563003.342 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-20T19:03:23.343Z,1671563003.343 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-20T19:03:23.745Z,1671563003.745 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2022-12-20T19:04:17.873Z,1671563057.873 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-12-20T19:04:18.691Z,1671563058.691 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T19:04:19.111Z,1671563059.111 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190418.00,A,3648.13138,N,12147.22415,W,0.058,0.00,201222,,,D*70
2022-12-20T19:04:19.115Z,1671563059.115 [NAL9602](INFO): GPS fix at 20221220T190418: (36.802190, -121.787069)
2022-12-20T19:04:19.126Z,1671563059.126 [Default:CheckIn:Read_GPS] Stopped
2022-12-20T19:04:19.126Z,1671563059.126 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-20T19:04:19.548Z,1671563059.548 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-12-20T19:04:26.903Z,1671563066.903 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20221220T185823/Courier0000.lzma
2022-12-20T19:04:27.905Z,1671563067.905 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Courier0000.lzma.bak
2022-12-20T19:04:27.905Z,1671563067.905 [DataOverHttps](INFO): SBD MOMSN=17399730
2022-12-20T19:04:32.786Z,1671563072.786 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T19:04:45.675Z,1671563085.675 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T19:04:48.419Z,1671563088.419 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20221220T185823/Courier0004.lzma
2022-12-20T19:04:49.421Z,1671563089.421 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Courier0004.lzma.bak
2022-12-20T19:04:49.422Z,1671563089.422 [DataOverHttps](INFO): SBD MOMSN=17399733
2022-12-20T19:04:51.712Z,1671563091.712 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-20T19:04:59.008Z,1671563099.008 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T19:05:08.277Z,1671563108.277 [DataOverHttps](INFO): Sending 115 bytes from file Logs/20221220T164801/Express0038.lzma
2022-12-20T19:05:09.278Z,1671563109.278 [DataOverHttps](INFO): Moved sent file to Logs/20221220T164801/Express0038.lzma.bak
2022-12-20T19:05:09.278Z,1671563109.278 [DataOverHttps](INFO): SBD MOMSN=17399737
2022-12-20T19:05:12.782Z,1671563112.782 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T19:05:25.670Z,1671563125.670 [DataOverHttps](INFO): Sending 1011 bytes from file Logs/20221220T185317/Express0001.lzma
2022-12-20T19:05:25.713Z,1671563125.713 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T19:05:26.670Z,1671563126.670 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185317/Express0001.lzma.bak
2022-12-20T19:05:26.670Z,1671563126.670 [DataOverHttps](INFO): SBD MOMSN=17399740
2022-12-20T19:05:39.034Z,1671563139.034 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T19:05:42.845Z,1671563142.845 [DataOverHttps](INFO): Sending 189 bytes from file Logs/20221220T185317/Express0005.lzma
2022-12-20T19:05:43.846Z,1671563143.846 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185317/Express0005.lzma.bak
2022-12-20T19:05:43.846Z,1671563143.846 [DataOverHttps](INFO): SBD MOMSN=17399763
2022-12-20T19:05:52.367Z,1671563152.367 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T19:05:59.721Z,1671563159.721 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20221220T185317/Express0008.lzma
2022-12-20T19:06:00.721Z,1671563160.721 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185317/Express0008.lzma.bak
2022-12-20T19:06:00.722Z,1671563160.722 [DataOverHttps](INFO): SBD MOMSN=17399768
2022-12-20T19:06:05.729Z,1671563165.729 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T19:06:16.615Z,1671563176.615 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20221220T185317/Express0011.lzma
2022-12-20T19:06:17.618Z,1671563177.618 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185317/Express0011.lzma.bak
2022-12-20T19:06:17.618Z,1671563177.618 [DataOverHttps](INFO): SBD MOMSN=17399776
2022-12-20T19:06:19.438Z,1671563179.438 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T19:06:32.954Z,1671563192.954 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T19:06:34.461Z,1671563194.461 [DataOverHttps](INFO): Sending 1013 bytes from file Logs/20221220T185823/Express0001.lzma
2022-12-20T19:06:35.462Z,1671563195.462 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Express0001.lzma.bak
2022-12-20T19:06:35.463Z,1671563195.463 [DataOverHttps](INFO): SBD MOMSN=17399778
2022-12-20T19:06:53.876Z,1671563213.876 [DataOverHttps](INFO): Sending 329 bytes from file Logs/20221220T185823/Express0005.lzma
2022-12-20T19:06:54.878Z,1671563214.878 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Express0005.lzma.bak
2022-12-20T19:06:54.878Z,1671563214.878 [DataOverHttps](INFO): SBD MOMSN=17399801
2022-12-20T19:06:55.946Z,1671563215.946 [Default:CheckIn:Read_Iridium] Stopped
2022-12-20T19:06:55.946Z,1671563215.946 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-20T19:06:55.946Z,1671563215.946 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-20T19:06:59.590Z,1671563219.590 [BPC1](INFO): Calculating totals. Valid battery stick count: 52. Valid reserve battery stick count: 5.
2022-12-20T19:06:59.593Z,1671563219.593 [BPC1](INFO): Received data from all battery sticks.
2022-12-20T19:11:56.710Z,1671563516.710 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-20T19:11:56.710Z,1671563516.710 [Default:CheckIn:C.Wait] Stopped
2022-12-20T19:11:56.710Z,1671563516.710 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T19:11:56.710Z,1671563516.710 [Default:CheckIn:D] Running Loop=1
2022-12-20T19:11:57.107Z,1671563517.107 [Default:CheckIn:D] Stopped
2022-12-20T19:11:57.107Z,1671563517.107 [Default:CheckIn:E] Running Loop=1
2022-12-20T19:11:57.505Z,1671563517.505 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 8.791064 min 
2022-12-20T19:11:57.505Z,1671563517.505 [Default:CheckIn:E] Stopped
2022-12-20T19:11:57.505Z,1671563517.505 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-20T19:11:57.505Z,1671563517.505 [Default:CheckIn] Stopped
2022-12-20T19:11:57.505Z,1671563517.505 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-20T19:11:57.505Z,1671563517.505 [Default:CheckIn](INFO): Running loop #2
2022-12-20T19:11:57.505Z,1671563517.505 [Default:CheckIn] Running Loop=2
2022-12-20T19:11:57.505Z,1671563517.505 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-20T19:11:57.506Z,1671563517.506 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-20T19:11:59.522Z,1671563519.522 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191158.00,A,3648.13195,N,12147.21978,W,0.058,255.56,201222,,,D*73
2022-12-20T19:11:59.532Z,1671563519.532 [NAL9602](INFO): GPS fix at 20221220T191158: (36.802199, -121.786996)
2022-12-20T19:11:59.542Z,1671563519.542 [Default:CheckIn:Read_GPS] Stopped
2022-12-20T19:11:59.542Z,1671563519.542 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-20T19:12:06.758Z,1671563526.758 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20221220T185823/Courier0007.lzma
2022-12-20T19:12:07.760Z,1671563527.760 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Courier0007.lzma.bak
2022-12-20T19:12:07.760Z,1671563527.760 [DataOverHttps](INFO): SBD MOMSN=17399808
2022-12-20T19:12:23.646Z,1671563543.646 [DataOverHttps](INFO): Sending 170 bytes from file Logs/20221220T185823/Express0008.lzma
2022-12-20T19:12:24.648Z,1671563544.648 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Express0008.lzma.bak
2022-12-20T19:12:24.648Z,1671563544.648 [DataOverHttps](INFO): SBD MOMSN=17399811
2022-12-20T19:12:25.795Z,1671563545.795 [Default:CheckIn:Read_Iridium] Stopped
2022-12-20T19:12:25.795Z,1671563545.795 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-20T19:12:25.795Z,1671563545.795 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-20T19:17:01.247Z,1671563821.247 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-12-20T19:17:26.313Z,1671563846.313 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-20T19:17:26.313Z,1671563846.313 [Default:CheckIn:C.Wait] Stopped
2022-12-20T19:17:26.313Z,1671563846.313 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T19:17:26.313Z,1671563846.313 [Default:CheckIn:D] Running Loop=1
2022-12-20T19:17:26.716Z,1671563846.716 [Default:CheckIn:D] Stopped
2022-12-20T19:17:26.716Z,1671563846.716 [Default:CheckIn:E] Running Loop=1
2022-12-20T19:17:27.117Z,1671563847.117 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 14.284543 min 
2022-12-20T19:17:27.117Z,1671563847.117 [Default:CheckIn:E] Stopped
2022-12-20T19:17:27.117Z,1671563847.117 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-20T19:17:27.117Z,1671563847.117 [Default:CheckIn] Stopped
2022-12-20T19:17:27.117Z,1671563847.117 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-20T19:17:27.117Z,1671563847.117 [Default:CheckIn](INFO): Running loop #3
2022-12-20T19:17:27.134Z,1671563847.134 [Default:CheckIn] Running Loop=3
2022-12-20T19:17:27.134Z,1671563847.134 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-20T19:17:27.134Z,1671563847.134 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-20T19:17:29.129Z,1671563849.129 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191728.00,A,3648.13336,N,12147.21638,W,0.097,255.56,201222,,,D*71
2022-12-20T19:17:29.132Z,1671563849.132 [NAL9602](INFO): GPS fix at 20221220T191728: (36.802223, -121.786940)
2022-12-20T19:17:29.142Z,1671563849.142 [Default:CheckIn:Read_GPS] Stopped
2022-12-20T19:17:29.143Z,1671563849.143 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-20T19:17:36.669Z,1671563856.669 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221220T185823/Courier0010.lzma
2022-12-20T19:17:37.683Z,1671563857.683 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Courier0010.lzma.bak
2022-12-20T19:17:37.684Z,1671563857.684 [DataOverHttps](INFO): SBD MOMSN=17399817
2022-12-20T19:17:53.426Z,1671563873.426 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20221220T185823/Express0011.lzma
2022-12-20T19:17:54.428Z,1671563874.428 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Express0011.lzma.bak
2022-12-20T19:17:54.428Z,1671563874.428 [DataOverHttps](INFO): SBD MOMSN=17399820
2022-12-20T19:17:55.800Z,1671563875.800 [Default:CheckIn:Read_Iridium] Stopped
2022-12-20T19:17:55.800Z,1671563875.800 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-20T19:17:55.801Z,1671563875.801 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-20T19:18:01.447Z,1671563881.447 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-20T19:22:56.472Z,1671564176.472 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-20T19:22:56.472Z,1671564176.472 [Default:CheckIn:C.Wait] Stopped
2022-12-20T19:22:56.472Z,1671564176.472 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T19:22:56.472Z,1671564176.472 [Default:CheckIn:D] Running Loop=1
2022-12-20T19:22:56.901Z,1671564176.901 [Default:CheckIn:D] Stopped
2022-12-20T19:22:56.901Z,1671564176.901 [Default:CheckIn:E] Running Loop=1
2022-12-20T19:22:57.277Z,1671564177.277 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 19.787622 min 
2022-12-20T19:22:57.277Z,1671564177.277 [Default:CheckIn:E] Stopped
2022-12-20T19:22:57.277Z,1671564177.277 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-20T19:22:57.277Z,1671564177.277 [Default:CheckIn] Stopped
2022-12-20T19:22:57.277Z,1671564177.277 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-20T19:22:57.277Z,1671564177.277 [Default:CheckIn](INFO): Running loop #4
2022-12-20T19:22:57.278Z,1671564177.278 [Default:CheckIn] Running Loop=4
2022-12-20T19:22:57.278Z,1671564177.278 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-20T19:22:57.278Z,1671564177.278 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-20T19:22:59.289Z,1671564179.289 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192258.00,A,3648.13013,N,12147.21774,W,0.039,255.56,201222,,,D*79
2022-12-20T19:22:59.291Z,1671564179.291 [NAL9602](INFO): GPS fix at 20221220T192258: (36.802169, -121.786962)
2022-12-20T19:22:59.302Z,1671564179.302 [Default:CheckIn:Read_GPS] Stopped
2022-12-20T19:22:59.302Z,1671564179.302 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-20T19:23:09.906Z,1671564189.906 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221220T185823/Courier0013.lzma
2022-12-20T19:23:10.908Z,1671564190.908 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Courier0013.lzma.bak
2022-12-20T19:23:10.908Z,1671564190.908 [DataOverHttps](INFO): SBD MOMSN=17399827
2022-12-20T19:23:27.109Z,1671564207.109 [DataOverHttps](INFO): Sending 138 bytes from file Logs/20221220T185823/Express0014.lzma
2022-12-20T19:23:28.112Z,1671564208.112 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Express0014.lzma.bak
2022-12-20T19:23:28.112Z,1671564208.112 [DataOverHttps](INFO): SBD MOMSN=17399830
2022-12-20T19:23:29.235Z,1671564209.235 [Default:CheckIn:Read_Iridium] Stopped
2022-12-20T19:23:29.235Z,1671564209.235 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-20T19:23:29.235Z,1671564209.235 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-20T19:23:30.041Z,1671564210.041 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-12-20T19:23:30.114Z,1671564210.114 [NAL9602](ERROR): received: 
+CSQ:0

OK
2022-12-20T19:28:01.627Z,1671564481.627 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-12-20T19:28:29.928Z,1671564509.928 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-20T19:28:29.928Z,1671564509.928 [Default:CheckIn:C.Wait] Stopped
2022-12-20T19:28:29.929Z,1671564509.929 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T19:28:29.929Z,1671564509.929 [Default:CheckIn:D] Running Loop=1
2022-12-20T19:28:30.321Z,1671564510.321 [Default:CheckIn:D] Stopped
2022-12-20T19:28:30.321Z,1671564510.321 [Default:CheckIn:E] Running Loop=1
2022-12-20T19:28:30.729Z,1671564510.729 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 25.344627 min 
2022-12-20T19:28:30.729Z,1671564510.729 [Default:CheckIn:E] Stopped
2022-12-20T19:28:30.730Z,1671564510.730 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-20T19:28:30.730Z,1671564510.730 [Default:CheckIn] Stopped
2022-12-20T19:28:30.730Z,1671564510.730 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-20T19:28:30.730Z,1671564510.730 [Default:CheckIn](INFO): Running loop #5
2022-12-20T19:28:30.730Z,1671564510.730 [Default:CheckIn] Running Loop=5
2022-12-20T19:28:30.730Z,1671564510.730 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-20T19:28:30.730Z,1671564510.730 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-20T19:28:32.741Z,1671564512.741 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192831.00,A,3648.13162,N,12147.21657,W,0.039,255.56,201222,,,D*7B
2022-12-20T19:28:32.743Z,1671564512.743 [NAL9602](INFO): GPS fix at 20221220T192831: (36.802194, -121.786943)
2022-12-20T19:28:32.767Z,1671564512.767 [Default:CheckIn:Read_GPS] Stopped
2022-12-20T19:28:32.767Z,1671564512.767 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-20T19:28:43.233Z,1671564523.233 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221220T185823/Courier0016.lzma
2022-12-20T19:28:44.236Z,1671564524.236 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Courier0016.lzma.bak
2022-12-20T19:28:44.236Z,1671564524.236 [DataOverHttps](INFO): SBD MOMSN=17399836
2022-12-20T19:29:00.018Z,1671564540.018 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20221220T185823/Express0017.lzma
2022-12-20T19:29:01.020Z,1671564541.020 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Express0017.lzma.bak
2022-12-20T19:29:01.020Z,1671564541.020 [DataOverHttps](INFO): SBD MOMSN=17399839
2022-12-20T19:29:02.302Z,1671564542.302 [Default:CheckIn:Read_Iridium] Stopped
2022-12-20T19:29:02.302Z,1671564542.302 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-20T19:29:02.302Z,1671564542.302 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-20T19:29:05.539Z,1671564545.539 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-20T19:34:02.957Z,1671564842.957 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-20T19:34:02.957Z,1671564842.957 [Default:CheckIn:C.Wait] Stopped
2022-12-20T19:34:02.957Z,1671564842.957 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T19:34:02.957Z,1671564842.957 [Default:CheckIn:D] Running Loop=1
2022-12-20T19:34:03.361Z,1671564843.361 [Default:CheckIn:D] Stopped
2022-12-20T19:34:03.361Z,1671564843.361 [Default:CheckIn:E] Running Loop=1
2022-12-20T19:34:03.775Z,1671564843.775 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 30.895292 min 
2022-12-20T19:34:03.775Z,1671564843.775 [Default:CheckIn:E] Stopped
2022-12-20T19:34:03.775Z,1671564843.775 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-20T19:34:03.775Z,1671564843.775 [Default:CheckIn] Stopped
2022-12-20T19:34:03.775Z,1671564843.775 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-20T19:34:03.776Z,1671564843.776 [Default:CheckIn](INFO): Running loop #6
2022-12-20T19:34:03.776Z,1671564843.776 [Default:CheckIn] Running Loop=6
2022-12-20T19:34:03.776Z,1671564843.776 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-20T19:34:03.776Z,1671564843.776 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-20T19:34:05.776Z,1671564845.776 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193404.00,A,3648.13582,N,12147.21423,W,0.058,255.56,201222,,,D*7C
2022-12-20T19:34:05.778Z,1671564845.778 [NAL9602](INFO): GPS fix at 20221220T193404: (36.802264, -121.786904)
2022-12-20T19:34:05.801Z,1671564845.801 [Default:CheckIn:Read_GPS] Stopped
2022-12-20T19:34:05.801Z,1671564845.801 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-20T19:34:12.930Z,1671564852.930 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221220T185823/Courier0019.lzma
2022-12-20T19:34:13.932Z,1671564853.932 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Courier0019.lzma.bak
2022-12-20T19:34:13.932Z,1671564853.932 [DataOverHttps](INFO): SBD MOMSN=17399846
2022-12-20T19:34:29.753Z,1671564869.753 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20221220T185823/Express0020.lzma
2022-12-20T19:34:30.756Z,1671564870.756 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Express0020.lzma.bak
2022-12-20T19:34:30.756Z,1671564870.756 [DataOverHttps](INFO): SBD MOMSN=17399849
2022-12-20T19:34:32.074Z,1671564872.074 [Default:CheckIn:Read_Iridium] Stopped
2022-12-20T19:34:32.074Z,1671564872.074 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-20T19:34:32.074Z,1671564872.074 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-20T19:34:36.520Z,1671564876.520 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-12-20T19:34:36.594Z,1671564876.594 [NAL9602](ERROR): received: 
+CSQ:0

OK
2022-12-20T19:39:07.619Z,1671565147.619 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-12-20T19:39:32.677Z,1671565172.677 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-20T19:39:32.677Z,1671565172.677 [Default:CheckIn:C.Wait] Stopped
2022-12-20T19:39:32.677Z,1671565172.677 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T19:39:32.677Z,1671565172.677 [Default:CheckIn:D] Running Loop=1
2022-12-20T19:39:33.084Z,1671565173.084 [Default:CheckIn:D] Stopped
2022-12-20T19:39:33.084Z,1671565173.084 [Default:CheckIn:E] Running Loop=1
2022-12-20T19:39:33.498Z,1671565173.498 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 36.390682 min 
2022-12-20T19:39:33.498Z,1671565173.498 [Default:CheckIn:E] Stopped
2022-12-20T19:39:33.498Z,1671565173.498 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-20T19:39:33.498Z,1671565173.498 [Default:CheckIn] Stopped
2022-12-20T19:39:33.498Z,1671565173.498 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-20T19:39:33.498Z,1671565173.498 [Default:CheckIn](INFO): Running loop #7
2022-12-20T19:39:33.498Z,1671565173.498 [Default:CheckIn] Running Loop=7
2022-12-20T19:39:33.498Z,1671565173.498 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-20T19:39:33.498Z,1671565173.498 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-20T19:39:35.501Z,1671565175.501 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193934.00,A,3648.13071,N,12147.21723,W,0.058,255.56,201222,,,D*78
2022-12-20T19:39:35.503Z,1671565175.503 [NAL9602](INFO): GPS fix at 20221220T193934: (36.802178, -121.786954)
2022-12-20T19:39:35.513Z,1671565175.513 [Default:CheckIn:Read_GPS] Stopped
2022-12-20T19:39:35.513Z,1671565175.513 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-20T19:39:42.733Z,1671565182.733 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221220T185823/Courier0022.lzma
2022-12-20T19:39:43.736Z,1671565183.736 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Courier0022.lzma.bak
2022-12-20T19:39:43.736Z,1671565183.736 [DataOverHttps](INFO): SBD MOMSN=17399855
2022-12-20T19:39:59.498Z,1671565199.498 [DataOverHttps](INFO): Sending 214 bytes from file Logs/20221220T185823/Express0023.lzma
2022-12-20T19:40:00.499Z,1671565200.499 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Express0023.lzma.bak
2022-12-20T19:40:00.500Z,1671565200.500 [DataOverHttps](INFO): SBD MOMSN=17399858
2022-12-20T19:40:01.765Z,1671565201.765 [Default:CheckIn:Read_Iridium] Stopped
2022-12-20T19:40:01.765Z,1671565201.765 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-20T19:40:01.765Z,1671565201.765 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-20T19:40:07.820Z,1671565207.820 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-20T19:45:02.396Z,1671565502.396 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-20T19:45:02.397Z,1671565502.397 [Default:CheckIn:C.Wait] Stopped
2022-12-20T19:45:02.397Z,1671565502.397 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T19:45:02.397Z,1671565502.397 [Default:CheckIn:D] Running Loop=1
2022-12-20T19:45:02.817Z,1671565502.817 [Default:CheckIn:D] Stopped
2022-12-20T19:45:02.822Z,1671565502.822 [Default:CheckIn:E] Running Loop=1
2022-12-20T19:45:03.210Z,1671565503.210 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 41.886230 min 
2022-12-20T19:45:03.210Z,1671565503.210 [Default:CheckIn:E] Stopped
2022-12-20T19:45:03.210Z,1671565503.210 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-20T19:45:03.210Z,1671565503.210 [Default:CheckIn] Stopped
2022-12-20T19:45:03.210Z,1671565503.210 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-20T19:45:03.211Z,1671565503.211 [Default:CheckIn](INFO): Running loop #8
2022-12-20T19:45:03.211Z,1671565503.211 [Default:CheckIn] Running Loop=8
2022-12-20T19:45:03.211Z,1671565503.211 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-20T19:45:03.211Z,1671565503.211 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-20T19:45:05.205Z,1671565505.205 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194504.00,A,3648.13378,N,12147.21702,W,0.019,255.56,201222,,,D*7C
2022-12-20T19:45:05.207Z,1671565505.207 [NAL9602](INFO): GPS fix at 20221220T194504: (36.802230, -121.786950)
2022-12-20T19:45:05.250Z,1671565505.250 [Default:CheckIn:Read_GPS] Stopped
2022-12-20T19:45:05.250Z,1671565505.250 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-20T19:45:15.721Z,1671565515.721 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20221220T185823/Courier0025.lzma
2022-12-20T19:45:16.724Z,1671565516.724 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Courier0025.lzma.bak
2022-12-20T19:45:16.724Z,1671565516.724 [DataOverHttps](INFO): SBD MOMSN=17399865
2022-12-20T19:45:32.577Z,1671565532.577 [DataOverHttps](INFO): Sending 138 bytes from file Logs/20221220T185823/Express0026.lzma
2022-12-20T19:45:33.580Z,1671565533.580 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Express0026.lzma.bak
2022-12-20T19:45:33.580Z,1671565533.580 [DataOverHttps](INFO): SBD MOMSN=17399868
2022-12-20T19:45:34.750Z,1671565534.750 [Default:CheckIn:Read_Iridium] Stopped
2022-12-20T19:45:34.750Z,1671565534.750 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-20T19:45:34.750Z,1671565534.750 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-20T19:45:35.945Z,1671565535.945 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-12-20T19:45:36.022Z,1671565536.022 [NAL9602](ERROR): received: 
+CSQ:0

OK
2022-12-20T19:50:07.895Z,1671565807.895 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-12-20T19:50:35.371Z,1671565835.371 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-20T19:50:35.371Z,1671565835.371 [Default:CheckIn:C.Wait] Stopped
2022-12-20T19:50:35.371Z,1671565835.371 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T19:50:35.371Z,1671565835.371 [Default:CheckIn:D] Running Loop=1
2022-12-20T19:50:35.776Z,1671565835.776 [Default:CheckIn:D] Stopped
2022-12-20T19:50:35.776Z,1671565835.776 [Default:CheckIn:E] Running Loop=1
2022-12-20T19:50:36.187Z,1671565836.187 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 47.435539 min 
2022-12-20T19:50:36.188Z,1671565836.188 [Default:CheckIn:E] Stopped
2022-12-20T19:50:36.188Z,1671565836.188 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-20T19:50:36.188Z,1671565836.188 [Default:CheckIn] Stopped
2022-12-20T19:50:36.188Z,1671565836.188 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-20T19:50:36.200Z,1671565836.200 [Default:CheckIn](INFO): Running loop #9
2022-12-20T19:50:36.200Z,1671565836.200 [Default:CheckIn] Running Loop=9
2022-12-20T19:50:36.201Z,1671565836.201 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-20T19:50:36.201Z,1671565836.201 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-20T19:50:38.184Z,1671565838.184 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195037.00,A,3648.13123,N,12147.21791,W,0.097,0.00,201222,,,D*79
2022-12-20T19:50:38.186Z,1671565838.186 [NAL9602](INFO): GPS fix at 20221220T195037: (36.802187, -121.786965)
2022-12-20T19:50:38.205Z,1671565838.205 [Default:CheckIn:Read_GPS] Stopped
2022-12-20T19:50:38.205Z,1671565838.205 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-20T19:50:45.464Z,1671565845.464 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221220T185823/Courier0028.lzma
2022-12-20T19:50:46.466Z,1671565846.466 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Courier0028.lzma.bak
2022-12-20T19:50:46.466Z,1671565846.466 [DataOverHttps](INFO): SBD MOMSN=17399886
2022-12-20T19:51:02.145Z,1671565862.145 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20221220T185823/Express0029.lzma
2022-12-20T19:51:03.146Z,1671565863.146 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Express0029.lzma.bak
2022-12-20T19:51:03.147Z,1671565863.147 [DataOverHttps](INFO): SBD MOMSN=17399889
2022-12-20T19:51:04.497Z,1671565864.497 [Default:CheckIn:Read_Iridium] Stopped
2022-12-20T19:51:04.497Z,1671565864.497 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-20T19:51:04.497Z,1671565864.497 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-20T19:51:10.990Z,1671565870.990 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-20T19:56:05.116Z,1671566165.116 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-20T19:56:05.117Z,1671566165.117 [Default:CheckIn:C.Wait] Stopped
2022-12-20T19:56:05.117Z,1671566165.117 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T19:56:05.117Z,1671566165.117 [Default:CheckIn:D] Running Loop=1
2022-12-20T19:56:05.527Z,1671566165.527 [Default:CheckIn:D] Stopped
2022-12-20T19:56:05.527Z,1671566165.527 [Default:CheckIn:E] Running Loop=1
2022-12-20T19:56:05.927Z,1671566165.927 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 52.931401 min 
2022-12-20T19:56:05.927Z,1671566165.927 [Default:CheckIn:E] Stopped
2022-12-20T19:56:05.928Z,1671566165.928 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-20T19:56:05.928Z,1671566165.928 [Default:CheckIn] Stopped
2022-12-20T19:56:05.928Z,1671566165.928 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-20T19:56:05.928Z,1671566165.928 [Default:CheckIn](INFO): Running loop #10
2022-12-20T19:56:05.944Z,1671566165.944 [Default:CheckIn] Running Loop=10
2022-12-20T19:56:05.944Z,1671566165.944 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-20T19:56:05.944Z,1671566165.944 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-20T19:56:07.935Z,1671566167.935 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195607.00,A,3648.13103,N,12147.21419,W,0.019,0.00,201222,,,D*7B
2022-12-20T19:56:07.937Z,1671566167.937 [NAL9602](INFO): GPS fix at 20221220T195607: (36.802184, -121.786903)
2022-12-20T19:56:07.947Z,1671566167.947 [Default:CheckIn:Read_GPS] Stopped
2022-12-20T19:56:07.947Z,1671566167.947 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-20T19:56:15.356Z,1671566175.356 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221220T185823/Courier0031.lzma
2022-12-20T19:56:16.358Z,1671566176.358 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Courier0031.lzma.bak
2022-12-20T19:56:16.358Z,1671566176.358 [DataOverHttps](INFO): SBD MOMSN=17399895
2022-12-20T19:56:32.140Z,1671566192.140 [DataOverHttps](INFO): Sending 138 bytes from file Logs/20221220T185823/Express0032.lzma
2022-12-20T19:56:33.142Z,1671566193.142 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Express0032.lzma.bak
2022-12-20T19:56:33.143Z,1671566193.143 [DataOverHttps](INFO): SBD MOMSN=17399899
2022-12-20T19:56:34.619Z,1671566194.619 [Default:CheckIn:Read_Iridium] Stopped
2022-12-20T19:56:34.620Z,1671566194.620 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-20T19:56:34.620Z,1671566194.620 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-20T19:56:38.666Z,1671566198.666 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-12-20T19:56:38.740Z,1671566198.740 [NAL9602](ERROR): received: 
+CSQ:0

OK
2022-12-20T20:01:09.770Z,1671566469.770 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-12-20T20:01:35.243Z,1671566495.243 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-20T20:01:35.243Z,1671566495.243 [Default:CheckIn:C.Wait] Stopped
2022-12-20T20:01:35.243Z,1671566495.243 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T20:01:35.243Z,1671566495.243 [Default:CheckIn:D] Running Loop=1
2022-12-20T20:01:35.636Z,1671566495.636 [Default:CheckIn:D] Stopped
2022-12-20T20:01:35.636Z,1671566495.636 [Default:CheckIn:E] Running Loop=1
2022-12-20T20:01:36.050Z,1671566496.050 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 58.433207 min 
2022-12-20T20:01:36.050Z,1671566496.050 [Default:CheckIn:E] Stopped
2022-12-20T20:01:36.050Z,1671566496.050 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-20T20:01:36.050Z,1671566496.050 [Default:CheckIn] Stopped
2022-12-20T20:01:36.050Z,1671566496.050 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-20T20:01:36.050Z,1671566496.050 [Default:CheckIn](INFO): Running loop #11
2022-12-20T20:01:36.051Z,1671566496.051 [Default:CheckIn] Running Loop=11
2022-12-20T20:01:36.051Z,1671566496.051 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-20T20:01:36.051Z,1671566496.051 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-20T20:01:38.055Z,1671566498.055 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200136.00,A,3648.13370,N,12147.21642,W,0.019,0.00,201222,,,D*7B
2022-12-20T20:01:38.058Z,1671566498.058 [NAL9602](INFO): GPS fix at 20221220T200136: (36.802228, -121.786940)
2022-12-20T20:01:38.068Z,1671566498.068 [Default:CheckIn:Read_GPS] Stopped
2022-12-20T20:01:38.068Z,1671566498.068 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-20T20:01:45.872Z,1671566505.872 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20221220T185823/Courier0034.lzma
2022-12-20T20:01:46.874Z,1671566506.874 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Courier0034.lzma.bak
2022-12-20T20:01:46.874Z,1671566506.874 [DataOverHttps](INFO): SBD MOMSN=17399905
2022-12-20T20:02:02.816Z,1671566522.816 [DataOverHttps](INFO): Sending 214 bytes from file Logs/20221220T185823/Express0035.lzma
2022-12-20T20:02:03.818Z,1671566523.818 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Express0035.lzma.bak
2022-12-20T20:02:03.818Z,1671566523.818 [DataOverHttps](INFO): SBD MOMSN=17399908
2022-12-20T20:02:05.130Z,1671566525.130 [Default:CheckIn:Read_Iridium] Stopped
2022-12-20T20:02:05.130Z,1671566525.130 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-20T20:02:05.130Z,1671566525.130 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-20T20:02:11.187Z,1671566531.187 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-20T20:07:05.792Z,1671566825.792 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-20T20:07:05.792Z,1671566825.792 [Default:CheckIn:C.Wait] Stopped
2022-12-20T20:07:05.792Z,1671566825.792 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T20:07:05.793Z,1671566825.793 [Default:CheckIn:D] Running Loop=1
2022-12-20T20:07:06.196Z,1671566826.196 [Default:CheckIn:D] Stopped
2022-12-20T20:07:06.196Z,1671566826.196 [Default:CheckIn:E] Running Loop=1
2022-12-20T20:07:06.611Z,1671566826.611 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 63.942542 min 
2022-12-20T20:07:06.612Z,1671566826.612 [Default:CheckIn:E] Stopped
2022-12-20T20:07:06.612Z,1671566826.612 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-20T20:07:06.612Z,1671566826.612 [Default:CheckIn] Stopped
2022-12-20T20:07:06.612Z,1671566826.612 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-20T20:07:06.624Z,1671566826.624 [Default:CheckIn](INFO): Running loop #12
2022-12-20T20:07:06.624Z,1671566826.624 [Default:CheckIn] Running Loop=12
2022-12-20T20:07:06.625Z,1671566826.625 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-20T20:07:06.625Z,1671566826.625 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-20T20:07:08.607Z,1671566828.607 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200707.00,A,3648.13319,N,12147.21781,W,0.000,0.00,201222,,,D*76
2022-12-20T20:07:08.618Z,1671566828.618 [NAL9602](INFO): GPS fix at 20221220T200707: (36.802220, -121.786963)
2022-12-20T20:07:08.628Z,1671566828.628 [Default:CheckIn:Read_GPS] Stopped
2022-12-20T20:07:08.628Z,1671566828.628 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-20T20:07:16.220Z,1671566836.220 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221220T185823/Courier0037.lzma
2022-12-20T20:07:17.222Z,1671566837.222 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Courier0037.lzma.bak
2022-12-20T20:07:17.222Z,1671566837.222 [DataOverHttps](INFO): SBD MOMSN=17399912
2022-12-20T20:07:33.332Z,1671566853.332 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20221220T185823/Express0038.lzma
2022-12-20T20:07:34.334Z,1671566854.334 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Express0038.lzma.bak
2022-12-20T20:07:34.334Z,1671566854.334 [DataOverHttps](INFO): SBD MOMSN=17399915
2022-12-20T20:07:35.689Z,1671566855.689 [Default:CheckIn:Read_Iridium] Stopped
2022-12-20T20:07:35.689Z,1671566855.689 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-20T20:07:35.690Z,1671566855.690 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-20T20:07:39.306Z,1671566859.306 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-12-20T20:07:39.384Z,1671566859.384 [NAL9602](ERROR): received: 
+CSQ:0

OK
2022-12-20T20:09:26.774Z,1671566966.774 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T20:09:40.102Z,1671566980.102 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T20:09:53.838Z,1671566993.838 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T20:10:07.170Z,1671567007.170 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T20:10:20.501Z,1671567020.501 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T20:10:33.833Z,1671567033.833 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T20:10:47.635Z,1671567047.635 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T20:11:00.965Z,1671567060.965 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T20:11:14.297Z,1671567074.297 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T20:11:27.629Z,1671567087.629 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T20:11:40.557Z,1671567100.557 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T20:12:11.266Z,1671567131.266 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-12-20T20:12:36.335Z,1671567156.335 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-20T20:12:36.335Z,1671567156.335 [Default:CheckIn:C.Wait] Stopped
2022-12-20T20:12:36.335Z,1671567156.335 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T20:12:36.335Z,1671567156.335 [Default:CheckIn:D] Running Loop=1
2022-12-20T20:12:36.832Z,1671567156.832 [Default:CheckIn:D] Stopped
2022-12-20T20:12:36.832Z,1671567156.832 [Default:CheckIn:E] Running Loop=1
2022-12-20T20:12:37.145Z,1671567157.145 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 69.453149 min 
2022-12-20T20:12:37.145Z,1671567157.145 [Default:CheckIn:E] Stopped
2022-12-20T20:12:37.145Z,1671567157.145 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-20T20:12:37.145Z,1671567157.145 [Default:CheckIn] Stopped
2022-12-20T20:12:37.145Z,1671567157.145 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-20T20:12:37.145Z,1671567157.145 [Default:CheckIn](INFO): Running loop #13
2022-12-20T20:12:37.145Z,1671567157.145 [Default:CheckIn] Running Loop=13
2022-12-20T20:12:37.146Z,1671567157.146 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-20T20:12:37.146Z,1671567157.146 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-20T20:12:39.156Z,1671567159.156 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201237.00,A,3648.13403,N,12147.21708,W,0.039,0.00,201222,,,D*76
2022-12-20T20:12:39.158Z,1671567159.158 [NAL9602](INFO): GPS fix at 20221220T201237: (36.802234, -121.786951)
2022-12-20T20:12:39.177Z,1671567159.177 [Default:CheckIn:Read_GPS] Stopped
2022-12-20T20:12:39.177Z,1671567159.177 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-20T20:12:46.784Z,1671567166.784 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221220T185823/Courier0040.lzma
2022-12-20T20:12:47.787Z,1671567167.787 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Courier0040.lzma.bak
2022-12-20T20:12:47.787Z,1671567167.787 [DataOverHttps](INFO): SBD MOMSN=17399918
2022-12-20T20:13:03.741Z,1671567183.741 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20221220T185823/Express0041.lzma
2022-12-20T20:13:04.742Z,1671567184.742 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Express0041.lzma.bak
2022-12-20T20:13:04.742Z,1671567184.742 [DataOverHttps](INFO): SBD MOMSN=17399921
2022-12-20T20:13:06.221Z,1671567186.221 [Default:CheckIn:Read_Iridium] Stopped
2022-12-20T20:13:06.221Z,1671567186.221 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-20T20:13:06.222Z,1671567186.222 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-20T20:13:11.514Z,1671567191.514 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-20T20:18:06.863Z,1671567486.863 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-20T20:18:06.863Z,1671567486.863 [Default:CheckIn:C.Wait] Stopped
2022-12-20T20:18:06.863Z,1671567486.863 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T20:18:06.863Z,1671567486.863 [Default:CheckIn:D] Running Loop=1
2022-12-20T20:18:07.271Z,1671567487.271 [Default:CheckIn:D] Stopped
2022-12-20T20:18:07.272Z,1671567487.272 [Default:CheckIn:E] Running Loop=1
2022-12-20T20:18:07.673Z,1671567487.673 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 74.960465 min 
2022-12-20T20:18:07.673Z,1671567487.673 [Default:CheckIn:E] Stopped
2022-12-20T20:18:07.674Z,1671567487.674 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-20T20:18:07.674Z,1671567487.674 [Default:CheckIn] Stopped
2022-12-20T20:18:07.674Z,1671567487.674 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-20T20:18:07.674Z,1671567487.674 [Default:CheckIn](INFO): Running loop #14
2022-12-20T20:18:07.674Z,1671567487.674 [Default:CheckIn] Running Loop=14
2022-12-20T20:18:07.674Z,1671567487.674 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-20T20:18:07.674Z,1671567487.674 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-20T20:18:09.682Z,1671567489.682 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201808.00,A,3648.13073,N,12147.21619,W,0.019,0.00,201222,,,D*70
2022-12-20T20:18:09.693Z,1671567489.693 [NAL9602](INFO): GPS fix at 20221220T201808: (36.802179, -121.786936)
2022-12-20T20:18:09.713Z,1671567489.713 [Default:CheckIn:Read_GPS] Stopped
2022-12-20T20:18:09.713Z,1671567489.713 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-20T20:18:11.699Z,1671567491.699 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file).
2022-12-20T20:18:17.052Z,1671567497.052 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221220T185823/Courier0043.lzma
2022-12-20T20:18:18.054Z,1671567498.054 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Courier0043.lzma.bak
2022-12-20T20:18:18.054Z,1671567498.054 [DataOverHttps](INFO): SBD MOMSN=17399925
2022-12-20T20:18:33.984Z,1671567513.984 [DataOverHttps](INFO): Sending 138 bytes from file Logs/20221220T185823/Express0044.lzma
2022-12-20T20:18:34.987Z,1671567514.987 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Express0044.lzma.bak
2022-12-20T20:18:34.987Z,1671567514.987 [DataOverHttps](INFO): SBD MOMSN=17399928
2022-12-20T20:18:36.407Z,1671567516.407 [Default:CheckIn:Read_Iridium] Stopped
2022-12-20T20:18:36.408Z,1671567516.408 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-20T20:18:36.408Z,1671567516.408 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-20T20:18:40.454Z,1671567520.454 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-12-20T20:18:40.536Z,1671567520.536 [NAL9602](ERROR): received: 
+CSQ:0

OK
2022-12-20T20:19:12.377Z,1671567552.377 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T20:19:18.606Z,1671567558.606 [DataOverHttps](IMPORTANT): SBD MTMSN=20221220T201916
2022-12-20T20:19:25.710Z,1671567565.710 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T20:19:26.193Z,1671567566.193 [DataOverHttps](INFO): Received command: sched asap "ibit" 2er3f 1 2
2022-12-20T20:19:26.231Z,1671567566.231 [CommandExec](IMPORTANT): got command schedule asap "ibit" 2er3f 1 2.000000
2022-12-20T20:19:26.231Z,1671567566.231 [CommandExec](IMPORTANT): Scheduling command #1 of 2 with id=2er3f
2022-12-20T20:19:26.232Z,1671567566.232 [CommandExec](IMPORTANT): Scheduled #1 (#1 of 2 with id='2er3f'): "ibit", ASAP
2022-12-20T20:19:27.194Z,1671567567.194 [DataOverHttps](IMPORTANT): SBD MTMSN=20221220T201925
2022-12-20T20:19:34.716Z,1671567574.716 [DataOverHttps](INFO): Received command: sched asap "" 2er3f 2 2
2022-12-20T20:19:34.783Z,1671567574.783 [CommandExec](IMPORTANT): got command schedule asap "" 2er3f 2 2.000000
2022-12-20T20:19:34.783Z,1671567574.783 [CommandExec](IMPORTANT): Scheduling command #2 of 2 with id=2er3f
2022-12-20T20:19:34.784Z,1671567574.784 [CommandExec](IMPORTANT): Scheduled #2 (#2 of 2 with id='2er3f'): "", ASAP
2022-12-20T20:19:34.885Z,1671567574.885 [CommandExec](IMPORTANT): got command ibit
2022-12-20T20:19:35.051Z,1671567575.051 [IBIT](IMPORTANT): Beginning Initiated BIT
2022-12-20T20:19:35.051Z,1671567575.051 [IBIT](IMPORTANT): Beginning control surface checks.
2022-12-20T20:19:35.055Z,1671567575.055 [CBIT](IMPORTANT): Beginning ground fault scan
2022-12-20T20:19:39.042Z,1671567579.042 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T20:19:46.033Z,1671567586.033 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.006849
CHAN A1 (24V): -0.008296
CHAN A2 (12V): -0.004849
CHAN A3 (5V): -0.002243
CHAN B0 (3.3V): -0.000754
CHAN B1 (3.15aV): -0.001437
CHAN B2 (3.15bV): -0.001418
CHAN B3 (GND): -0.000200
OPEN: 0.004261
Full Scale: +/- 1 mA
2022-12-20T20:19:52.380Z,1671567592.380 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T20:20:05.704Z,1671567605.704 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T20:20:19.441Z,1671567619.441 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T20:20:32.773Z,1671567632.773 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T20:20:46.104Z,1671567646.104 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T20:20:59.436Z,1671567659.436 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T20:21:12.364Z,1671567672.364 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T20:21:25.862Z,1671567685.862 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired.
2022-12-20T20:21:26.108Z,1671567686.108 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T20:21:26.171Z,1671567686.171 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 314.618988
Voltage: 16.294001
2022-12-20T20:21:26.171Z,1671567686.171 [IBIT](IMPORTANT): batteryCapacityThreshold: 30.000000 Ah
2022-12-20T20:21:26.171Z,1671567686.171 [IBIT](IMPORTANT): batteryVoltageThreshold: 12.000000 V
2022-12-20T20:21:26.563Z,1671567686.563 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2022-12-20T20:21:26.563Z,1671567686.563 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2022-12-20T20:21:26.563Z,1671567686.563 [IBIT](IMPORTANT): Pressure:9.153417 PSI
2022-12-20T20:21:26.564Z,1671567686.564 [IBIT](IMPORTANT): Humidity:12.074228 %
2022-12-20T20:21:26.953Z,1671567686.953 [IBIT](IMPORTANT): Vehicle Pitch:-2.250316 degrees
2022-12-20T20:21:26.953Z,1671567686.953 [IBIT](IMPORTANT): Vehicle  Roll:-2.340489 degrees
2022-12-20T20:21:26.953Z,1671567686.953 [IBIT](IMPORTANT): Vehicle  Heading:64.474937 degrees
2022-12-20T20:21:27.333Z,1671567687.333 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2022-12-20T20:21:27.334Z,1671567687.334 [IBIT](IMPORTANT): buoyancyNeutral: 324.282104 cc
2022-12-20T20:21:27.334Z,1671567687.334 [IBIT](IMPORTANT): massDefault: 2.000000 cm
2022-12-20T20:21:27.334Z,1671567687.334 [IBIT](IMPORTANT): stopDepth: 275.000000 m
2022-12-20T20:21:27.334Z,1671567687.334 [IBIT](IMPORTANT): abortDepth: 300.000000 m
2022-12-20T20:21:27.334Z,1671567687.334 [IBIT](IMPORTANT): IBIT FAILED
2022-12-20T20:23:12.418Z,1671567792.418 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-12-20T20:23:37.063Z,1671567817.063 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-20T20:23:37.063Z,1671567817.063 [Default:CheckIn:C.Wait] Stopped
2022-12-20T20:23:37.063Z,1671567817.063 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T20:23:37.063Z,1671567817.063 [Default:CheckIn:D] Running Loop=1
2022-12-20T20:23:37.469Z,1671567817.469 [Default:CheckIn:D] Stopped
2022-12-20T20:23:37.469Z,1671567817.469 [Default:CheckIn:E] Running Loop=1
2022-12-20T20:23:37.864Z,1671567817.864 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 80.463753 min 
2022-12-20T20:23:37.864Z,1671567817.864 [Default:CheckIn:E] Stopped
2022-12-20T20:23:37.864Z,1671567817.864 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-20T20:23:37.864Z,1671567817.864 [Default:CheckIn] Stopped
2022-12-20T20:23:37.864Z,1671567817.864 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-20T20:23:37.865Z,1671567817.865 [Default:CheckIn](INFO): Running loop #15
2022-12-20T20:23:37.865Z,1671567817.865 [Default:CheckIn] Running Loop=15
2022-12-20T20:23:37.865Z,1671567817.865 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-20T20:23:37.865Z,1671567817.865 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-20T20:23:39.875Z,1671567819.875 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202337.00,A,3648.13174,N,12147.21699,W,0.000,0.00,201222,,,D*72
2022-12-20T20:23:39.882Z,1671567819.882 [NAL9602](INFO): GPS fix at 20221220T202337: (36.802196, -121.786950)
2022-12-20T20:23:39.900Z,1671567819.900 [Default:CheckIn:Read_GPS] Stopped
2022-12-20T20:23:39.900Z,1671567819.900 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-20T20:23:43.917Z,1671567823.917 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221220T185823/Courier0046.lzma
2022-12-20T20:23:44.646Z,1671567824.646 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Courier0046.lzma.bak
2022-12-20T20:23:44.646Z,1671567824.646 [DataOverHttps](INFO): SBD MOMSN=17399935
2022-12-20T20:24:00.809Z,1671567840.809 [DataOverHttps](INFO): Sending 985 bytes from file Logs/20221220T185823/Express0047.lzma
2022-12-20T20:24:01.810Z,1671567841.810 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Express0047.lzma.bak
2022-12-20T20:24:01.810Z,1671567841.810 [DataOverHttps](INFO): SBD MOMSN=17399938
2022-12-20T20:24:12.762Z,1671567852.762 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-20T20:24:17.676Z,1671567857.676 [DataOverHttps](INFO): Sending 70 bytes from file Logs/20221220T185823/Express0050.lzma
2022-12-20T20:24:18.678Z,1671567858.678 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Express0050.lzma.bak
2022-12-20T20:24:18.678Z,1671567858.678 [DataOverHttps](INFO): SBD MOMSN=17399972
2022-12-20T20:24:20.049Z,1671567860.049 [Default:CheckIn:Read_Iridium] Stopped
2022-12-20T20:24:20.049Z,1671567860.049 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-20T20:24:20.049Z,1671567860.049 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-20T20:26:05.928Z,1671567965.928 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file).
2022-12-20T20:28:46.724Z,1671568126.724 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T20:29:00.058Z,1671568140.058 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T20:29:13.438Z,1671568153.438 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T20:29:20.737Z,1671568160.737 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-20T20:29:20.737Z,1671568160.737 [Default:CheckIn:C.Wait] Stopped
2022-12-20T20:29:20.737Z,1671568160.737 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T20:29:20.737Z,1671568160.737 [Default:CheckIn:D] Running Loop=1
2022-12-20T20:29:21.127Z,1671568161.127 [Default:CheckIn:D] Stopped
2022-12-20T20:29:21.127Z,1671568161.127 [Default:CheckIn:E] Running Loop=1
2022-12-20T20:29:21.529Z,1671568161.529 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 86.191390 min 
2022-12-20T20:29:21.529Z,1671568161.529 [Default:CheckIn:E] Stopped
2022-12-20T20:29:21.529Z,1671568161.529 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-20T20:29:21.529Z,1671568161.529 [Default:CheckIn] Stopped
2022-12-20T20:29:21.529Z,1671568161.529 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-20T20:29:21.529Z,1671568161.529 [Default:CheckIn](INFO): Running loop #16
2022-12-20T20:29:21.529Z,1671568161.529 [Default:CheckIn] Running Loop=16
2022-12-20T20:29:21.529Z,1671568161.529 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-20T20:29:21.529Z,1671568161.529 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-20T20:29:23.540Z,1671568163.540 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202921.00,A,3648.13124,N,12147.21743,W,0.039,0.00,201222,,,D*76
2022-12-20T20:29:23.543Z,1671568163.543 [NAL9602](INFO): GPS fix at 20221220T202921: (36.802187, -121.786957)
2022-12-20T20:29:23.553Z,1671568163.553 [Default:CheckIn:Read_GPS] Stopped
2022-12-20T20:29:23.553Z,1671568163.553 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-20T20:29:27.172Z,1671568167.172 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T20:29:31.376Z,1671568171.376 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221220T185823/Courier0052.lzma
2022-12-20T20:29:32.379Z,1671568172.379 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Courier0052.lzma.bak
2022-12-20T20:29:32.379Z,1671568172.379 [DataOverHttps](INFO): SBD MOMSN=17399975
2022-12-20T20:29:40.510Z,1671568180.510 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T20:29:48.696Z,1671568188.696 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20221220T185823/Express0053.lzma
2022-12-20T20:29:49.698Z,1671568189.698 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Express0053.lzma.bak
2022-12-20T20:29:49.698Z,1671568189.698 [DataOverHttps](INFO): SBD MOMSN=17399978
2022-12-20T20:29:51.036Z,1671568191.036 [Default:CheckIn:Read_Iridium] Stopped
2022-12-20T20:29:51.036Z,1671568191.036 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-20T20:29:51.036Z,1671568191.036 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-20T20:29:53.847Z,1671568193.847 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T20:29:54.266Z,1671568194.266 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-12-20T20:29:54.344Z,1671568194.344 [NAL9602](ERROR): received: 
+CSQ:0

OK
2022-12-20T20:30:07.172Z,1671568207.172 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T20:30:20.909Z,1671568220.909 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T20:30:34.257Z,1671568234.257 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T20:30:47.575Z,1671568247.575 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T20:31:00.905Z,1671568260.905 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T20:34:25.687Z,1671568465.687 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-12-20T20:34:51.576Z,1671568491.576 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-20T20:34:51.576Z,1671568491.576 [Default:CheckIn:C.Wait] Stopped
2022-12-20T20:34:51.577Z,1671568491.577 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T20:34:51.577Z,1671568491.577 [Default:CheckIn:D] Running Loop=1
2022-12-20T20:34:51.988Z,1671568491.988 [Default:CheckIn:D] Stopped
2022-12-20T20:34:51.989Z,1671568491.989 [Default:CheckIn:E] Running Loop=1
2022-12-20T20:34:52.441Z,1671568492.441 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 91.705754 min 
2022-12-20T20:34:52.441Z,1671568492.441 [Default:CheckIn:E] Stopped
2022-12-20T20:34:52.457Z,1671568492.457 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-20T20:34:52.457Z,1671568492.457 [Default:CheckIn] Stopped
2022-12-20T20:34:52.457Z,1671568492.457 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-20T20:34:52.458Z,1671568492.458 [Default:CheckIn](INFO): Running loop #17
2022-12-20T20:34:52.458Z,1671568492.458 [Default:CheckIn] Running Loop=17
2022-12-20T20:34:52.458Z,1671568492.458 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-20T20:34:52.458Z,1671568492.458 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-20T20:34:54.402Z,1671568494.402 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203453.00,A,3648.13370,N,12147.21738,W,0.039,0.00,201222,,,D*70
2022-12-20T20:34:54.405Z,1671568494.405 [NAL9602](INFO): GPS fix at 20221220T203453: (36.802228, -121.786956)
2022-12-20T20:34:54.420Z,1671568494.420 [Default:CheckIn:Read_GPS] Stopped
2022-12-20T20:34:54.420Z,1671568494.420 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-20T20:35:01.481Z,1671568501.481 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221220T185823/Courier0055.lzma
2022-12-20T20:35:02.483Z,1671568502.483 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Courier0055.lzma.bak
2022-12-20T20:35:02.483Z,1671568502.483 [DataOverHttps](INFO): SBD MOMSN=17399981
2022-12-20T20:35:21.154Z,1671568521.154 [DataOverHttps](INFO): Sending 217 bytes from file Logs/20221220T185823/Express0056.lzma
2022-12-20T20:35:22.155Z,1671568522.155 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Express0056.lzma.bak
2022-12-20T20:35:22.155Z,1671568522.155 [DataOverHttps](INFO): SBD MOMSN=17399984
2022-12-20T20:35:23.557Z,1671568523.557 [Default:CheckIn:Read_Iridium] Stopped
2022-12-20T20:35:23.557Z,1671568523.557 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-20T20:35:23.557Z,1671568523.557 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-20T20:35:26.775Z,1671568526.775 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-20T20:38:00.341Z,1671568680.341 [BPC1](INFO): Calculating totals. Valid battery stick count: 50. Valid reserve battery stick count: 5.
2022-12-20T20:38:00.343Z,1671568680.343 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle.
2022-12-20T20:40:24.180Z,1671568824.180 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-20T20:40:24.180Z,1671568824.180 [Default:CheckIn:C.Wait] Stopped
2022-12-20T20:40:24.180Z,1671568824.180 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T20:40:24.180Z,1671568824.180 [Default:CheckIn:D] Running Loop=1
2022-12-20T20:40:24.581Z,1671568824.581 [Default:CheckIn:D] Stopped
2022-12-20T20:40:24.581Z,1671568824.581 [Default:CheckIn:E] Running Loop=1
2022-12-20T20:40:24.997Z,1671568824.997 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 97.248966 min 
2022-12-20T20:40:24.997Z,1671568824.997 [Default:CheckIn:E] Stopped
2022-12-20T20:40:24.997Z,1671568824.997 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-20T20:40:24.997Z,1671568824.997 [Default:CheckIn] Stopped
2022-12-20T20:40:24.997Z,1671568824.997 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-20T20:40:24.998Z,1671568824.998 [Default:CheckIn](INFO): Running loop #18
2022-12-20T20:40:24.998Z,1671568824.998 [Default:CheckIn] Running Loop=18
2022-12-20T20:40:24.998Z,1671568824.998 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-20T20:40:24.998Z,1671568824.998 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-20T20:40:26.997Z,1671568826.997 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204026.00,A,3648.12988,N,12147.21874,W,0.019,0.00,201222,,,D*78
2022-12-20T20:40:26.999Z,1671568826.999 [NAL9602](INFO): GPS fix at 20221220T204026: (36.802165, -121.786979)
2022-12-20T20:40:27.009Z,1671568827.009 [Default:CheckIn:Read_GPS] Stopped
2022-12-20T20:40:27.009Z,1671568827.009 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-20T20:40:35.569Z,1671568835.569 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20221220T185823/Courier0058.lzma
2022-12-20T20:40:36.571Z,1671568836.571 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Courier0058.lzma.bak
2022-12-20T20:40:36.572Z,1671568836.572 [DataOverHttps](INFO): SBD MOMSN=17399996
2022-12-20T20:40:54.717Z,1671568854.717 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20221220T185823/Express0059.lzma
2022-12-20T20:40:55.719Z,1671568855.719 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Express0059.lzma.bak
2022-12-20T20:40:55.719Z,1671568855.719 [DataOverHttps](INFO): SBD MOMSN=17399999
2022-12-20T20:40:56.941Z,1671568856.941 [Default:CheckIn:Read_Iridium] Stopped
2022-12-20T20:40:56.941Z,1671568856.941 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-20T20:40:56.941Z,1671568856.941 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-20T20:40:57.732Z,1671568857.732 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-12-20T20:40:57.805Z,1671568857.805 [NAL9602](ERROR): received: 
+CSQ:0

OK
2022-12-20T20:45:29.712Z,1671569129.712 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-12-20T20:45:57.612Z,1671569157.612 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-20T20:45:57.612Z,1671569157.612 [Default:CheckIn:C.Wait] Stopped
2022-12-20T20:45:57.612Z,1671569157.612 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T20:45:57.612Z,1671569157.612 [Default:CheckIn:D] Running Loop=1
2022-12-20T20:45:58.003Z,1671569158.003 [Default:CheckIn:D] Stopped
2022-12-20T20:45:58.003Z,1671569158.003 [Default:CheckIn:E] Running Loop=1
2022-12-20T20:45:58.404Z,1671569158.404 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 102.805981 min 
2022-12-20T20:45:58.405Z,1671569158.405 [Default:CheckIn:E] Stopped
2022-12-20T20:45:58.405Z,1671569158.405 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-20T20:45:58.405Z,1671569158.405 [Default:CheckIn] Stopped
2022-12-20T20:45:58.405Z,1671569158.405 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-20T20:45:58.405Z,1671569158.405 [Default:CheckIn](INFO): Running loop #19
2022-12-20T20:45:58.405Z,1671569158.405 [Default:CheckIn] Running Loop=19
2022-12-20T20:45:58.405Z,1671569158.405 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-20T20:45:58.406Z,1671569158.406 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-20T20:46:00.416Z,1671569160.416 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204559.00,A,3648.13280,N,12147.21712,W,0.019,0.00,201222,,,D*78
2022-12-20T20:46:00.427Z,1671569160.427 [NAL9602](INFO): GPS fix at 20221220T204559: (36.802213, -121.786952)
2022-12-20T20:46:00.438Z,1671569160.438 [Default:CheckIn:Read_GPS] Stopped
2022-12-20T20:46:00.438Z,1671569160.438 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-20T20:46:08.077Z,1671569168.077 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221220T185823/Courier0061.lzma
2022-12-20T20:46:09.079Z,1671569169.079 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Courier0061.lzma.bak
2022-12-20T20:46:09.079Z,1671569169.079 [DataOverHttps](INFO): SBD MOMSN=17400003
2022-12-20T20:46:24.777Z,1671569184.777 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20221220T185823/Express0062.lzma
2022-12-20T20:46:25.779Z,1671569185.779 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Express0062.lzma.bak
2022-12-20T20:46:25.779Z,1671569185.779 [DataOverHttps](INFO): SBD MOMSN=17400007
2022-12-20T20:46:27.097Z,1671569187.097 [Default:CheckIn:Read_Iridium] Stopped
2022-12-20T20:46:27.097Z,1671569187.097 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-20T20:46:27.097Z,1671569187.097 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-20T20:46:33.138Z,1671569193.138 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-20T20:51:27.637Z,1671569487.637 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-20T20:51:27.637Z,1671569487.637 [Default:CheckIn:C.Wait] Stopped
2022-12-20T20:51:27.637Z,1671569487.637 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T20:51:27.637Z,1671569487.637 [Default:CheckIn:D] Running Loop=1
2022-12-20T20:51:28.036Z,1671569488.036 [Default:CheckIn:D] Stopped
2022-12-20T20:51:28.036Z,1671569488.036 [Default:CheckIn:E] Running Loop=1
2022-12-20T20:51:28.442Z,1671569488.442 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 108.306535 min 
2022-12-20T20:51:28.443Z,1671569488.443 [Default:CheckIn:E] Stopped
2022-12-20T20:51:28.443Z,1671569488.443 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-20T20:51:28.443Z,1671569488.443 [Default:CheckIn] Stopped
2022-12-20T20:51:28.443Z,1671569488.443 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-20T20:51:28.443Z,1671569488.443 [Default:CheckIn](INFO): Running loop #20
2022-12-20T20:51:28.443Z,1671569488.443 [Default:CheckIn] Running Loop=20
2022-12-20T20:51:28.443Z,1671569488.443 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-20T20:51:28.443Z,1671569488.443 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-20T20:51:30.457Z,1671569490.457 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205129.00,A,3648.13004,N,12147.21471,W,0.039,109.67,201222,,,D*79
2022-12-20T20:51:30.467Z,1671569490.467 [NAL9602](INFO): GPS fix at 20221220T205129: (36.802167, -121.786912)
2022-12-20T20:51:30.477Z,1671569490.477 [Default:CheckIn:Read_GPS] Stopped
2022-12-20T20:51:30.477Z,1671569490.477 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-20T20:51:37.801Z,1671569497.801 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221220T185823/Courier0064.lzma
2022-12-20T20:51:38.804Z,1671569498.804 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Courier0064.lzma.bak
2022-12-20T20:51:38.804Z,1671569498.804 [DataOverHttps](INFO): SBD MOMSN=17400011
2022-12-20T20:51:54.677Z,1671569514.677 [DataOverHttps](INFO): Sending 141 bytes from file Logs/20221220T185823/Express0065.lzma
2022-12-20T20:51:55.680Z,1671569515.680 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Express0065.lzma.bak
2022-12-20T20:51:55.680Z,1671569515.680 [DataOverHttps](INFO): SBD MOMSN=17400014
2022-12-20T20:51:57.134Z,1671569517.134 [Default:CheckIn:Read_Iridium] Stopped
2022-12-20T20:51:57.134Z,1671569517.134 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-20T20:51:57.134Z,1671569517.134 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-20T20:52:01.159Z,1671569521.159 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-12-20T20:52:01.242Z,1671569521.242 [NAL9602](ERROR): received: 
+CSQ:0

OK
2022-12-20T20:56:32.759Z,1671569792.759 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-12-20T20:56:57.796Z,1671569817.796 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-20T20:56:57.796Z,1671569817.796 [Default:CheckIn:C.Wait] Stopped
2022-12-20T20:56:57.796Z,1671569817.796 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T20:56:57.797Z,1671569817.796 [Default:CheckIn:D] Running Loop=1
2022-12-20T20:56:58.205Z,1671569818.205 [Default:CheckIn:D] Stopped
2022-12-20T20:56:58.205Z,1671569818.205 [Default:CheckIn:E] Running Loop=1
2022-12-20T20:56:58.596Z,1671569818.596 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 113.809351 min 
2022-12-20T20:56:58.596Z,1671569818.596 [Default:CheckIn:E] Stopped
2022-12-20T20:56:58.596Z,1671569818.596 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-20T20:56:58.596Z,1671569818.596 [Default:CheckIn] Stopped
2022-12-20T20:56:58.596Z,1671569818.596 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-20T20:56:58.596Z,1671569818.596 [Default:CheckIn](INFO): Running loop #21
2022-12-20T20:56:58.597Z,1671569818.597 [Default:CheckIn] Running Loop=21
2022-12-20T20:56:58.597Z,1671569818.597 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-20T20:56:58.597Z,1671569818.597 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-20T20:57:00.616Z,1671569820.616 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205659.00,A,3648.13076,N,12147.21612,W,0.019,109.67,201222,,,D*79
2022-12-20T20:57:00.619Z,1671569820.619 [NAL9602](INFO): GPS fix at 20221220T205659: (36.802179, -121.786935)
2022-12-20T20:57:00.629Z,1671569820.629 [Default:CheckIn:Read_GPS] Stopped
2022-12-20T20:57:00.629Z,1671569820.629 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-20T20:57:10.945Z,1671569830.945 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20221220T185823/Courier0067.lzma
2022-12-20T20:57:11.948Z,1671569831.948 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Courier0067.lzma.bak
2022-12-20T20:57:11.948Z,1671569831.948 [DataOverHttps](INFO): SBD MOMSN=17400019
2022-12-20T20:57:27.766Z,1671569847.766 [DataOverHttps](INFO): Sending 218 bytes from file Logs/20221220T185823/Express0068.lzma
2022-12-20T20:57:28.768Z,1671569848.768 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Express0068.lzma.bak
2022-12-20T20:57:28.768Z,1671569848.768 [DataOverHttps](INFO): SBD MOMSN=17400022
2022-12-20T20:57:30.180Z,1671569850.180 [Default:CheckIn:Read_Iridium] Stopped
2022-12-20T20:57:30.180Z,1671569850.180 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-20T20:57:30.180Z,1671569850.180 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-20T20:57:32.999Z,1671569852.999 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-20T21:02:30.830Z,1671570150.830 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-20T21:02:30.831Z,1671570150.831 [Default:CheckIn:C.Wait] Stopped
2022-12-20T21:02:30.831Z,1671570150.831 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T21:02:30.831Z,1671570150.831 [Default:CheckIn:D] Running Loop=1
2022-12-20T21:02:31.228Z,1671570151.228 [Default:CheckIn:D] Stopped
2022-12-20T21:02:31.228Z,1671570151.228 [Default:CheckIn:E] Running Loop=1
2022-12-20T21:02:31.642Z,1671570151.642 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 119.359741 min 
2022-12-20T21:02:31.642Z,1671570151.642 [Default:CheckIn:E] Stopped
2022-12-20T21:02:31.643Z,1671570151.643 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-20T21:02:31.643Z,1671570151.643 [Default:CheckIn] Stopped
2022-12-20T21:02:31.643Z,1671570151.643 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-20T21:02:31.643Z,1671570151.643 [Default:CheckIn](INFO): Running loop #22
2022-12-20T21:02:31.643Z,1671570151.643 [Default:CheckIn] Running Loop=22
2022-12-20T21:02:31.643Z,1671570151.643 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-20T21:02:31.643Z,1671570151.643 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-20T21:02:33.645Z,1671570153.645 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210232.00,A,3648.13052,N,12147.21311,W,0.019,109.67,201222,,,D*74
2022-12-20T21:02:33.647Z,1671570153.647 [NAL9602](INFO): GPS fix at 20221220T210232: (36.802175, -121.786885)
2022-12-20T21:02:33.690Z,1671570153.690 [Default:CheckIn:Read_GPS] Stopped
2022-12-20T21:02:33.691Z,1671570153.691 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-20T21:02:44.277Z,1671570164.277 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221220T185823/Courier0070.lzma
2022-12-20T21:02:45.280Z,1671570165.280 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Courier0070.lzma.bak
2022-12-20T21:02:45.280Z,1671570165.280 [DataOverHttps](INFO): SBD MOMSN=17400026
2022-12-20T21:03:01.113Z,1671570181.113 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20221220T185823/Express0071.lzma
2022-12-20T21:03:02.116Z,1671570182.116 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Express0071.lzma.bak
2022-12-20T21:03:02.116Z,1671570182.116 [DataOverHttps](INFO): SBD MOMSN=17400029
2022-12-20T21:03:03.402Z,1671570183.402 [Default:CheckIn:Read_Iridium] Stopped
2022-12-20T21:03:03.402Z,1671570183.402 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-20T21:03:03.402Z,1671570183.402 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-20T21:03:04.191Z,1671570184.191 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-12-20T21:03:04.274Z,1671570184.274 [NAL9602](ERROR): received: 
+CSQ:0

OK
2022-12-20T21:07:35.764Z,1671570455.764 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-12-20T21:08:04.048Z,1671570484.048 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-20T21:08:04.048Z,1671570484.048 [Default:CheckIn:C.Wait] Stopped
2022-12-20T21:08:04.048Z,1671570484.048 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T21:08:04.049Z,1671570484.049 [Default:CheckIn:D] Running Loop=1
2022-12-20T21:08:04.450Z,1671570484.450 [Default:CheckIn:D] Stopped
2022-12-20T21:08:04.450Z,1671570484.450 [Default:CheckIn:E] Running Loop=1
2022-12-20T21:08:04.868Z,1671570484.868 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 124.913444 min 
2022-12-20T21:08:04.868Z,1671570484.868 [Default:CheckIn:E] Stopped
2022-12-20T21:08:04.868Z,1671570484.868 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-20T21:08:04.869Z,1671570484.869 [Default:CheckIn] Stopped
2022-12-20T21:08:04.869Z,1671570484.869 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-20T21:08:04.869Z,1671570484.869 [Default:CheckIn](INFO): Running loop #23
2022-12-20T21:08:04.869Z,1671570484.869 [Default:CheckIn] Running Loop=23
2022-12-20T21:08:04.869Z,1671570484.869 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-20T21:08:04.869Z,1671570484.869 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-20T21:08:06.868Z,1671570486.868 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210805.00,A,3648.13110,N,12147.21292,W,0.058,109.67,201222,,,D*72
2022-12-20T21:08:06.871Z,1671570486.871 [NAL9602](INFO): GPS fix at 20221220T210805: (36.802185, -121.786882)
2022-12-20T21:08:06.881Z,1671570486.881 [Default:CheckIn:Read_GPS] Stopped
2022-12-20T21:08:06.901Z,1671570486.901 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-20T21:08:14.149Z,1671570494.149 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221220T185823/Courier0073.lzma
2022-12-20T21:08:15.152Z,1671570495.152 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Courier0073.lzma.bak
2022-12-20T21:08:15.152Z,1671570495.152 [DataOverHttps](INFO): SBD MOMSN=17400032
2022-12-20T21:08:31.050Z,1671570511.050 [DataOverHttps](INFO): Sending 217 bytes from file Logs/20221220T185823/Express0074.lzma
2022-12-20T21:08:32.052Z,1671570512.052 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Express0074.lzma.bak
2022-12-20T21:08:32.052Z,1671570512.052 [DataOverHttps](INFO): SBD MOMSN=17400035
2022-12-20T21:08:33.159Z,1671570513.159 [Default:CheckIn:Read_Iridium] Stopped
2022-12-20T21:08:33.159Z,1671570513.159 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-20T21:08:33.159Z,1671570513.159 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-20T21:08:39.223Z,1671570519.223 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-20T21:13:33.641Z,1671570813.641 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-20T21:13:33.642Z,1671570813.642 [Default:CheckIn:C.Wait] Stopped
2022-12-20T21:13:33.642Z,1671570813.642 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T21:13:33.642Z,1671570813.642 [Default:CheckIn:D] Running Loop=1
2022-12-20T21:13:34.010Z,1671570814.010 [Default:CheckIn:D] Stopped
2022-12-20T21:13:34.010Z,1671570814.010 [Default:CheckIn:E] Running Loop=1
2022-12-20T21:13:34.424Z,1671570814.424 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 130.406112 min 
2022-12-20T21:13:34.424Z,1671570814.424 [Default:CheckIn:E] Stopped
2022-12-20T21:13:34.424Z,1671570814.424 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-20T21:13:34.424Z,1671570814.424 [Default:CheckIn] Stopped
2022-12-20T21:13:34.424Z,1671570814.424 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-20T21:13:34.424Z,1671570814.424 [Default:CheckIn](INFO): Running loop #24
2022-12-20T21:13:34.424Z,1671570814.424 [Default:CheckIn] Running Loop=24
2022-12-20T21:13:34.425Z,1671570814.425 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-20T21:13:34.425Z,1671570814.425 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-20T21:13:36.426Z,1671570816.426 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211335.00,A,3648.13234,N,12147.21476,W,0.019,109.67,201222,,,D*77
2022-12-20T21:13:36.429Z,1671570816.429 [NAL9602](INFO): GPS fix at 20221220T211335: (36.802206, -121.786913)
2022-12-20T21:13:36.459Z,1671570816.459 [Default:CheckIn:Read_GPS] Stopped
2022-12-20T21:13:36.459Z,1671570816.459 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-20T21:13:44.088Z,1671570824.088 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221220T185823/Courier0076.lzma
2022-12-20T21:13:45.091Z,1671570825.091 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Courier0076.lzma.bak
2022-12-20T21:13:45.091Z,1671570825.091 [DataOverHttps](INFO): SBD MOMSN=17400039
2022-12-20T21:14:01.049Z,1671570841.049 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20221220T185823/Express0077.lzma
2022-12-20T21:14:02.051Z,1671570842.051 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Express0077.lzma.bak
2022-12-20T21:14:02.051Z,1671570842.051 [DataOverHttps](INFO): SBD MOMSN=17400042
2022-12-20T21:14:03.516Z,1671570843.516 [Default:CheckIn:Read_Iridium] Stopped
2022-12-20T21:14:03.516Z,1671570843.516 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-20T21:14:03.516Z,1671570843.516 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-20T21:14:07.134Z,1671570847.134 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-12-20T21:14:07.217Z,1671570847.217 [NAL9602](ERROR): received: 
+CSQ:0

OK
2022-12-20T21:18:38.665Z,1671571118.665 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-12-20T21:19:04.131Z,1671571144.131 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-20T21:19:04.131Z,1671571144.131 [Default:CheckIn:C.Wait] Stopped
2022-12-20T21:19:04.131Z,1671571144.131 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T21:19:04.132Z,1671571144.132 [Default:CheckIn:D] Running Loop=1
2022-12-20T21:19:04.544Z,1671571144.544 [Default:CheckIn:D] Stopped
2022-12-20T21:19:04.544Z,1671571144.544 [Default:CheckIn:E] Running Loop=1
2022-12-20T21:19:04.956Z,1671571144.956 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 135.915007 min 
2022-12-20T21:19:04.956Z,1671571144.956 [Default:CheckIn:E] Stopped
2022-12-20T21:19:04.956Z,1671571144.956 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-20T21:19:04.956Z,1671571144.956 [Default:CheckIn] Stopped
2022-12-20T21:19:04.956Z,1671571144.956 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-20T21:19:04.969Z,1671571144.969 [Default:CheckIn](INFO): Running loop #25
2022-12-20T21:19:04.969Z,1671571144.969 [Default:CheckIn] Running Loop=25
2022-12-20T21:19:04.969Z,1671571144.969 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-20T21:19:04.969Z,1671571144.969 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-20T21:19:06.948Z,1671571146.948 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211905.00,A,3648.13178,N,12147.21362,W,0.019,109.67,201222,,,D*77
2022-12-20T21:19:06.950Z,1671571146.950 [NAL9602](INFO): GPS fix at 20221220T211905: (36.802196, -121.786894)
2022-12-20T21:19:06.969Z,1671571146.969 [Default:CheckIn:Read_GPS] Stopped
2022-12-20T21:19:06.970Z,1671571146.970 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-20T21:19:14.980Z,1671571154.980 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221220T185823/Courier0079.lzma
2022-12-20T21:19:15.983Z,1671571155.983 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Courier0079.lzma.bak
2022-12-20T21:19:15.983Z,1671571155.983 [DataOverHttps](INFO): SBD MOMSN=17400045
2022-12-20T21:19:31.893Z,1671571171.893 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20221220T185823/Express0080.lzma
2022-12-20T21:19:32.895Z,1671571172.895 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Express0080.lzma.bak
2022-12-20T21:19:32.895Z,1671571172.895 [DataOverHttps](INFO): SBD MOMSN=17400048
2022-12-20T21:19:34.062Z,1671571174.062 [Default:CheckIn:Read_Iridium] Stopped
2022-12-20T21:19:34.062Z,1671571174.062 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-20T21:19:34.062Z,1671571174.062 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-20T21:19:39.704Z,1671571179.704 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-20T21:24:34.739Z,1671571474.739 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-20T21:24:34.739Z,1671571474.739 [Default:CheckIn:C.Wait] Stopped
2022-12-20T21:24:34.739Z,1671571474.739 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T21:24:34.739Z,1671571474.739 [Default:CheckIn:D] Running Loop=1
2022-12-20T21:24:35.146Z,1671571475.146 [Default:CheckIn:D] Stopped
2022-12-20T21:24:35.147Z,1671571475.147 [Default:CheckIn:E] Running Loop=1
2022-12-20T21:24:35.560Z,1671571475.560 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 141.425049 min 
2022-12-20T21:24:35.560Z,1671571475.560 [Default:CheckIn:E] Stopped
2022-12-20T21:24:35.560Z,1671571475.560 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-20T21:24:35.560Z,1671571475.560 [Default:CheckIn] Stopped
2022-12-20T21:24:35.560Z,1671571475.560 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-20T21:24:35.560Z,1671571475.560 [Default:CheckIn](INFO): Running loop #26
2022-12-20T21:24:35.560Z,1671571475.560 [Default:CheckIn] Running Loop=26
2022-12-20T21:24:35.560Z,1671571475.560 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-20T21:24:35.561Z,1671571475.561 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-20T21:24:37.547Z,1671571477.547 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212436.00,A,3648.13318,N,12147.21469,W,0.019,315.32,201222,,,D*7E
2022-12-20T21:24:37.550Z,1671571477.550 [NAL9602](INFO): GPS fix at 20221220T212436: (36.802220, -121.786912)
2022-12-20T21:24:37.568Z,1671571477.568 [Default:CheckIn:Read_GPS] Stopped
2022-12-20T21:24:37.568Z,1671571477.568 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-20T21:24:45.800Z,1671571485.800 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221220T185823/Courier0082.lzma
2022-12-20T21:24:46.803Z,1671571486.803 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Courier0082.lzma.bak
2022-12-20T21:24:46.803Z,1671571486.803 [DataOverHttps](INFO): SBD MOMSN=17400052
2022-12-20T21:25:02.633Z,1671571502.633 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20221220T185823/Express0083.lzma
2022-12-20T21:25:03.635Z,1671571503.635 [DataOverHttps](INFO): Moved sent file to Logs/20221220T185823/Express0083.lzma.bak
2022-12-20T21:25:03.635Z,1671571503.635 [DataOverHttps](INFO): SBD MOMSN=17400055
2022-12-20T21:25:05.036Z,1671571505.036 [Default:CheckIn:Read_Iridium] Stopped
2022-12-20T21:25:05.037Z,1671571505.037 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-20T21:25:05.037Z,1671571505.037 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-20T21:25:08.270Z,1671571508.270 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-12-20T21:25:08.353Z,1671571508.353 [NAL9602](ERROR): received: 
+CSQ:0

OK
2022-12-20T21:26:45.025Z,1671571605.025 [CommandExec](IMPORTANT): got command failComponent
2022-12-20T21:26:45.026Z,1671571605.026 [CommandExec](IMPORTANT): Failed components:
2022-12-20T21:26:45.026Z,1671571605.026 [CommandExec](IMPORTANT): No failed Components.
2022-12-20T21:26:50.850Z,1671571610.850 [CommandExec](IMPORTANT): got command restart system
2022-12-20T21:26:52.913Z,1671571612.913 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2022-12-20T21:26:52.913Z,1671571612.913 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2022-12-20T21:26:52.913Z,1671571612.913 [CommandExec](INFO): Uninitializing the command executive.
2022-12-20T21:26:52.913Z,1671571612.913 [CommandExec](INFO): Uninitializing the command scheduler.
2022-12-20T21:26:52.914Z,1671571612.914 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-12-20T21:26:52.968Z,1671571612.968 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2022-12-20T21:26:52.968Z,1671571612.968 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2022-12-20T21:26:52.968Z,1671571612.968 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-12-20T21:26:52.977Z,1671571612.977 [NavChartDb](INFO): Join timeout helper Thread ID is 1709
2022-12-20T21:26:53.073Z,1671571613.073 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2022-12-20T21:26:53.073Z,1671571613.073 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-12-20T21:26:53.078Z,1671571613.078 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2022-12-20T21:26:53.078Z,1671571613.078 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2022-12-20T21:26:53.078Z,1671571613.078 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1710
2022-12-20T21:26:53.331Z,1671571613.331 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2022-12-20T21:26:53.331Z,1671571613.331 [WetLabsBB2FL](INFO): Powering down
2022-12-20T21:26:53.332Z,1671571613.332 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2022-12-20T21:26:53.349Z,1671571613.349 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2022-12-20T21:26:53.349Z,1671571613.349 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-12-20T21:26:53.349Z,1671571613.349 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1711
2022-12-20T21:26:53.941Z,1671571613.941 [CTD_Seabird](INFO): Powering down
2022-12-20T21:26:53.953Z,1671571613.953 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2022-12-20T21:26:53.953Z,1671571613.953 [CTD_Seabird](INFO): Powering down
2022-12-20T21:26:53.969Z,1671571613.969 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-12-20T21:26:53.973Z,1671571613.973 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler
2022-12-20T21:26:53.973Z,1671571613.973 [DAT ThreadHandler](INFO): Thread cancelled.
2022-12-20T21:26:53.973Z,1671571613.973 [DAT](INFO): Join timeout helper Thread ID is 1712
2022-12-20T21:26:54.097Z,1671571614.097 [DAT](INFO): Powering down
2022-12-20T21:26:54.174Z,1671571614.174 [DAT ThreadHandler](INFO): Uninitializing protected caller thread.
2022-12-20T21:26:54.174Z,1671571614.174 [DAT](INFO): Powering down
2022-12-20T21:26:54.175Z,1671571614.175 [DAT ThreadHandler](INFO): Thread cancelled.
2022-12-20T21:26:54.194Z,1671571614.194 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2022-12-20T21:26:54.194Z,1671571614.194 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-12-20T21:26:54.195Z,1671571614.195 [Radio_Surface](INFO): Join timeout helper Thread ID is 1713
2022-12-20T21:26:54.289Z,1671571614.289 [Radio_Surface](INFO): Powering down
2022-12-20T21:26:54.290Z,1671571614.290 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2022-12-20T21:26:54.290Z,1671571614.290 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-12-20T21:26:54.298Z,1671571614.298 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2022-12-20T21:26:54.298Z,1671571614.298 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-12-20T21:26:54.298Z,1671571614.298 [Onboard](INFO): Join timeout helper Thread ID is 1714
2022-12-20T21:26:55.769Z,1671571615.769 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2022-12-20T21:26:55.769Z,1671571615.769 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-12-20T21:26:55.782Z,1671571615.782 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2022-12-20T21:26:55.782Z,1671571615.782 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-12-20T21:26:55.782Z,1671571615.782 [DataOverHttps](INFO): Join timeout helper Thread ID is 1715
2022-12-20T21:26:56.786Z,1671571616.786 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2022-12-20T21:26:56.789Z,1671571616.789 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-12-20T21:26:56.812Z,1671571616.812 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2022-12-20T21:26:56.812Z,1671571616.812 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-12-20T21:26:56.812Z,1671571616.812 [BackseatComponent](INFO): Join timeout helper Thread ID is 1716
2022-12-20T21:26:56.965Z,1671571616.965 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2022-12-20T21:26:56.965Z,1671571616.965 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-12-20T21:26:56.982Z,1671571616.982 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2022-12-20T21:26:56.982Z,1671571616.982 [logger ThreadHandler](INFO): Thread cancelled.
2022-12-20T21:26:56.982Z,1671571616.982 [logger](INFO): Join timeout helper Thread ID is 1717
2022-12-20T21:26:57.013Z,1671571617.013 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2022-12-20T21:26:57.013Z,1671571617.013 [logger ThreadHandler](INFO): Thread cancelled.
2022-12-20T21:26:57.030Z,1671571617.030 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2022-12-20T21:26:57.030Z,1671571617.030 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-12-20T21:26:57.031Z,1671571617.031 [CommandLine](INFO): Join timeout helper Thread ID is 1718
2022-12-20T21:26:57.081Z,1671571617.081 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2022-12-20T21:26:57.081Z,1671571617.081 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-12-20T21:26:57.089Z,1671571617.089 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2022-12-20T21:26:57.089Z,1671571617.089 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-12-20T21:26:57.090Z,1671571617.090 [CommandExec](INFO): Join timeout helper Thread ID is 1719
2022-12-20T21:26:57.091Z,1671571617.091 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2022-12-20T21:26:57.091Z,1671571617.091 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-12-20T21:26:57.092Z,1671571617.092 [controlThread](INFO): Join timeout helper Thread ID is 1720
2022-12-20T21:26:57.365Z,1671571617.365 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2022-12-20T21:26:57.365Z,1671571617.365 [controlThread](DEBUG): Uninitializing ControlThread
2022-12-20T21:26:57.366Z,1671571617.366 [AHRS_M2](INFO): Powering down
2022-12-20T21:26:57.438Z,1671571617.438 [NAL9602](INFO): Powering down
2022-12-20T21:26:57.439Z,1671571617.439 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2022-12-20T21:26:57.440Z,1671571617.440 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2022-12-20T21:26:57.441Z,1671571617.441 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2022-12-20T21:26:57.441Z,1671571617.441 [MissionManager](INFO): Uninitializing Mission Default
2022-12-20T21:26:57.441Z,1671571617.441 [Default] Stopped
2022-12-20T21:26:57.442Z,1671571617.442 [Default](DEBUG): Aggregate::uninitialize Default
2022-12-20T21:26:57.442Z,1671571617.442 [Default:B.GoToSurface] Stopped
2022-12-20T21:26:57.442Z,1671571617.442 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-12-20T21:26:57.442Z,1671571617.442 [Default:CheckIn] Stopped
2022-12-20T21:26:57.442Z,1671571617.442 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-20T21:26:57.442Z,1671571617.442 [Default:CheckIn:C.Wait] Stopped
2022-12-20T21:26:57.442Z,1671571617.442 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T21:26:57.445Z,1671571617.445 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2022-12-20T21:26:57.445Z,1671571617.445 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2022-12-20T21:26:57.446Z,1671571617.446 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2022-12-20T21:26:57.446Z,1671571617.446 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2022-12-20T21:26:57.446Z,1671571617.446 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2022-12-20T21:26:57.446Z,1671571617.446 [BuoyancyServo](INFO): Powering down
2022-12-20T21:26:57.461Z,1671571617.461 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2022-12-20T21:26:57.461Z,1671571617.461 [ElevatorServo](INFO): Powering down
2022-12-20T21:26:57.462Z,1671571617.462 [MassServo](DEBUG): Uninitialize Mass Servo.
2022-12-20T21:26:57.462Z,1671571617.462 [MassServo](INFO): Powering down
2022-12-20T21:26:57.463Z,1671571617.463 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-12-20T21:26:57.463Z,1671571617.463 [RudderServo](INFO): Powering down
2022-12-20T21:26:57.464Z,1671571617.464 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2022-12-20T21:26:57.464Z,1671571617.464 [ThrusterHE](INFO): Powering down
2022-12-20T21:26:57.465Z,1671571617.465 [SBIT](DEBUG): Uninitialize SBIT Component.
2022-12-20T21:26:57.465Z,1671571617.465 [IBIT](DEBUG): Uninitialize IBIT Component.
2022-12-20T21:26:57.466Z,1671571617.466 [CBIT](DEBUG): Uninitialize CBIT Component.
2022-12-20T21:26:57.466Z,1671571617.466 [CBIT](DEBUG): Powering off loads.
2022-12-20T21:26:57.477Z,1671571617.477 [CBIT](DEBUG): Disabling WDT.
2022-12-20T21:26:57.489Z,1671571617.489 [CBIT](DEBUG): Opening all GF detection circuits.
2022-12-20T21:26:57.490Z,1671571617.490 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-12-20T21:26:57.551Z,1671571617.551 [DAT ThreadHandler](INFO): Thread cancelled.
2022-12-20T21:26:57.556Z,1671571617.556 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-12-20T21:26:57.558Z,1671571617.558 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-12-20T21:26:57.564Z,1671571617.564 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-12-20T21:26:57.611Z,1671571617.611 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-12-20T21:26:57.649Z,1671571617.649 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2022-12-20T21:26:57.653Z,1671571617.653 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-12-20T21:26:57.687Z,1671571617.687 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-12-20T21:26:57.756Z,1671571617.756 [logger ThreadHandler](INFO): Thread cancelled.