2021-10-29T16:54:24.218Z,1635526464.218 [Supervisor](DEBUG): Initializing supervisor.
2021-10-29T16:54:24.222Z,1635526464.222 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2021-10-29T16:54:24.223Z,1635526464.223 [SyncHandler](INFO): Protected caller Thread ID is 9437
2021-10-29T16:54:24.223Z,1635526464.223 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2021-10-29T16:54:24.224Z,1635526464.224 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2021-10-29T16:54:24.224Z,1635526464.224 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 9438
2021-10-29T16:54:24.228Z,1635526464.228 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2021-10-29T16:54:24.247Z,1635526464.247 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2021-10-29T16:54:24.248Z,1635526464.248 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2021-10-29T16:54:24.248Z,1635526464.248 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 9439
2021-10-29T16:54:24.252Z,1635526464.252 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2021-10-29T16:54:24.253Z,1635526464.253 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2021-10-29T16:54:24.253Z,1635526464.253 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 9440
2021-10-29T16:54:24.256Z,1635526464.256 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2021-10-29T16:54:24.257Z,1635526464.257 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2021-10-29T16:54:24.257Z,1635526464.257 [logger ThreadHandler](INFO): Protected caller Thread ID is 9441
2021-10-29T16:54:24.261Z,1635526464.261 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2021-10-29T16:54:24.261Z,1635526464.261 [Supervisor](INFO): Looking for Config files in directory: Config/
2021-10-29T16:54:24.263Z,1635526464.263 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2021-10-29T16:54:24.675Z,1635526464.675 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2021-10-29T16:54:24.676Z,1635526464.676 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2021-10-29T16:54:24.818Z,1635526464.818 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2021-10-29T16:54:24.819Z,1635526464.819 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2021-10-29T16:54:24.898Z,1635526464.898 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2021-10-29T16:54:25.112Z,1635526465.112 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2021-10-29T16:54:25.112Z,1635526465.112 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2021-10-29T16:54:25.189Z,1635526465.189 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2021-10-29T16:54:25.282Z,1635526465.282 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2021-10-29T16:54:25.283Z,1635526465.283 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2021-10-29T16:54:25.623Z,1635526465.623 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2021-10-29T16:54:25.623Z,1635526465.623 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2021-10-29T16:54:25.744Z,1635526465.744 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2021-10-29T16:54:25.745Z,1635526465.745 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2021-10-29T16:54:26.255Z,1635526466.255 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2021-10-29T16:54:26.256Z,1635526466.256 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2021-10-29T16:54:26.438Z,1635526466.438 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2021-10-29T16:54:26.439Z,1635526466.439 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2021-10-29T16:54:26.800Z,1635526466.800 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2021-10-29T16:54:26.801Z,1635526466.801 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2021-10-29T16:54:27.033Z,1635526467.033 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2021-10-29T16:54:27.033Z,1635526467.033 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2021-10-29T16:54:27.140Z,1635526467.140 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2021-10-29T16:54:27.141Z,1635526467.141 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2021-10-29T16:54:27.773Z,1635526467.773 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2021-10-29T16:54:27.774Z,1635526467.774 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2021-10-29T16:54:28.105Z,1635526468.105 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2021-10-29T16:54:28.105Z,1635526468.105 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2021-10-29T16:54:28.383Z,1635526468.383 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2021-10-29T16:54:28.385Z,1635526468.385 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/
2021-10-29T16:54:28.386Z,1635526468.386 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/vehicle.cfg
2021-10-29T16:54:28.571Z,1635526468.571 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/secure.cfg
2021-10-29T16:54:28.652Z,1635526468.652 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Science.cfg
2021-10-29T16:54:28.784Z,1635526468.784 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Simulator.cfg
2021-10-29T16:54:28.867Z,1635526468.867 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Battery.cfg
2021-10-29T16:54:29.124Z,1635526469.124 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2021-10-29T16:54:29.124Z,1635526469.124 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/logger.cfg
2021-10-29T16:54:29.249Z,1635526469.249 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Servo.cfg
2021-10-29T16:54:29.562Z,1635526469.562 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Navigation.cfg
2021-10-29T16:54:29.760Z,1635526469.760 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Sensor.cfg
2021-10-29T16:54:30.097Z,1635526470.097 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Control.cfg
2021-10-29T16:54:30.194Z,1635526470.194 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/BIT.cfg
2021-10-29T16:54:30.285Z,1635526470.285 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/root/
2021-10-29T16:54:30.285Z,1635526470.285 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2021-10-29T16:54:30.299Z,1635526470.299 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2021-10-29T16:54:30.311Z,1635526470.311 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2021-10-29T16:54:30.311Z,1635526470.311 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2021-10-29T16:54:30.407Z,1635526470.407 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2021-10-29T16:54:30.408Z,1635526470.408 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2021-10-29T16:54:30.461Z,1635526470.461 [VerticalControl](DEBUG): Construct VerticalControl.
2021-10-29T16:54:30.522Z,1635526470.522 [VerticalControl] Loaded
2021-10-29T16:54:30.523Z,1635526470.523 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2021-10-29T16:54:30.525Z,1635526470.525 [HorizontalControl](DEBUG): Construct HorizontalControl.
2021-10-29T16:54:30.563Z,1635526470.563 [HorizontalControl] Loaded
2021-10-29T16:54:30.564Z,1635526470.564 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2021-10-29T16:54:30.566Z,1635526470.566 [SpeedControl](DEBUG): Construct SpeedControl.
2021-10-29T16:54:30.569Z,1635526470.569 [SpeedControl] Loaded
2021-10-29T16:54:30.570Z,1635526470.570 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2021-10-29T16:54:30.572Z,1635526470.572 [LoopControl](DEBUG): Construct LoopControl.
2021-10-29T16:54:30.573Z,1635526470.573 [LoopControl] Loaded
2021-10-29T16:54:30.573Z,1635526470.573 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2021-10-29T16:54:30.573Z,1635526470.573 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2021-10-29T16:54:30.574Z,1635526470.574 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2021-10-29T16:54:30.704Z,1635526470.704 [BuoyancyServo] Loaded
2021-10-29T16:54:30.704Z,1635526470.704 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2021-10-29T16:54:30.724Z,1635526470.724 [ElevatorServo] Loaded
2021-10-29T16:54:30.724Z,1635526470.724 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2021-10-29T16:54:30.742Z,1635526470.742 [MassServo] Loaded
2021-10-29T16:54:30.743Z,1635526470.743 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2021-10-29T16:54:30.760Z,1635526470.760 [RudderServo] Loaded
2021-10-29T16:54:30.761Z,1635526470.761 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2021-10-29T16:54:30.775Z,1635526470.775 [ThrusterHE] Loaded
2021-10-29T16:54:30.776Z,1635526470.776 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2021-10-29T16:54:30.776Z,1635526470.776 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2021-10-29T16:54:30.777Z,1635526470.777 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2021-10-29T16:54:30.820Z,1635526470.820 [DepthRateCalculator] Loaded
2021-10-29T16:54:30.820Z,1635526470.820 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2021-10-29T16:54:30.825Z,1635526470.825 [PitchRateCalculator] Loaded
2021-10-29T16:54:30.825Z,1635526470.825 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2021-10-29T16:54:30.835Z,1635526470.835 [SpeedCalculator] Loaded
2021-10-29T16:54:30.835Z,1635526470.835 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2021-10-29T16:54:30.849Z,1635526470.849 [TempGradientCalculator] Loaded
2021-10-29T16:54:30.849Z,1635526470.849 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2021-10-29T16:54:30.853Z,1635526470.853 [YawRateCalculator] Loaded
2021-10-29T16:54:30.854Z,1635526470.854 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2021-10-29T16:54:30.871Z,1635526470.871 [ElevatorOffsetCalculator] Loaded
2021-10-29T16:54:30.871Z,1635526470.871 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2021-10-29T16:54:30.872Z,1635526470.872 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2021-10-29T16:54:30.872Z,1635526470.872 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2021-10-29T16:54:30.953Z,1635526470.953 [DeadReckonUsingMultipleVelocitySources] Loaded
2021-10-29T16:54:30.953Z,1635526470.953 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2021-10-29T16:54:30.967Z,1635526470.967 [NavChart] Loaded
2021-10-29T16:54:30.967Z,1635526470.967 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2021-10-29T16:54:30.972Z,1635526470.972 [UniversalFixResidualReporter] Loaded
2021-10-29T16:54:30.973Z,1635526470.973 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2021-10-29T16:54:30.973Z,1635526470.973 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2021-10-29T16:54:30.974Z,1635526470.974 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2021-10-29T16:54:31.352Z,1635526471.352 [AHRS_M2] Loaded
2021-10-29T16:54:31.352Z,1635526471.352 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2021-10-29T16:54:31.382Z,1635526471.382 [BackseatComponent] Loaded
2021-10-29T16:54:31.382Z,1635526471.382 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2021-10-29T16:54:31.383Z,1635526471.383 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 4089D4E0
2021-10-29T16:54:31.384Z,1635526471.384 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 9524
2021-10-29T16:54:31.386Z,1635526471.386 [LcmUniversalReporter] Loaded
2021-10-29T16:54:31.386Z,1635526471.386 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2021-10-29T16:54:32.190Z,1635526472.190 [BPC1] Loaded
2021-10-29T16:54:32.190Z,1635526472.190 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2021-10-29T16:54:32.264Z,1635526472.264 [DataOverHttps] Loaded
2021-10-29T16:54:32.265Z,1635526472.265 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2021-10-29T16:54:32.266Z,1635526472.266 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408CD4E0
2021-10-29T16:54:32.266Z,1635526472.266 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 9525
2021-10-29T16:54:32.286Z,1635526472.286 [Depth_Keller] Loaded
2021-10-29T16:54:32.286Z,1635526472.286 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2021-10-29T16:54:32.291Z,1635526472.291 [DropWeight] Loaded
2021-10-29T16:54:32.291Z,1635526472.291 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2021-10-29T16:54:32.352Z,1635526472.352 [NAL9602] Loaded
2021-10-29T16:54:32.352Z,1635526472.352 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2021-10-29T16:54:32.381Z,1635526472.381 [Onboard] Loaded
2021-10-29T16:54:32.381Z,1635526472.381 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2021-10-29T16:54:32.382Z,1635526472.382 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408FD4E0
2021-10-29T16:54:32.383Z,1635526472.383 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 9526
2021-10-29T16:54:32.396Z,1635526472.396 [Power24vConverter] Loaded
2021-10-29T16:54:32.396Z,1635526472.396 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2021-10-29T16:54:32.409Z,1635526472.409 [Radio_Surface] Loaded
2021-10-29T16:54:32.410Z,1635526472.410 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2021-10-29T16:54:32.411Z,1635526472.411 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4092D4E0
2021-10-29T16:54:32.411Z,1635526472.411 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 9527
2021-10-29T16:54:32.412Z,1635526472.412 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2021-10-29T16:54:32.413Z,1635526472.413 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2021-10-29T16:54:32.472Z,1635526472.472 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2021-10-29T16:54:32.473Z,1635526472.473 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2021-10-29T16:54:32.577Z,1635526472.577 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2021-10-29T16:54:32.577Z,1635526472.577 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2021-10-29T16:54:32.605Z,1635526472.605 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2021-10-29T16:54:32.606Z,1635526472.606 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2021-10-29T16:54:32.778Z,1635526472.778 [CTD_Seabird] Loaded
2021-10-29T16:54:32.779Z,1635526472.779 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2021-10-29T16:54:32.780Z,1635526472.780 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A4D4E0
2021-10-29T16:54:32.780Z,1635526472.780 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 9528
2021-10-29T16:54:32.811Z,1635526472.811 [ESPComponent] Loaded
2021-10-29T16:54:32.812Z,1635526472.812 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2021-10-29T16:54:32.831Z,1635526472.831 [PAR_Licor] Loaded
2021-10-29T16:54:32.831Z,1635526472.831 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2021-10-29T16:54:32.863Z,1635526472.863 [WetLabsBB2FL] Loaded
2021-10-29T16:54:32.863Z,1635526472.863 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2021-10-29T16:54:32.864Z,1635526472.864 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A7D4E0
2021-10-29T16:54:32.865Z,1635526472.865 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 9529
2021-10-29T16:54:32.865Z,1635526472.865 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2021-10-29T16:54:32.866Z,1635526472.866 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2021-10-29T16:54:33.188Z,1635526473.188 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2021-10-29T16:54:33.189Z,1635526473.189 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2021-10-29T16:54:33.335Z,1635526473.335 [SBIT](DEBUG): Construct Startup Built In Test.
2021-10-29T16:54:33.344Z,1635526473.344 [SBIT] Loaded
2021-10-29T16:54:33.344Z,1635526473.344 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2021-10-29T16:54:33.347Z,1635526473.347 [IBIT](DEBUG): Construct Initiated Built In Test.
2021-10-29T16:54:33.360Z,1635526473.360 [IBIT] Loaded
2021-10-29T16:54:33.360Z,1635526473.360 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2021-10-29T16:54:33.366Z,1635526473.366 [CBIT](DEBUG): Construct Continuous Built In Test.
2021-10-29T16:54:33.467Z,1635526473.467 [CBIT] Loaded
2021-10-29T16:54:33.467Z,1635526473.467 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2021-10-29T16:54:33.468Z,1635526473.468 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2021-10-29T16:54:33.474Z,1635526473.474 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2021-10-29T16:54:33.477Z,1635526473.477 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2021-10-29T16:54:33.488Z,1635526473.488 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2021-10-29T16:54:33.489Z,1635526473.489 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B644E0
2021-10-29T16:54:33.489Z,1635526473.489 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 9530
2021-10-29T16:54:33.493Z,1635526473.493 [Supervisor](INFO): Main Thread ID is 9436
2021-10-29T16:54:33.494Z,1635526473.494 [Supervisor](DEBUG): Running supervisor.
2021-10-29T16:54:33.494Z,1635526473.494 [CommandExec ThreadHandler](INFO): Handler Thread ID is 9531
2021-10-29T16:54:33.495Z,1635526473.495 [CommandExec](INFO): Initializing the command executive.
2021-10-29T16:54:33.496Z,1635526473.496 [CommandLine ThreadHandler](INFO): Handler Thread ID is 9532
2021-10-29T16:54:33.499Z,1635526473.499 [controlThread ThreadHandler](INFO): Handler Thread ID is 9533
2021-10-29T16:54:33.499Z,1635526473.499 [controlThread](DEBUG): Initializing ControlThread
2021-10-29T16:54:33.500Z,1635526473.500 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2021-10-29T16:54:33.502Z,1635526473.502 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2021-10-29T16:54:33.503Z,1635526473.503 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2021-10-29T16:54:33.503Z,1635526473.503 [LoopControl](DEBUG): Initialize LoopControlComponent.
2021-10-29T16:54:33.504Z,1635526473.504 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2021-10-29T16:54:33.505Z,1635526473.505 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2021-10-29T16:54:33.505Z,1635526473.505 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2021-10-29T16:54:33.505Z,1635526473.505 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2021-10-29T16:54:33.506Z,1635526473.506 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2021-10-29T16:54:33.506Z,1635526473.506 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2021-10-29T16:54:33.507Z,1635526473.507 [NavChart](DEBUG): Initialize NavChart Navigation.
2021-10-29T16:54:33.508Z,1635526473.508 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2021-10-29T16:54:33.515Z,1635526473.515 [SBIT](INFO): Initialize SBIT Component.
2021-10-29T16:54:33.516Z,1635526473.516 [SBIT](IMPORTANT): git: 2021-10-11a
2021-10-29T16:54:33.516Z,1635526473.516 [SBIT](INFO): git hash: 36f3a97de7a122c995f034a375e3cefac6406048
2021-10-29T16:54:33.516Z,1635526473.516 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2021-10-29T16:54:33.517Z,1635526473.517 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2021-10-29T16:54:33.519Z,1635526473.519 [SBIT](INFO): Beginning SBIT in 57.000000 seconds.
2021-10-29T16:54:33.519Z,1635526473.519 [IBIT](INFO): Initialize IBIT Component.
2021-10-29T16:54:33.520Z,1635526473.520 [CBIT](DEBUG): Initialize CBIT Component.
2021-10-29T16:54:33.521Z,1635526473.521 [logger ThreadHandler](INFO): Handler Thread ID is 9534
2021-10-29T16:54:33.535Z,1635526473.535 [CBIT](DEBUG): Initialized mux pins.
2021-10-29T16:54:33.535Z,1635526473.535 [CBIT](DEBUG): Initializing the watchdog timer.
2021-10-29T16:54:33.539Z,1635526473.539 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 9535
2021-10-29T16:54:33.548Z,1635526473.548 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 9536
2021-10-29T16:54:33.549Z,1635526473.549 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2021-10-29T16:54:33.555Z,1635526473.555 [Onboard ThreadHandler](INFO): Handler Thread ID is 9537
2021-10-29T16:54:33.559Z,1635526473.559 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2021-10-29T16:54:33.560Z,1635526473.560 [CBIT](DEBUG): Initializing heartbeat.
2021-10-29T16:54:33.576Z,1635526473.576 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 9538
2021-10-29T16:54:33.591Z,1635526473.591 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 9539
2021-10-29T16:54:33.592Z,1635526473.592 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2021-10-29T16:54:33.596Z,1635526473.596 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 9541
2021-10-29T16:54:33.600Z,1635526473.600 [WetLabsBB2FL](INFO): Powering up
2021-10-29T16:54:33.601Z,1635526473.601 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 9543
2021-10-29T16:54:33.604Z,1635526473.604 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2021-10-29T16:54:33.604Z,1635526473.604 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2021-10-29T16:54:33.605Z,1635526473.605 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2021-10-29T16:54:33.605Z,1635526473.605 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2021-10-29T16:54:33.605Z,1635526473.605 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2021-10-29T16:54:33.605Z,1635526473.605 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2021-10-29T16:54:33.605Z,1635526473.605 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2021-10-29T16:54:33.605Z,1635526473.605 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2021-10-29T16:54:33.606Z,1635526473.606 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2021-10-29T16:54:33.606Z,1635526473.606 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2021-10-29T16:54:33.606Z,1635526473.606 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2021-10-29T16:54:33.606Z,1635526473.606 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2021-10-29T16:54:33.606Z,1635526473.606 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2021-10-29T16:54:33.607Z,1635526473.607 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2021-10-29T16:54:33.607Z,1635526473.607 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2021-10-29T16:54:33.607Z,1635526473.607 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2021-10-29T16:54:33.631Z,1635526473.631 [CBIT](DEBUG): Deactivating GF circuits.
2021-10-29T16:54:33.631Z,1635526473.631 [CBIT](DEBUG): Deactivating emergency mode.
2021-10-29T16:54:33.667Z,1635526473.667 [CBIT](DEBUG): Backplane powered.
2021-10-29T16:54:33.668Z,1635526473.668 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2021-10-29T16:54:33.681Z,1635526473.681 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2021-10-29T16:54:33.712Z,1635526473.712 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

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

    <Aggregate Id="StartupSatComms">

        <Sequence/>

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

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

    </Aggregate>

</Mission>


2021-10-29T16:54:33.713Z,1635526473.713 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2021-10-29T16:54:33.801Z,1635526473.801 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2021-10-29T16:54:33.802Z,1635526473.802 [Default:A.Wait](DEBUG): Construct Wait.
2021-10-29T16:54:33.805Z,1635526473.805 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2021-10-29T16:54:33.848Z,1635526473.848 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2021-10-29T16:54:33.851Z,1635526473.851 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2021-10-29T16:54:33.870Z,1635526473.870 [Default:E.Execute](DEBUG): Construct Execute.
2021-10-29T16:54:33.884Z,1635526473.884 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

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

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

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

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

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

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

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

    </Aggregate>

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

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

</Mission>


2021-10-29T16:54:33.889Z,1635526473.889 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2021-10-29T16:54:33.912Z,1635526473.912 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2021-10-29T16:54:33.979Z,1635526473.979 [Radio_Surface](INFO): Powering up
2021-10-29T16:54:33.982Z,1635526473.982 [Power24vConverter](INFO): Powering up.
2021-10-29T16:54:34.029Z,1635526474.029 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2021-10-29T16:54:34.035Z,1635526474.035 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2021-10-29T16:54:34.036Z,1635526474.036 [ElevatorServo](DEBUG): Initializing EZServoServo.
2021-10-29T16:54:34.047Z,1635526474.047 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2021-10-29T16:54:34.048Z,1635526474.048 [MassServo](DEBUG): Initializing EZServoServo.
2021-10-29T16:54:34.055Z,1635526474.055 [MassServo](DEBUG): Initializing MassServo.
2021-10-29T16:54:34.056Z,1635526474.056 [RudderServo](DEBUG): Initializing EZServoServo.
2021-10-29T16:54:34.063Z,1635526474.063 [RudderServo](DEBUG): Initializing RudderServo.
2021-10-29T16:54:34.064Z,1635526474.064 [ThrusterHE](DEBUG): Initializing EZServoServo.
2021-10-29T16:54:34.071Z,1635526474.071 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2021-10-29T16:54:34.331Z,1635526474.331 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2021-10-29T16:54:34.331Z,1635526474.331 [DropWeight] Hardware Fault, FailCount= 1
2021-10-29T16:54:34.331Z,1635526474.331 [DropWeight](ERROR): Hardware Fault
2021-10-29T16:54:34.444Z,1635526474.444 [CommandExec](FAULT): Scheduling is paused
2021-10-29T16:54:34.445Z,1635526474.445 [CBIT](INFO): Critical error at 20211029T165434
2021-10-29T16:54:34.445Z,1635526474.445 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2021-10-29T16:54:34.571Z,1635526474.571 [CBIT](ERROR): Hardware Fault in component: DropWeight
2021-10-29T16:54:34.571Z,1635526474.571 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2021-10-29T16:54:34.813Z,1635526474.813 [CBIT](INFO): Critical error at 20211029T165434
2021-10-29T16:54:35.707Z,1635526475.707 [WetLabsBB2FL](INFO): Powering down
2021-10-29T16:54:47.161Z,1635526487.161 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004697
2021-10-29T16:54:49.387Z,1635526489.387 [MassServo](ERROR): getPosition uart error serial timeout
2021-10-29T16:54:49.388Z,1635526489.388 [MassServo](FAULT): Invalid EZ Servo response:"\r"
2021-10-29T16:54:49.388Z,1635526489.388 [MassServo] Communications Fault, FailCount= 1
2021-10-29T16:54:49.388Z,1635526489.388 [MassServo](ERROR): Communications Fault
2021-10-29T16:54:49.392Z,1635526489.392 [CBIT](ERROR): Communications Fault in component: MassServo
2021-10-29T16:54:49.717Z,1635526489.717 [MassServo](DEBUG): Uninitialize Mass Servo.
2021-10-29T16:54:49.717Z,1635526489.717 [MassServo](INFO): Powering down
2021-10-29T16:54:50.505Z,1635526490.505 [MassServo](DEBUG): Initializing EZServoServo.
2021-10-29T16:54:50.624Z,1635526490.624 [MassServo](DEBUG): Initializing MassServo.
2021-10-29T16:54:50.629Z,1635526490.629 [CBIT](INFO): Clearing failed state for component MassServo
2021-10-29T16:54:50.629Z,1635526490.629 [MassServo] No Fault, FailCount= 1
2021-10-29T16:55:02.584Z,1635526502.584 [NAL9602](INFO): Powering up NAL9602
2021-10-29T16:55:13.492Z,1635526513.492 [NAL9602](INFO): NAL9602 initialized
2021-10-29T16:55:15.325Z,1635526515.325 [CommandExec](IMPORTANT): got command get Onboard.Pressure
2021-10-29T16:55:15.326Z,1635526515.326 [CommandExec](IMPORTANT): Onboard.Pressure 53104.519531 Pa
2021-10-29T16:55:30.930Z,1635526530.930 [SBIT](IMPORTANT): Beginning Startup BIT
2021-10-29T16:55:30.961Z,1635526530.961 [CBIT](IMPORTANT): Beginning ground fault scan
2021-10-29T16:55:33.833Z,1635526533.833 [CommandExec](IMPORTANT): got command get Onboard.Humidity
2021-10-29T16:55:33.834Z,1635526533.834 [CommandExec](IMPORTANT): Onboard.Humidity 8.600904 %
2021-10-29T16:55:41.843Z,1635526541.843 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.004056
CHAN A1 (24V): 0.169211
CHAN A2 (12V): -0.004417
CHAN A3 (5V): -0.003625
CHAN B0 (3.3V): -0.001008
CHAN B1 (3.15aV): -0.000956
CHAN B2 (3.15bV): -0.000632
CHAN B3 (GND): 0.000050
OPEN: 0.003722
Full Scale: +/- 1 mA
2021-10-29T16:56:22.180Z,1635526582.180 [CommandExec](IMPORTANT): got command help
2021-10-29T16:56:25.069Z,1635526585.069 [SBIT](IMPORTANT): SBIT PASSED
2021-10-29T16:56:25.070Z,1635526585.070 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2021-10-29T16:56:25.075Z,1635526585.075 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=32 count;

2021-10-29T16:56:25.075Z,1635526585.075 [SBIT](IMPORTANT): BPC1.batterySamplingInterval=1 hour;

2021-10-29T16:56:25.075Z,1635526585.075 [SBIT](IMPORTANT): BackseatComponent.loadAtStartup=1 bool;

2021-10-29T16:56:25.075Z,1635526585.075 [SBIT](IMPORTANT): CBIT.gf24Offset=-18.106 microampere;

2021-10-29T16:56:25.075Z,1635526585.075 [SBIT](IMPORTANT): CBIT.stopDepth=295 meter;

2021-10-29T16:56:25.077Z,1635526585.077 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool;

2021-10-29T16:56:25.077Z,1635526585.077 [SBIT](IMPORTANT): ESPComponent.loadAtStartup=1 bool;

2021-10-29T16:56:25.077Z,1635526585.077 [SBIT](IMPORTANT): ESPComponent.simulateHardware=1 bool;

2021-10-29T16:56:25.124Z,1635526585.124 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water;

2021-10-29T16:56:25.124Z,1635526585.124 [SBIT](IMPORTANT): Express linearApproximation platform_pitch_angle 5.000000 degree;

2021-10-29T16:56:25.124Z,1635526585.124 [SBIT](IMPORTANT): Express none platform_roll_angle;

2021-10-29T16:56:25.124Z,1635526585.124 [SBIT](IMPORTANT): PAR_Licor.parCal=1.38207 none;

2021-10-29T16:56:25.124Z,1635526585.124 [SBIT](IMPORTANT): ThrusterHE.loadAtStartup=1 bool;

2021-10-29T16:56:25.124Z,1635526585.124 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=391.537766 cubic_centimeter;

2021-10-29T16:56:25.125Z,1635526585.125 [SBIT](IMPORTANT): VerticalControl.massDefault=9.394078 millimeter;

2021-10-29T16:56:25.437Z,1635526585.437 [MissionManager](IMPORTANT): Started mission Startup
2021-10-29T16:56:25.437Z,1635526585.437 [Startup] Running Loop=1
2021-10-29T16:56:25.437Z,1635526585.437 [Startup](DEBUG): Aggregate::initialize Startup
2021-10-29T16:56:25.437Z,1635526585.437 [Startup:A.GoToSurface] Running Loop=1
2021-10-29T16:56:25.437Z,1635526585.437 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-10-29T16:56:25.438Z,1635526585.438 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-10-29T16:56:25.438Z,1635526585.438 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-10-29T16:56:25.443Z,1635526585.443 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-10-29T16:56:25.444Z,1635526585.444 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-10-29T16:56:25.444Z,1635526585.444 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-10-29T16:56:25.446Z,1635526585.446 [Startup:StartupSatComms] Running Loop=1
2021-10-29T16:56:25.446Z,1635526585.446 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2021-10-29T16:56:25.446Z,1635526585.446 [Startup:StartupSatComms:A] Running Loop=1
2021-10-29T16:56:25.844Z,1635526585.844 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2021-10-29T16:57:01.770Z,1635526621.770 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T16:57:15.970Z,1635526635.970 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T16:57:25.619Z,1635526645.619 [Startup:StartupSatComms:A](INFO): Timed out from 2021-10-29T16:56:25.4Z
2021-10-29T16:57:25.619Z,1635526645.619 [Startup:StartupSatComms:A] Stopped
2021-10-29T16:57:25.619Z,1635526645.619 [Startup:StartupSatComms:B] Running Loop=1
2021-10-29T16:57:26.017Z,1635526646.017 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-10-29T16:57:29.339Z,1635526649.339 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T16:57:32.962Z,1635526652.962 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20211028T230023/Courier0007.lzma
2021-10-29T16:57:33.699Z,1635526653.699 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2021-10-29T16:57:33.699Z,1635526653.699 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-10-29T16:57:33.710Z,1635526653.710 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-10-29T16:57:33.965Z,1635526653.965 [DataOverHttps](INFO): Moved sent file to Logs/20211028T230023/Courier0007.lzma.bak
2021-10-29T16:57:33.965Z,1635526653.965 [DataOverHttps](INFO): SBD MOMSN=16169490
2021-10-29T16:57:34.114Z,1635526654.114 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-10-29T16:57:34.114Z,1635526654.114 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2021-10-29T16:57:43.036Z,1635526663.036 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T16:57:49.427Z,1635526669.427 [DataOverHttps](INFO): Sending 246 bytes from file Logs/20211029T165424/Courier0000.lzma
2021-10-29T16:57:56.718Z,1635526676.718 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T16:58:10.050Z,1635526690.050 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T16:58:13.519Z,1635526693.519 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting.
2021-10-29T16:58:23.822Z,1635526703.822 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T16:58:25.837Z,1635526705.837 [Startup:StartupSatComms:B](INFO): Timed out from 2021-10-29T16:57:25.6Z
2021-10-29T16:58:25.837Z,1635526705.837 [Startup:StartupSatComms:B] Stopped
2021-10-29T16:58:25.837Z,1635526705.837 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2021-10-29T16:58:25.837Z,1635526705.837 [Startup:StartupSatComms] Stopped
2021-10-29T16:58:25.837Z,1635526705.837 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2021-10-29T16:58:25.838Z,1635526705.838 [Startup](INFO): Completed Startup
2021-10-29T16:58:25.838Z,1635526705.838 [MissionManager](INFO): Startup is completed.
2021-10-29T16:58:25.838Z,1635526705.838 [MissionManager](INFO): Uninitializing Mission Startup
2021-10-29T16:58:25.839Z,1635526705.839 [Startup] Stopped
2021-10-29T16:58:25.839Z,1635526705.839 [Startup](DEBUG): Aggregate::uninitialize Startup
2021-10-29T16:58:25.839Z,1635526705.839 [Startup:A.GoToSurface] Stopped
2021-10-29T16:58:25.839Z,1635526705.839 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-10-29T16:58:26.218Z,1635526706.218 [MissionManager](IMPORTANT): Started mission Default
2021-10-29T16:58:26.218Z,1635526706.218 [Default] Running Loop=1
2021-10-29T16:58:26.218Z,1635526706.218 [Default](DEBUG): Aggregate::initialize Default
2021-10-29T16:58:26.218Z,1635526706.218 [Default:B.GoToSurface] Running Loop=1
2021-10-29T16:58:26.218Z,1635526706.218 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-10-29T16:58:26.219Z,1635526706.219 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-10-29T16:58:26.219Z,1635526706.219 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-10-29T16:58:26.220Z,1635526706.220 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-10-29T16:58:26.220Z,1635526706.220 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-10-29T16:58:26.220Z,1635526706.220 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-10-29T16:58:26.221Z,1635526706.221 [Default:A.Wait] Running Loop=1
2021-10-29T16:58:26.221Z,1635526706.221 [Default:A.Wait](DEBUG): Initialize Wait Component.
2021-10-29T16:58:36.770Z,1635526716.770 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T16:58:39.549Z,1635526719.549 [Default:A.Wait](INFO): Done Waiting.
2021-10-29T16:58:39.549Z,1635526719.549 [Default:A.Wait] Stopped
2021-10-29T16:58:39.550Z,1635526719.550 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T16:58:39.954Z,1635526719.954 [Default:CheckIn] Running Loop=1
2021-10-29T16:58:39.954Z,1635526719.954 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T16:58:39.954Z,1635526719.954 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T16:58:40.371Z,1635526720.371 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2021-10-29T16:58:42.655Z,1635526722.655 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.423359
2021-10-29T16:58:50.453Z,1635526730.453 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T16:59:04.190Z,1635526744.190 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T16:59:13.783Z,1635526753.783 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-29T16:59:17.518Z,1635526757.518 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T16:59:30.907Z,1635526770.907 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2021-10-29T16:59:30.915Z,1635526770.915 [BPC1](INFO): Calculating totals. Valid battery stick count: 30. Valid reserve battery stick count: 3.
2021-10-29T16:59:30.918Z,1635526770.918 [BPC1](INFO): Received data from all battery sticks.
2021-10-29T16:59:48.923Z,1635526788.923 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-10-29T17:00:16.496Z,1635526816.496 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-10-29T17:00:21.251Z,1635526821.251 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002790
2021-10-29T17:00:34.755Z,1635526834.755 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2021-10-29T17:00:34.755Z,1635526834.755 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-10-29T17:00:34.803Z,1635526834.803 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-10-29T17:00:35.237Z,1635526835.237 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-10-29T17:00:35.237Z,1635526835.237 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2021-10-29T17:03:35.894Z,1635527015.894 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2021-10-29T17:03:35.894Z,1635527015.894 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-10-29T17:03:35.905Z,1635527015.905 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-10-29T17:03:36.317Z,1635527016.317 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-10-29T17:03:36.317Z,1635527016.317 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2021-10-29T17:03:40.339Z,1635527020.339 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-10-29T16:58:39.0Z
2021-10-29T17:03:40.339Z,1635527020.339 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T17:03:40.339Z,1635527020.339 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T17:03:40.754Z,1635527020.754 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-10-29T17:03:46.955Z,1635527026.955 [DataOverHttps](INFO): Sending 246 bytes from file Logs/20211029T165424/Courier0000.lzma
2021-10-29T17:03:47.956Z,1635527027.956 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0000.lzma.bak
2021-10-29T17:03:47.957Z,1635527027.957 [DataOverHttps](INFO): SBD MOMSN=16169501
2021-10-29T17:04:03.350Z,1635527043.350 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20211029T165424/Courier0004.lzma
2021-10-29T17:04:04.353Z,1635527044.353 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0004.lzma.bak
2021-10-29T17:04:04.353Z,1635527044.353 [DataOverHttps](INFO): SBD MOMSN=16169506
2021-10-29T17:04:20.815Z,1635527060.815 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20211028T230023/Express0008.lzma
2021-10-29T17:04:21.817Z,1635527061.817 [DataOverHttps](INFO): Moved sent file to Logs/20211028T230023/Express0008.lzma.bak
2021-10-29T17:04:21.817Z,1635527061.817 [DataOverHttps](INFO): SBD MOMSN=16169508
2021-10-29T17:04:34.942Z,1635527074.942 [Power24vConverter](INFO): Powering down.
2021-10-29T17:04:40.736Z,1635527080.736 [DataOverHttps](INFO): Sending 1175 bytes from file Logs/20211029T165424/Express0001.lzma
2021-10-29T17:04:41.737Z,1635527081.737 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0001.lzma.bak
2021-10-29T17:04:41.737Z,1635527081.737 [DataOverHttps](INFO): SBD MOMSN=16169517
2021-10-29T17:04:58.535Z,1635527098.535 [DataOverHttps](INFO): Sending 197 bytes from file Logs/20211029T165424/Express0005.lzma
2021-10-29T17:04:59.537Z,1635527099.537 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0005.lzma.bak
2021-10-29T17:04:59.537Z,1635527099.537 [DataOverHttps](INFO): SBD MOMSN=16169550
2021-10-29T17:05:01.654Z,1635527101.654 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T17:05:01.654Z,1635527101.654 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T17:05:01.654Z,1635527101.654 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T17:05:17.044Z,1635527117.044 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-10-29T17:05:17.044Z,1635527117.044 [NAL9602] Data Fault, FailCount= 1
2021-10-29T17:05:17.045Z,1635527117.045 [NAL9602](ERROR): Data Fault
2021-10-29T17:05:17.116Z,1635527117.116 [CBIT](ERROR): Data Fault in component: NAL9602
2021-10-29T17:05:17.444Z,1635527117.444 [NAL9602](INFO): Powering down
2021-10-29T17:05:18.271Z,1635527118.271 [CBIT](INFO): Clearing failed state for component NAL9602
2021-10-29T17:05:18.271Z,1635527118.271 [NAL9602] No Fault, FailCount= 1
2021-10-29T17:05:47.743Z,1635527147.743 [NAL9602](INFO): Powering up NAL9602
2021-10-29T17:05:58.656Z,1635527158.656 [NAL9602](INFO): NAL9602 initialized
2021-10-29T17:06:37.071Z,1635527197.071 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2021-10-29T17:06:37.071Z,1635527197.071 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-10-29T17:06:37.082Z,1635527197.082 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-10-29T17:06:37.471Z,1635527197.471 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-10-29T17:06:37.472Z,1635527197.472 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2021-10-29T17:09:34.442Z,1635527374.442 [CBIT](INFO): Clearing failed state for component DropWeight
2021-10-29T17:09:34.442Z,1635527374.442 [DropWeight] No Fault, FailCount= 1
2021-10-29T17:09:38.046Z,1635527378.046 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2021-10-29T17:09:38.046Z,1635527378.046 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-10-29T17:09:38.057Z,1635527378.057 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-10-29T17:09:38.463Z,1635527378.463 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-10-29T17:09:38.463Z,1635527378.463 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2021-10-29T17:10:02.306Z,1635527402.306 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T17:10:02.306Z,1635527402.306 [Default:CheckIn:C.Wait] Stopped
2021-10-29T17:10:02.306Z,1635527402.306 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T17:10:02.306Z,1635527402.306 [Default:CheckIn:D] Running Loop=1
2021-10-29T17:10:02.697Z,1635527402.697 [Default:CheckIn:D] Stopped
2021-10-29T17:10:02.697Z,1635527402.697 [Default:CheckIn:E] Running Loop=1
2021-10-29T17:10:03.109Z,1635527403.109 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.607974 min 
2021-10-29T17:10:03.109Z,1635527403.109 [Default:CheckIn:E] Stopped
2021-10-29T17:10:03.109Z,1635527403.109 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T17:10:03.109Z,1635527403.109 [Default:CheckIn] Stopped
2021-10-29T17:10:03.109Z,1635527403.109 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T17:10:03.110Z,1635527403.110 [Default:CheckIn](INFO): Running loop #2
2021-10-29T17:10:03.110Z,1635527403.110 [Default:CheckIn] Running Loop=2
2021-10-29T17:10:03.110Z,1635527403.110 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T17:10:03.110Z,1635527403.110 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T17:12:39.080Z,1635527559.080 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2021-10-29T17:12:39.080Z,1635527559.080 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-10-29T17:12:39.091Z,1635527559.091 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-10-29T17:12:39.521Z,1635527559.521 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-10-29T17:12:39.521Z,1635527559.521 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2021-10-29T17:15:03.359Z,1635527703.359 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-10-29T17:10:03.1Z
2021-10-29T17:15:03.359Z,1635527703.359 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T17:15:03.359Z,1635527703.359 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T17:15:13.830Z,1635527713.830 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20211029T165424/Courier0007.lzma
2021-10-29T17:15:14.832Z,1635527714.832 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0007.lzma.bak
2021-10-29T17:15:14.833Z,1635527714.833 [DataOverHttps](INFO): SBD MOMSN=16169626
2021-10-29T17:15:31.355Z,1635527731.355 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20211029T165424/Express0008.lzma
2021-10-29T17:15:32.357Z,1635527732.357 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0008.lzma.bak
2021-10-29T17:15:32.357Z,1635527732.357 [DataOverHttps](INFO): SBD MOMSN=16169628
2021-10-29T17:15:34.516Z,1635527734.516 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T17:15:34.516Z,1635527734.516 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T17:15:34.516Z,1635527734.516 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T17:15:40.145Z,1635527740.145 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2021-10-29T17:15:40.145Z,1635527740.145 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-10-29T17:15:40.156Z,1635527740.156 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-10-29T17:15:40.552Z,1635527740.552 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-10-29T17:15:40.552Z,1635527740.552 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2021-10-29T17:16:01.537Z,1635527761.537 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-10-29T17:16:01.537Z,1635527761.537 [NAL9602] Data Fault, FailCount= 2
2021-10-29T17:16:01.537Z,1635527761.537 [NAL9602](ERROR): Data Fault
2021-10-29T17:16:01.583Z,1635527761.583 [CBIT](ERROR): Data Fault in component: NAL9602
2021-10-29T17:16:01.940Z,1635527761.940 [NAL9602](INFO): Powering down
2021-10-29T17:16:02.774Z,1635527762.774 [CBIT](INFO): Clearing failed state for component NAL9602
2021-10-29T17:16:02.774Z,1635527762.774 [NAL9602] No Fault, FailCount= 2
2021-10-29T17:16:32.240Z,1635527792.240 [NAL9602](INFO): Powering up NAL9602
2021-10-29T17:16:43.152Z,1635527803.152 [NAL9602](INFO): NAL9602 initialized
2021-10-29T17:18:41.164Z,1635527921.164 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2021-10-29T17:18:41.164Z,1635527921.164 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-10-29T17:18:41.177Z,1635527921.177 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-10-29T17:18:41.579Z,1635527921.579 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-10-29T17:18:41.580Z,1635527921.580 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2021-10-29T17:20:35.085Z,1635528035.085 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T17:20:35.085Z,1635528035.085 [Default:CheckIn:C.Wait] Stopped
2021-10-29T17:20:35.085Z,1635528035.085 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T17:20:35.085Z,1635528035.085 [Default:CheckIn:D] Running Loop=1
2021-10-29T17:20:35.475Z,1635528035.475 [Default:CheckIn:D] Stopped
2021-10-29T17:20:35.476Z,1635528035.476 [Default:CheckIn:E] Running Loop=1
2021-10-29T17:20:35.885Z,1635528035.885 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 22.154289 min 
2021-10-29T17:20:35.886Z,1635528035.886 [Default:CheckIn:E] Stopped
2021-10-29T17:20:35.886Z,1635528035.886 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T17:20:35.886Z,1635528035.886 [Default:CheckIn] Stopped
2021-10-29T17:20:35.886Z,1635528035.886 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T17:20:35.886Z,1635528035.886 [Default:CheckIn](INFO): Running loop #3
2021-10-29T17:20:35.886Z,1635528035.886 [Default:CheckIn] Running Loop=3
2021-10-29T17:20:35.886Z,1635528035.886 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T17:20:35.886Z,1635528035.886 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T17:21:42.186Z,1635528102.186 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2021-10-29T17:21:42.186Z,1635528102.186 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-10-29T17:21:42.197Z,1635528102.197 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-10-29T17:21:42.611Z,1635528102.611 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-10-29T17:21:42.611Z,1635528102.611 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2021-10-29T17:24:43.172Z,1635528283.172 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2021-10-29T17:24:43.172Z,1635528283.172 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-10-29T17:24:43.183Z,1635528283.183 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-10-29T17:24:43.592Z,1635528283.592 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-10-29T17:24:43.592Z,1635528283.592 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2021-10-29T17:25:32.050Z,1635528332.050 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172530.00,A,3648.16585,N,12147.28308,W,0.330,321.57,291021,,,A*73
2021-10-29T17:25:32.098Z,1635528332.098 [NAL9602](INFO): GPS fix at 20211029T172530: (36.802764, -121.788051)
2021-10-29T17:25:32.111Z,1635528332.111 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T17:25:32.111Z,1635528332.111 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T17:25:42.095Z,1635528342.095 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20211029T165424/Courier0010.lzma
2021-10-29T17:25:43.097Z,1635528343.097 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0010.lzma.bak
2021-10-29T17:25:43.097Z,1635528343.097 [DataOverHttps](INFO): SBD MOMSN=16169672
2021-10-29T17:26:00.627Z,1635528360.627 [DataOverHttps](INFO): Sending 340 bytes from file Logs/20211029T165424/Express0011.lzma
2021-10-29T17:26:01.629Z,1635528361.629 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0011.lzma.bak
2021-10-29T17:26:01.629Z,1635528361.629 [DataOverHttps](INFO): SBD MOMSN=16169675
2021-10-29T17:26:04.005Z,1635528364.005 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T17:26:04.005Z,1635528364.005 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T17:26:04.005Z,1635528364.005 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T17:26:04.372Z,1635528364.372 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-29T17:31:04.552Z,1635528664.552 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T17:31:04.552Z,1635528664.552 [Default:CheckIn:C.Wait] Stopped
2021-10-29T17:31:04.552Z,1635528664.552 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T17:31:04.553Z,1635528664.553 [Default:CheckIn:D] Running Loop=1
2021-10-29T17:31:04.977Z,1635528664.977 [Default:CheckIn:D] Stopped
2021-10-29T17:31:04.977Z,1635528664.977 [Default:CheckIn:E] Running Loop=1
2021-10-29T17:31:05.358Z,1635528665.358 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 32.645980 min 
2021-10-29T17:31:05.358Z,1635528665.358 [Default:CheckIn:E] Stopped
2021-10-29T17:31:05.358Z,1635528665.358 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T17:31:05.358Z,1635528665.358 [Default:CheckIn] Stopped
2021-10-29T17:31:05.359Z,1635528665.359 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T17:31:05.359Z,1635528665.359 [Default:CheckIn](INFO): Running loop #4
2021-10-29T17:31:05.359Z,1635528665.359 [Default:CheckIn] Running Loop=4
2021-10-29T17:31:05.359Z,1635528665.359 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T17:31:05.359Z,1635528665.359 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T17:31:07.370Z,1635528667.370 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173106.00,A,3648.16507,N,12147.28627,W,0.233,331.12,291021,,,A*73
2021-10-29T17:31:07.372Z,1635528667.372 [NAL9602](INFO): GPS fix at 20211029T173106: (36.802751, -121.788105)
2021-10-29T17:31:07.392Z,1635528667.392 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T17:31:07.392Z,1635528667.392 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T17:31:16.391Z,1635528676.391 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211029T165424/Courier0013.lzma
2021-10-29T17:31:17.393Z,1635528677.393 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0013.lzma.bak
2021-10-29T17:31:17.393Z,1635528677.393 [DataOverHttps](INFO): SBD MOMSN=16169716
2021-10-29T17:31:34.094Z,1635528694.094 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20211029T165424/Express0014.lzma
2021-10-29T17:31:35.097Z,1635528695.097 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0014.lzma.bak
2021-10-29T17:31:35.097Z,1635528695.097 [DataOverHttps](INFO): SBD MOMSN=16169719
2021-10-29T17:31:37.316Z,1635528697.316 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T17:31:37.316Z,1635528697.316 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T17:31:37.316Z,1635528697.316 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T17:36:09.176Z,1635528969.176 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-10-29T17:36:37.866Z,1635528997.866 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T17:36:37.866Z,1635528997.866 [Default:CheckIn:C.Wait] Stopped
2021-10-29T17:36:37.866Z,1635528997.866 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T17:36:37.866Z,1635528997.866 [Default:CheckIn:D] Running Loop=1
2021-10-29T17:36:38.279Z,1635528998.279 [Default:CheckIn:D] Stopped
2021-10-29T17:36:38.279Z,1635528998.279 [Default:CheckIn:E] Running Loop=1
2021-10-29T17:36:38.674Z,1635528998.674 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 38.201009 min 
2021-10-29T17:36:38.674Z,1635528998.674 [Default:CheckIn:E] Stopped
2021-10-29T17:36:38.675Z,1635528998.675 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T17:36:38.675Z,1635528998.675 [Default:CheckIn] Stopped
2021-10-29T17:36:38.675Z,1635528998.675 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T17:36:38.675Z,1635528998.675 [Default:CheckIn](INFO): Running loop #5
2021-10-29T17:36:38.675Z,1635528998.675 [Default:CheckIn] Running Loop=5
2021-10-29T17:36:38.675Z,1635528998.675 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T17:36:38.675Z,1635528998.675 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T17:36:40.690Z,1635529000.690 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173640.00,A,3648.16395,N,12147.28077,W,0.097,331.12,291021,,,A*74
2021-10-29T17:36:40.693Z,1635529000.693 [NAL9602](INFO): GPS fix at 20211029T173640: (36.802732, -121.788013)
2021-10-29T17:36:40.703Z,1635529000.703 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T17:36:40.703Z,1635529000.703 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T17:36:47.854Z,1635529007.854 [DataOverHttps](INFO): Sending 70 bytes from file Logs/20211029T165424/Courier0016.lzma
2021-10-29T17:36:48.857Z,1635529008.857 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0016.lzma.bak
2021-10-29T17:36:48.857Z,1635529008.857 [DataOverHttps](INFO): SBD MOMSN=16169728
2021-10-29T17:37:08.206Z,1635529028.206 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20211029T165424/Express0017.lzma
2021-10-29T17:37:09.209Z,1635529029.209 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0017.lzma.bak
2021-10-29T17:37:09.209Z,1635529029.209 [DataOverHttps](INFO): SBD MOMSN=16169731
2021-10-29T17:37:12.378Z,1635529032.378 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T17:37:12.379Z,1635529032.379 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T17:37:12.379Z,1635529032.379 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T17:37:13.138Z,1635529033.138 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-29T17:42:12.903Z,1635529332.903 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T17:42:12.903Z,1635529332.903 [Default:CheckIn:C.Wait] Stopped
2021-10-29T17:42:12.903Z,1635529332.903 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T17:42:12.903Z,1635529332.903 [Default:CheckIn:D] Running Loop=1
2021-10-29T17:42:13.311Z,1635529333.311 [Default:CheckIn:D] Stopped
2021-10-29T17:42:13.312Z,1635529333.312 [Default:CheckIn:E] Running Loop=1
2021-10-29T17:42:13.703Z,1635529333.703 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 43.784888 min 
2021-10-29T17:42:13.703Z,1635529333.703 [Default:CheckIn:E] Stopped
2021-10-29T17:42:13.703Z,1635529333.703 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T17:42:13.703Z,1635529333.703 [Default:CheckIn] Stopped
2021-10-29T17:42:13.703Z,1635529333.703 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T17:42:13.703Z,1635529333.703 [Default:CheckIn](INFO): Running loop #6
2021-10-29T17:42:13.704Z,1635529333.704 [Default:CheckIn] Running Loop=6
2021-10-29T17:42:13.704Z,1635529333.704 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T17:42:13.704Z,1635529333.704 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T17:42:15.722Z,1635529335.722 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174215.00,A,3648.16429,N,12147.28487,W,0.214,314.40,291021,,,A*75
2021-10-29T17:42:15.724Z,1635529335.724 [NAL9602](INFO): GPS fix at 20211029T174215: (36.802738, -121.788081)
2021-10-29T17:42:15.735Z,1635529335.735 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T17:42:15.735Z,1635529335.735 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T17:42:23.506Z,1635529343.506 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211029T165424/Courier0019.lzma
2021-10-29T17:42:24.509Z,1635529344.509 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0019.lzma.bak
2021-10-29T17:42:24.509Z,1635529344.509 [DataOverHttps](INFO): SBD MOMSN=16169746
2021-10-29T17:42:41.447Z,1635529361.447 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20211029T165424/Express0020.lzma
2021-10-29T17:42:42.450Z,1635529362.450 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0020.lzma.bak
2021-10-29T17:42:42.450Z,1635529362.450 [DataOverHttps](INFO): SBD MOMSN=16169749
2021-10-29T17:42:44.863Z,1635529364.863 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T17:42:44.863Z,1635529364.863 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T17:42:44.864Z,1635529364.864 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T17:47:18.380Z,1635529638.380 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-10-29T17:47:45.461Z,1635529665.461 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T17:47:45.461Z,1635529665.461 [Default:CheckIn:C.Wait] Stopped
2021-10-29T17:47:45.461Z,1635529665.461 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T17:47:45.461Z,1635529665.461 [Default:CheckIn:D] Running Loop=1
2021-10-29T17:47:45.874Z,1635529665.874 [Default:CheckIn:D] Stopped
2021-10-29T17:47:45.874Z,1635529665.874 [Default:CheckIn:E] Running Loop=1
2021-10-29T17:47:46.322Z,1635529666.322 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 49.327600 min 
2021-10-29T17:47:46.322Z,1635529666.322 [Default:CheckIn:E] Stopped
2021-10-29T17:47:46.322Z,1635529666.322 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T17:47:46.322Z,1635529666.322 [Default:CheckIn] Stopped
2021-10-29T17:47:46.323Z,1635529666.323 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T17:47:46.323Z,1635529666.323 [Default:CheckIn](INFO): Running loop #7
2021-10-29T17:47:46.323Z,1635529666.323 [Default:CheckIn] Running Loop=7
2021-10-29T17:47:46.323Z,1635529666.323 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T17:47:46.323Z,1635529666.323 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T17:47:48.278Z,1635529668.278 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174747.00,A,3648.16214,N,12147.28182,W,0.136,314.40,291021,,,A*7C
2021-10-29T17:47:48.281Z,1635529668.281 [NAL9602](INFO): GPS fix at 20211029T174747: (36.802702, -121.788030)
2021-10-29T17:47:48.295Z,1635529668.295 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T17:47:48.295Z,1635529668.295 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T17:47:56.090Z,1635529676.090 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211029T165424/Courier0022.lzma
2021-10-29T17:47:57.092Z,1635529677.092 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0022.lzma.bak
2021-10-29T17:47:57.093Z,1635529677.093 [DataOverHttps](INFO): SBD MOMSN=16169758
2021-10-29T17:48:13.835Z,1635529693.835 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20211029T165424/Express0023.lzma
2021-10-29T17:48:14.837Z,1635529694.837 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0023.lzma.bak
2021-10-29T17:48:14.837Z,1635529694.837 [DataOverHttps](INFO): SBD MOMSN=16169761
2021-10-29T17:48:16.999Z,1635529696.999 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T17:48:16.999Z,1635529696.999 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T17:48:16.000Z,1635529697.000 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T17:48:20.596Z,1635529700.596 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-29T17:53:17.618Z,1635529997.618 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T17:53:17.618Z,1635529997.618 [Default:CheckIn:C.Wait] Stopped
2021-10-29T17:53:17.618Z,1635529997.618 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T17:53:17.618Z,1635529997.618 [Default:CheckIn:D] Running Loop=1
2021-10-29T17:53:18.023Z,1635529998.023 [Default:CheckIn:D] Stopped
2021-10-29T17:53:18.023Z,1635529998.023 [Default:CheckIn:E] Running Loop=1
2021-10-29T17:53:18.438Z,1635529998.438 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 54.863416 min 
2021-10-29T17:53:18.438Z,1635529998.438 [Default:CheckIn:E] Stopped
2021-10-29T17:53:18.438Z,1635529998.438 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T17:53:18.438Z,1635529998.438 [Default:CheckIn] Stopped
2021-10-29T17:53:18.438Z,1635529998.438 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T17:53:18.439Z,1635529998.439 [Default:CheckIn](INFO): Running loop #8
2021-10-29T17:53:18.439Z,1635529998.439 [Default:CheckIn] Running Loop=8
2021-10-29T17:53:18.439Z,1635529998.439 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T17:53:18.439Z,1635529998.439 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T17:53:20.438Z,1635530000.438 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175319.00,A,3648.16528,N,12147.28196,W,0.214,134.76,291021,,,A*79
2021-10-29T17:53:20.441Z,1635530000.441 [NAL9602](INFO): GPS fix at 20211029T175319: (36.802755, -121.788033)
2021-10-29T17:53:20.477Z,1635530000.477 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T17:53:20.477Z,1635530000.477 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T17:53:28.162Z,1635530008.162 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211029T165424/Courier0025.lzma
2021-10-29T17:53:29.165Z,1635530009.165 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0025.lzma.bak
2021-10-29T17:53:29.165Z,1635530009.165 [DataOverHttps](INFO): SBD MOMSN=16169765
2021-10-29T17:53:45.983Z,1635530025.983 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20211029T165424/Express0026.lzma
2021-10-29T17:53:46.985Z,1635530026.985 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0026.lzma.bak
2021-10-29T17:53:46.985Z,1635530026.985 [DataOverHttps](INFO): SBD MOMSN=16169769
2021-10-29T17:53:49.144Z,1635530029.144 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T17:53:49.144Z,1635530029.144 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T17:53:49.144Z,1635530029.144 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T17:53:51.140Z,1635530031.140 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2021-10-29T17:53:51.223Z,1635530031.223 [NAL9602](ERROR): received: 
+CSQ:0

OK
2021-10-29T17:58:18.626Z,1635530298.626 [NAL9602](INFO): SBD MO Status=2, MOMSN=6476, MT Status=2, MTMSN=0
2021-10-29T17:58:18.627Z,1635530298.627 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-10-29T17:58:22.261Z,1635530302.261 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-10-29T17:58:49.744Z,1635530329.744 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T17:58:49.744Z,1635530329.744 [Default:CheckIn:C.Wait] Stopped
2021-10-29T17:58:49.744Z,1635530329.744 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T17:58:49.744Z,1635530329.744 [Default:CheckIn:D] Running Loop=1
2021-10-29T17:58:50.158Z,1635530330.158 [Default:CheckIn:D] Stopped
2021-10-29T17:58:50.158Z,1635530330.158 [Default:CheckIn:E] Running Loop=1
2021-10-29T17:58:50.554Z,1635530330.554 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 60.398999 min 
2021-10-29T17:58:50.554Z,1635530330.554 [Default:CheckIn:E] Stopped
2021-10-29T17:58:50.554Z,1635530330.554 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T17:58:50.554Z,1635530330.554 [Default:CheckIn] Stopped
2021-10-29T17:58:50.554Z,1635530330.554 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T17:58:50.555Z,1635530330.555 [Default:CheckIn](INFO): Running loop #9
2021-10-29T17:58:50.555Z,1635530330.555 [Default:CheckIn] Running Loop=9
2021-10-29T17:58:50.555Z,1635530330.555 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T17:58:50.555Z,1635530330.555 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T17:58:52.562Z,1635530332.562 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175851.00,A,3648.16471,N,12147.28301,W,0.428,134.76,291021,,,A*76
2021-10-29T17:58:52.565Z,1635530332.565 [NAL9602](INFO): GPS fix at 20211029T175851: (36.802745, -121.788050)
2021-10-29T17:58:52.576Z,1635530332.576 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T17:58:52.576Z,1635530332.576 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T17:59:00.360Z,1635530340.360 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20211029T165424/Courier0028.lzma
2021-10-29T17:59:01.360Z,1635530341.360 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0028.lzma.bak
2021-10-29T17:59:01.361Z,1635530341.361 [DataOverHttps](INFO): SBD MOMSN=16169912
2021-10-29T17:59:21.631Z,1635530361.631 [DataOverHttps](INFO): Sending 217 bytes from file Logs/20211029T165424/Express0029.lzma
2021-10-29T17:59:22.633Z,1635530362.633 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0029.lzma.bak
2021-10-29T17:59:22.633Z,1635530362.633 [DataOverHttps](INFO): SBD MOMSN=16169915
2021-10-29T17:59:24.548Z,1635530364.548 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-29T17:59:24.966Z,1635530364.966 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T17:59:24.967Z,1635530364.967 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T17:59:24.967Z,1635530364.967 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T18:01:59.283Z,1635530519.283 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T18:02:13.481Z,1635530533.481 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T18:02:27.160Z,1635530547.160 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T18:02:40.901Z,1635530560.901 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T18:02:54.237Z,1635530574.237 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T18:03:07.165Z,1635530587.165 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T18:03:20.941Z,1635530600.941 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T18:03:35.068Z,1635530615.068 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T18:03:48.413Z,1635530628.413 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T18:04:01.345Z,1635530641.345 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T18:04:15.079Z,1635530655.079 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T18:04:25.596Z,1635530665.596 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T18:04:25.596Z,1635530665.596 [Default:CheckIn:C.Wait] Stopped
2021-10-29T18:04:25.596Z,1635530665.596 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T18:04:25.596Z,1635530665.596 [Default:CheckIn:D] Running Loop=1
2021-10-29T18:04:25.986Z,1635530665.986 [Default:CheckIn:D] Stopped
2021-10-29T18:04:25.987Z,1635530665.987 [Default:CheckIn:E] Running Loop=1
2021-10-29T18:04:26.395Z,1635530666.395 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 65.996139 min 
2021-10-29T18:04:26.395Z,1635530666.395 [Default:CheckIn:E] Stopped
2021-10-29T18:04:26.395Z,1635530666.395 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T18:04:26.395Z,1635530666.395 [Default:CheckIn] Stopped
2021-10-29T18:04:26.395Z,1635530666.395 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T18:04:26.396Z,1635530666.396 [Default:CheckIn](INFO): Running loop #10
2021-10-29T18:04:26.396Z,1635530666.396 [Default:CheckIn] Running Loop=10
2021-10-29T18:04:26.396Z,1635530666.396 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T18:04:26.396Z,1635530666.396 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T18:04:27.000Z,1635530668.000 [BPC1](INFO): Calculating totals. Valid battery stick count: 28. Valid reserve battery stick count: 4.
2021-10-29T18:04:28.003Z,1635530668.003 [BPC1](INFO): Received data from all battery sticks.
2021-10-29T18:04:28.410Z,1635530668.410 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180427.00,A,3648.16630,N,12147.28586,W,0.156,134.76,291021,,,A*73
2021-10-29T18:04:28.412Z,1635530668.412 [NAL9602](INFO): GPS fix at 20211029T180427: (36.802772, -121.788098)
2021-10-29T18:04:28.423Z,1635530668.423 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T18:04:28.423Z,1635530668.423 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T18:04:35.654Z,1635530675.654 [DataOverHttps](INFO): Sending 84 bytes from file Logs/20211029T165424/Courier0031.lzma
2021-10-29T18:04:36.657Z,1635530676.657 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0031.lzma.bak
2021-10-29T18:04:36.657Z,1635530676.657 [DataOverHttps](INFO): SBD MOMSN=16169919
2021-10-29T18:04:53.486Z,1635530693.486 [DataOverHttps](INFO): Sending 138 bytes from file Logs/20211029T165424/Express0032.lzma
2021-10-29T18:04:54.489Z,1635530694.489 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0032.lzma.bak
2021-10-29T18:04:54.489Z,1635530694.489 [DataOverHttps](INFO): SBD MOMSN=16169922
2021-10-29T18:04:56.695Z,1635530696.695 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T18:04:56.695Z,1635530696.695 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T18:04:56.695Z,1635530696.695 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T18:04:59.104Z,1635530699.104 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2021-10-29T18:04:59.179Z,1635530699.179 [NAL9602](ERROR): received: 
+SBDI: 2, 6476, 2, 0, 0, 0

OK
2021-10-29T18:08:07.430Z,1635530887.430 [NAL9602](INFO): SBD MO Status=2, MOMSN=6476, MT Status=2, MTMSN=0
2021-10-29T18:08:07.430Z,1635530887.430 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-10-29T18:08:43.788Z,1635530923.788 [NAL9602](INFO): SBD MO Status=2, MOMSN=6476, MT Status=2, MTMSN=0
2021-10-29T18:08:43.788Z,1635530923.788 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-10-29T18:09:00.749Z,1635530940.749 [NAL9602](INFO): SBD MO Status=2, MOMSN=6476, MT Status=2, MTMSN=0
2021-10-29T18:09:00.750Z,1635530940.750 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-10-29T18:09:18.525Z,1635530958.525 [NAL9602](INFO): SBD MO Status=2, MOMSN=6476, MT Status=2, MTMSN=0
2021-10-29T18:09:18.526Z,1635530958.526 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-10-29T18:09:37.109Z,1635530977.109 [NAL9602](INFO): SBD MO Status=2, MOMSN=6476, MT Status=2, MTMSN=0
2021-10-29T18:09:37.110Z,1635530977.110 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-10-29T18:09:37.516Z,1635530977.516 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-10-29T18:09:57.329Z,1635530997.329 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T18:09:57.330Z,1635530997.330 [Default:CheckIn:C.Wait] Stopped
2021-10-29T18:09:57.330Z,1635530997.330 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T18:09:57.330Z,1635530997.330 [Default:CheckIn:D] Running Loop=1
2021-10-29T18:09:57.722Z,1635530997.722 [Default:CheckIn:D] Stopped
2021-10-29T18:09:57.722Z,1635530997.722 [Default:CheckIn:E] Running Loop=1
2021-10-29T18:09:58.129Z,1635530998.129 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 71.525065 min 
2021-10-29T18:09:58.129Z,1635530998.129 [Default:CheckIn:E] Stopped
2021-10-29T18:09:58.129Z,1635530998.129 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T18:09:58.130Z,1635530998.130 [Default:CheckIn] Stopped
2021-10-29T18:09:58.130Z,1635530998.130 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T18:09:58.130Z,1635530998.130 [Default:CheckIn](INFO): Running loop #11
2021-10-29T18:09:58.130Z,1635530998.130 [Default:CheckIn] Running Loop=11
2021-10-29T18:09:58.130Z,1635530998.130 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T18:09:58.130Z,1635530998.130 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T18:10:00.140Z,1635531000.140 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180959.00,A,3648.16541,N,12147.28058,W,0.428,0.00,291021,,,A*7F
2021-10-29T18:10:00.142Z,1635531000.142 [NAL9602](INFO): GPS fix at 20211029T180959: (36.802757, -121.788010)
2021-10-29T18:10:00.153Z,1635531000.153 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T18:10:00.153Z,1635531000.153 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T18:10:07.958Z,1635531007.958 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211029T165424/Courier0034.lzma
2021-10-29T18:10:08.961Z,1635531008.961 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0034.lzma.bak
2021-10-29T18:10:08.961Z,1635531008.961 [DataOverHttps](INFO): SBD MOMSN=16169964
2021-10-29T18:10:25.659Z,1635531025.659 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20211029T165424/Express0035.lzma
2021-10-29T18:10:26.661Z,1635531026.661 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0035.lzma.bak
2021-10-29T18:10:26.661Z,1635531026.661 [DataOverHttps](INFO): SBD MOMSN=16169967
2021-10-29T18:10:28.829Z,1635531028.829 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T18:10:28.829Z,1635531028.829 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T18:10:28.830Z,1635531028.830 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T18:10:32.464Z,1635531032.464 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-29T18:15:29.447Z,1635531329.447 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T18:15:29.447Z,1635531329.447 [Default:CheckIn:C.Wait] Stopped
2021-10-29T18:15:29.447Z,1635531329.447 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T18:15:29.448Z,1635531329.448 [Default:CheckIn:D] Running Loop=1
2021-10-29T18:15:29.850Z,1635531329.850 [Default:CheckIn:D] Stopped
2021-10-29T18:15:29.850Z,1635531329.850 [Default:CheckIn:E] Running Loop=1
2021-10-29T18:15:30.252Z,1635531330.252 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 77.060522 min 
2021-10-29T18:15:30.252Z,1635531330.252 [Default:CheckIn:E] Stopped
2021-10-29T18:15:30.252Z,1635531330.252 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T18:15:30.252Z,1635531330.252 [Default:CheckIn] Stopped
2021-10-29T18:15:30.252Z,1635531330.252 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T18:15:30.253Z,1635531330.253 [Default:CheckIn](INFO): Running loop #12
2021-10-29T18:15:30.253Z,1635531330.253 [Default:CheckIn] Running Loop=12
2021-10-29T18:15:30.253Z,1635531330.253 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T18:15:30.253Z,1635531330.253 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T18:15:32.262Z,1635531332.262 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181531.00,A,3648.16768,N,12147.28507,W,0.117,0.00,291021,,,A*73
2021-10-29T18:15:32.264Z,1635531332.264 [NAL9602](INFO): GPS fix at 20211029T181531: (36.802795, -121.788084)
2021-10-29T18:15:32.309Z,1635531332.309 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T18:15:32.309Z,1635531332.309 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T18:15:39.994Z,1635531339.994 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211029T165424/Courier0037.lzma
2021-10-29T18:15:40.997Z,1635531340.997 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0037.lzma.bak
2021-10-29T18:15:40.997Z,1635531340.997 [DataOverHttps](INFO): SBD MOMSN=16169971
2021-10-29T18:15:57.766Z,1635531357.766 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20211029T165424/Express0038.lzma
2021-10-29T18:15:58.769Z,1635531358.769 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0038.lzma.bak
2021-10-29T18:15:58.769Z,1635531358.769 [DataOverHttps](INFO): SBD MOMSN=16169974
2021-10-29T18:16:01.011Z,1635531361.011 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T18:16:01.011Z,1635531361.011 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T18:16:01.011Z,1635531361.011 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T18:17:52.453Z,1635531472.453 [NAL9602](INFO): SBD MO Status=2, MOMSN=6476, MT Status=2, MTMSN=0
2021-10-29T18:17:52.453Z,1635531472.453 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-10-29T18:18:18.709Z,1635531498.709 [NAL9602](INFO): SBD MO Status=0, MOMSN=6476, MT Status=0, MTMSN=0
2021-10-29T18:18:18.709Z,1635531498.709 [NAL9602](INFO): No messages in MT queue
2021-10-29T18:18:49.412Z,1635531529.412 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-29T18:21:01.610Z,1635531661.610 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T18:21:01.610Z,1635531661.610 [Default:CheckIn:C.Wait] Stopped
2021-10-29T18:21:01.610Z,1635531661.610 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T18:21:01.611Z,1635531661.611 [Default:CheckIn:D] Running Loop=1
2021-10-29T18:21:02.016Z,1635531662.016 [Default:CheckIn:D] Stopped
2021-10-29T18:21:02.016Z,1635531662.016 [Default:CheckIn:E] Running Loop=1
2021-10-29T18:21:02.448Z,1635531662.448 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 82.596631 min 
2021-10-29T18:21:02.448Z,1635531662.448 [Default:CheckIn:E] Stopped
2021-10-29T18:21:02.448Z,1635531662.448 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T18:21:02.448Z,1635531662.448 [Default:CheckIn] Stopped
2021-10-29T18:21:02.448Z,1635531662.448 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T18:21:02.449Z,1635531662.449 [Default:CheckIn](INFO): Running loop #13
2021-10-29T18:21:02.449Z,1635531662.449 [Default:CheckIn] Running Loop=13
2021-10-29T18:21:02.449Z,1635531662.449 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T18:21:02.449Z,1635531662.449 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T18:21:04.432Z,1635531664.432 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182103.00,A,3648.16408,N,12147.28999,W,0.058,0.00,291021,,,A*71
2021-10-29T18:21:04.435Z,1635531664.435 [NAL9602](INFO): GPS fix at 20211029T182103: (36.802735, -121.788167)
2021-10-29T18:21:04.452Z,1635531664.452 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T18:21:04.453Z,1635531664.453 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T18:21:15.662Z,1635531675.662 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211029T165424/Courier0040.lzma
2021-10-29T18:21:16.665Z,1635531676.665 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0040.lzma.bak
2021-10-29T18:21:16.665Z,1635531676.665 [DataOverHttps](INFO): SBD MOMSN=16169984
2021-10-29T18:21:33.618Z,1635531693.618 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20211029T165424/Express0041.lzma
2021-10-29T18:21:34.621Z,1635531694.621 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0041.lzma.bak
2021-10-29T18:21:34.621Z,1635531694.621 [DataOverHttps](INFO): SBD MOMSN=16169987
2021-10-29T18:21:36.957Z,1635531696.957 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T18:21:36.958Z,1635531696.958 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T18:21:36.958Z,1635531696.958 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T18:25:41.367Z,1635531941.367 [NAL9602](INFO): SBD MO Status=2, MOMSN=6477, MT Status=2, MTMSN=0
2021-10-29T18:25:41.367Z,1635531941.367 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-10-29T18:26:06.413Z,1635531966.413 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-10-29T18:26:37.124Z,1635531997.124 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-29T18:26:37.542Z,1635531997.542 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T18:26:37.542Z,1635531997.542 [Default:CheckIn:C.Wait] Stopped
2021-10-29T18:26:37.542Z,1635531997.542 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T18:26:37.542Z,1635531997.542 [Default:CheckIn:D] Running Loop=1
2021-10-29T18:26:37.935Z,1635531997.935 [Default:CheckIn:D] Stopped
2021-10-29T18:26:37.935Z,1635531997.935 [Default:CheckIn:E] Running Loop=1
2021-10-29T18:26:38.348Z,1635531998.348 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 88.195280 min 
2021-10-29T18:26:38.348Z,1635531998.348 [Default:CheckIn:E] Stopped
2021-10-29T18:26:38.348Z,1635531998.348 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T18:26:38.348Z,1635531998.348 [Default:CheckIn] Stopped
2021-10-29T18:26:38.348Z,1635531998.348 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T18:26:38.348Z,1635531998.348 [Default:CheckIn](INFO): Running loop #14
2021-10-29T18:26:38.348Z,1635531998.348 [Default:CheckIn] Running Loop=14
2021-10-29T18:26:38.348Z,1635531998.348 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T18:26:38.349Z,1635531998.349 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T18:26:40.352Z,1635532000.352 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182639.00,A,3648.16995,N,12147.28023,W,1.244,0.00,291021,,,A*70
2021-10-29T18:26:40.354Z,1635532000.354 [NAL9602](INFO): GPS fix at 20211029T182639: (36.802833, -121.788004)
2021-10-29T18:26:40.365Z,1635532000.365 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T18:26:40.366Z,1635532000.366 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T18:26:47.286Z,1635532007.286 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211029T165424/Courier0043.lzma
2021-10-29T18:26:48.289Z,1635532008.289 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0043.lzma.bak
2021-10-29T18:26:48.289Z,1635532008.289 [DataOverHttps](INFO): SBD MOMSN=16169990
2021-10-29T18:27:07.523Z,1635532027.523 [DataOverHttps](INFO): Sending 217 bytes from file Logs/20211029T165424/Express0044.lzma
2021-10-29T18:27:08.519Z,1635532028.519 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0044.lzma.bak
2021-10-29T18:27:08.519Z,1635532028.519 [DataOverHttps](INFO): SBD MOMSN=16169993
2021-10-29T18:27:11.113Z,1635532031.113 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2021-10-29T18:27:11.187Z,1635532031.187 [NAL9602](ERROR): received: 
+CSQ:0

OK77, 2, 0, 0, 0

OK
2021-10-29T18:27:11.586Z,1635532031.586 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T18:27:11.586Z,1635532031.586 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T18:27:11.586Z,1635532031.586 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T18:27:32.522Z,1635532052.522 [NAL9602](INFO): SBD MO Status=0, MOMSN=6477, MT Status=0, MTMSN=0
2021-10-29T18:27:32.522Z,1635532052.522 [NAL9602](INFO): No messages in MT queue
2021-10-29T18:28:03.224Z,1635532083.224 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-29T18:32:12.124Z,1635532332.124 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T18:32:12.124Z,1635532332.124 [Default:CheckIn:C.Wait] Stopped
2021-10-29T18:32:12.124Z,1635532332.124 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T18:32:12.124Z,1635532332.124 [Default:CheckIn:D] Running Loop=1
2021-10-29T18:32:12.511Z,1635532332.511 [Default:CheckIn:D] Stopped
2021-10-29T18:32:12.511Z,1635532332.511 [Default:CheckIn:E] Running Loop=1
2021-10-29T18:32:12.918Z,1635532332.918 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 93.771541 min 
2021-10-29T18:32:12.918Z,1635532332.918 [Default:CheckIn:E] Stopped
2021-10-29T18:32:12.918Z,1635532332.918 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T18:32:12.918Z,1635532332.918 [Default:CheckIn] Stopped
2021-10-29T18:32:12.919Z,1635532332.919 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T18:32:12.919Z,1635532332.919 [Default:CheckIn](INFO): Running loop #15
2021-10-29T18:32:12.919Z,1635532332.919 [Default:CheckIn] Running Loop=15
2021-10-29T18:32:12.919Z,1635532332.919 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T18:32:12.919Z,1635532332.919 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T18:32:14.931Z,1635532334.931 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183214.00,A,3648.16823,N,12147.28897,W,0.117,0.00,291021,,,A*75
2021-10-29T18:32:14.934Z,1635532334.934 [NAL9602](INFO): GPS fix at 20211029T183214: (36.802804, -121.788150)
2021-10-29T18:32:14.952Z,1635532334.952 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T18:32:14.952Z,1635532334.952 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T18:32:21.914Z,1635532341.914 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211029T165424/Courier0046.lzma
2021-10-29T18:32:22.917Z,1635532342.917 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0046.lzma.bak
2021-10-29T18:32:22.917Z,1635532342.917 [DataOverHttps](INFO): SBD MOMSN=16170166
2021-10-29T18:32:40.314Z,1635532360.314 [DataOverHttps](INFO): Sending 141 bytes from file Logs/20211029T165424/Express0047.lzma
2021-10-29T18:32:41.317Z,1635532361.317 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0047.lzma.bak
2021-10-29T18:32:41.317Z,1635532361.317 [DataOverHttps](INFO): SBD MOMSN=16170169
2021-10-29T18:32:43.697Z,1635532363.697 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T18:32:43.697Z,1635532363.697 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T18:32:43.697Z,1635532363.697 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T18:36:27.030Z,1635532587.030 [NAL9602](INFO): SBD MO Status=2, MOMSN=6478, MT Status=2, MTMSN=0
2021-10-29T18:36:27.030Z,1635532587.030 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-10-29T18:36:56.113Z,1635532616.113 [NAL9602](INFO): SBD MO Status=0, MOMSN=6478, MT Status=0, MTMSN=0
2021-10-29T18:36:56.113Z,1635532616.113 [NAL9602](INFO): No messages in MT queue
2021-10-29T18:37:26.864Z,1635532646.864 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-29T18:37:44.254Z,1635532664.254 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T18:37:44.255Z,1635532664.255 [Default:CheckIn:C.Wait] Stopped
2021-10-29T18:37:44.255Z,1635532664.255 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T18:37:44.255Z,1635532664.255 [Default:CheckIn:D] Running Loop=1
2021-10-29T18:37:44.646Z,1635532664.646 [Default:CheckIn:D] Stopped
2021-10-29T18:37:44.646Z,1635532664.646 [Default:CheckIn:E] Running Loop=1
2021-10-29T18:37:45.054Z,1635532665.054 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 99.307129 min 
2021-10-29T18:37:45.054Z,1635532665.054 [Default:CheckIn:E] Stopped
2021-10-29T18:37:45.054Z,1635532665.054 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T18:37:45.054Z,1635532665.054 [Default:CheckIn] Stopped
2021-10-29T18:37:45.055Z,1635532665.055 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T18:37:45.055Z,1635532665.055 [Default:CheckIn](INFO): Running loop #16
2021-10-29T18:37:45.055Z,1635532665.055 [Default:CheckIn] Running Loop=16
2021-10-29T18:37:45.055Z,1635532665.055 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T18:37:45.055Z,1635532665.055 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T18:37:47.068Z,1635532667.068 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183746.00,A,3648.16426,N,12147.28868,W,0.136,0.00,291021,,,A*7D
2021-10-29T18:37:47.070Z,1635532667.070 [NAL9602](INFO): GPS fix at 20211029T183746: (36.802738, -121.788145)
2021-10-29T18:37:47.082Z,1635532667.082 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T18:37:47.082Z,1635532667.082 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T18:37:54.782Z,1635532674.782 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211029T165424/Courier0049.lzma
2021-10-29T18:37:55.785Z,1635532675.785 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0049.lzma.bak
2021-10-29T18:37:55.785Z,1635532675.785 [DataOverHttps](INFO): SBD MOMSN=16170172
2021-10-29T18:38:09.282Z,1635532689.282 [NAL9602](INFO): SBD MO Status=0, MOMSN=6479, MT Status=0, MTMSN=0
2021-10-29T18:38:09.282Z,1635532689.282 [NAL9602](INFO): No messages in MT queue
2021-10-29T18:38:13.030Z,1635532693.030 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20211029T165424/Express0050.lzma
2021-10-29T18:38:14.033Z,1635532694.033 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0050.lzma.bak
2021-10-29T18:38:14.033Z,1635532694.033 [DataOverHttps](INFO): SBD MOMSN=16170175
2021-10-29T18:38:16.183Z,1635532696.183 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T18:38:16.183Z,1635532696.183 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T18:38:16.183Z,1635532696.183 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T18:38:39.986Z,1635532719.986 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-29T18:43:16.788Z,1635532996.788 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T18:43:16.788Z,1635532996.788 [Default:CheckIn:C.Wait] Stopped
2021-10-29T18:43:16.788Z,1635532996.788 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T18:43:16.788Z,1635532996.788 [Default:CheckIn:D] Running Loop=1
2021-10-29T18:43:17.201Z,1635532997.201 [Default:CheckIn:D] Stopped
2021-10-29T18:43:17.201Z,1635532997.201 [Default:CheckIn:E] Running Loop=1
2021-10-29T18:43:17.593Z,1635532997.593 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 104.849707 min 
2021-10-29T18:43:17.594Z,1635532997.594 [Default:CheckIn:E] Stopped
2021-10-29T18:43:17.594Z,1635532997.594 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T18:43:17.594Z,1635532997.594 [Default:CheckIn] Stopped
2021-10-29T18:43:17.594Z,1635532997.594 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T18:43:17.594Z,1635532997.594 [Default:CheckIn](INFO): Running loop #17
2021-10-29T18:43:17.594Z,1635532997.594 [Default:CheckIn] Running Loop=17
2021-10-29T18:43:17.594Z,1635532997.594 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T18:43:17.615Z,1635532997.615 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T18:43:19.610Z,1635532999.610 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184318.00,A,3648.16646,N,12147.28238,W,0.467,0.00,291021,,,A*7F
2021-10-29T18:43:19.613Z,1635532999.613 [NAL9602](INFO): GPS fix at 20211029T184318: (36.802774, -121.788040)
2021-10-29T18:43:19.653Z,1635532999.653 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T18:43:19.653Z,1635532999.653 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T18:43:27.274Z,1635533007.274 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211029T165424/Courier0052.lzma
2021-10-29T18:43:28.277Z,1635533008.277 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0052.lzma.bak
2021-10-29T18:43:28.277Z,1635533008.277 [DataOverHttps](INFO): SBD MOMSN=16170180
2021-10-29T18:43:45.556Z,1635533025.556 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20211029T165424/Express0053.lzma
2021-10-29T18:43:46.085Z,1635533026.085 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0053.lzma.bak
2021-10-29T18:43:46.085Z,1635533026.085 [DataOverHttps](INFO): SBD MOMSN=16170183
2021-10-29T18:43:48.333Z,1635533028.333 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T18:43:48.333Z,1635533028.333 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T18:43:48.333Z,1635533028.333 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T18:45:01.822Z,1635533101.822 [NAL9602](INFO): SBD MO Status=2, MOMSN=6480, MT Status=2, MTMSN=0
2021-10-29T18:45:01.822Z,1635533101.822 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-10-29T18:45:41.042Z,1635533141.042 [NAL9602](INFO): SBD MO Status=2, MOMSN=6480, MT Status=2, MTMSN=0
2021-10-29T18:45:41.042Z,1635533141.042 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-10-29T18:45:53.157Z,1635533153.157 [NAL9602](INFO): SBD MO Status=2, MOMSN=6480, MT Status=2, MTMSN=0
2021-10-29T18:45:53.157Z,1635533153.157 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-10-29T18:46:16.599Z,1635533176.599 [NAL9602](INFO): SBD MO Status=2, MOMSN=6480, MT Status=2, MTMSN=0
2021-10-29T18:46:16.599Z,1635533176.599 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-10-29T18:47:57.590Z,1635533277.590 [NAL9602](INFO): SBD MO Status=2, MOMSN=6480, MT Status=2, MTMSN=0
2021-10-29T18:47:57.590Z,1635533277.590 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-10-29T18:48:22.232Z,1635533302.232 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-10-29T18:48:48.914Z,1635533328.914 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T18:48:48.914Z,1635533328.914 [Default:CheckIn:C.Wait] Stopped
2021-10-29T18:48:48.914Z,1635533328.914 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T18:48:48.914Z,1635533328.914 [Default:CheckIn:D] Running Loop=1
2021-10-29T18:48:49.314Z,1635533329.314 [Default:CheckIn:D] Stopped
2021-10-29T18:48:49.314Z,1635533329.314 [Default:CheckIn:E] Running Loop=1
2021-10-29T18:48:49.715Z,1635533329.715 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 110.384928 min 
2021-10-29T18:48:49.715Z,1635533329.715 [Default:CheckIn:E] Stopped
2021-10-29T18:48:49.715Z,1635533329.715 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T18:48:49.715Z,1635533329.715 [Default:CheckIn] Stopped
2021-10-29T18:48:49.715Z,1635533329.715 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T18:48:49.715Z,1635533329.715 [Default:CheckIn](INFO): Running loop #18
2021-10-29T18:48:49.715Z,1635533329.715 [Default:CheckIn] Running Loop=18
2021-10-29T18:48:49.716Z,1635533329.716 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T18:48:49.716Z,1635533329.716 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T18:48:51.734Z,1635533331.734 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184851.00,A,3648.16325,N,12147.28238,W,0.078,0.00,291021,,,A*73
2021-10-29T18:48:51.736Z,1635533331.736 [NAL9602](INFO): GPS fix at 20211029T184851: (36.802721, -121.788040)
2021-10-29T18:48:51.748Z,1635533331.748 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T18:48:51.748Z,1635533331.748 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T18:48:58.858Z,1635533338.858 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211029T165424/Courier0055.lzma
2021-10-29T18:48:59.861Z,1635533339.861 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0055.lzma.bak
2021-10-29T18:48:59.861Z,1635533339.861 [DataOverHttps](INFO): SBD MOMSN=16170250
2021-10-29T18:49:19.483Z,1635533359.483 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20211029T165424/Express0056.lzma
2021-10-29T18:49:20.485Z,1635533360.485 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0056.lzma.bak
2021-10-29T18:49:20.485Z,1635533360.485 [DataOverHttps](INFO): SBD MOMSN=16170253
2021-10-29T18:49:22.490Z,1635533362.490 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T18:49:22.490Z,1635533362.490 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T18:49:22.490Z,1635533362.490 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T18:49:24.508Z,1635533364.508 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-29T18:54:23.155Z,1635533663.155 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T18:54:23.155Z,1635533663.155 [Default:CheckIn:C.Wait] Stopped
2021-10-29T18:54:23.155Z,1635533663.155 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T18:54:23.156Z,1635533663.156 [Default:CheckIn:D] Running Loop=1
2021-10-29T18:54:23.546Z,1635533663.546 [Default:CheckIn:D] Stopped
2021-10-29T18:54:23.546Z,1635533663.546 [Default:CheckIn:E] Running Loop=1
2021-10-29T18:54:23.956Z,1635533663.956 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 115.955469 min 
2021-10-29T18:54:23.956Z,1635533663.956 [Default:CheckIn:E] Stopped
2021-10-29T18:54:23.956Z,1635533663.956 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T18:54:23.956Z,1635533663.956 [Default:CheckIn] Stopped
2021-10-29T18:54:23.956Z,1635533663.956 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T18:54:23.957Z,1635533663.957 [Default:CheckIn](INFO): Running loop #19
2021-10-29T18:54:23.957Z,1635533663.957 [Default:CheckIn] Running Loop=19
2021-10-29T18:54:23.957Z,1635533663.957 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T18:54:23.957Z,1635533663.957 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T18:54:25.963Z,1635533665.963 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185425.00,A,3648.16349,N,12147.28391,W,0.156,0.00,291021,,,A*78
2021-10-29T18:54:25.965Z,1635533665.965 [NAL9602](INFO): GPS fix at 20211029T185425: (36.802725, -121.788065)
2021-10-29T18:54:25.976Z,1635533665.976 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T18:54:25.976Z,1635533665.976 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T18:54:33.966Z,1635533673.966 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211029T165424/Courier0058.lzma
2021-10-29T18:54:35.522Z,1635533675.522 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0058.lzma.bak
2021-10-29T18:54:35.522Z,1635533675.522 [DataOverHttps](INFO): SBD MOMSN=16170257
2021-10-29T18:54:51.818Z,1635533691.818 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20211029T165424/Express0059.lzma
2021-10-29T18:54:52.821Z,1635533692.821 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0059.lzma.bak
2021-10-29T18:54:52.821Z,1635533692.821 [DataOverHttps](INFO): SBD MOMSN=16170260
2021-10-29T18:54:55.155Z,1635533695.155 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T18:54:55.155Z,1635533695.155 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T18:54:55.155Z,1635533695.155 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T18:54:56.762Z,1635533696.761 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2021-10-29T18:54:56.839Z,1635533696.839 [NAL9602](ERROR): received: 
+CSQ:0

OK80, 2, 0, 0, 0

OK
2021-10-29T18:56:06.690Z,1635533766.690 [NAL9602](INFO): SBD MO Status=2, MOMSN=6480, MT Status=2, MTMSN=0
2021-10-29T18:56:06.690Z,1635533766.690 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-10-29T18:56:34.157Z,1635533794.157 [NAL9602](INFO): SBD MO Status=2, MOMSN=6480, MT Status=2, MTMSN=0
2021-10-29T18:56:34.158Z,1635533794.158 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-10-29T18:59:28.284Z,1635533968.284 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-10-29T18:59:55.772Z,1635533995.772 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T18:59:55.772Z,1635533995.772 [Default:CheckIn:C.Wait] Stopped
2021-10-29T18:59:55.772Z,1635533995.772 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T18:59:55.772Z,1635533995.772 [Default:CheckIn:D] Running Loop=1
2021-10-29T18:59:56.182Z,1635533996.182 [Default:CheckIn:D] Stopped
2021-10-29T18:59:56.182Z,1635533996.182 [Default:CheckIn:E] Running Loop=1
2021-10-29T18:59:56.578Z,1635533996.578 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 121.499390 min 
2021-10-29T18:59:56.579Z,1635533996.579 [Default:CheckIn:E] Stopped
2021-10-29T18:59:56.579Z,1635533996.579 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T18:59:56.579Z,1635533996.579 [Default:CheckIn] Stopped
2021-10-29T18:59:56.579Z,1635533996.579 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T18:59:56.579Z,1635533996.579 [Default:CheckIn](INFO): Running loop #20
2021-10-29T18:59:56.579Z,1635533996.579 [Default:CheckIn] Running Loop=20
2021-10-29T18:59:56.579Z,1635533996.579 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T18:59:56.580Z,1635533996.580 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T18:59:58.590Z,1635533998.590 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185957.00,A,3648.16542,N,12147.28749,W,0.194,64.27,291021,,,A*45
2021-10-29T18:59:58.593Z,1635533998.593 [NAL9602](INFO): GPS fix at 20211029T185957: (36.802757, -121.788125)
2021-10-29T18:59:58.603Z,1635533998.603 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T18:59:58.603Z,1635533998.603 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T19:00:06.354Z,1635534006.354 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211029T165424/Courier0061.lzma
2021-10-29T19:00:07.357Z,1635534007.357 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0061.lzma.bak
2021-10-29T19:00:07.357Z,1635534007.357 [DataOverHttps](INFO): SBD MOMSN=16170307
2021-10-29T19:00:23.279Z,1635534023.279 [DataOverHttps](INFO): Sending 218 bytes from file Logs/20211029T165424/Express0062.lzma
2021-10-29T19:00:24.281Z,1635534024.281 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0062.lzma.bak
2021-10-29T19:00:24.281Z,1635534024.281 [DataOverHttps](INFO): SBD MOMSN=16170310
2021-10-29T19:00:26.529Z,1635534026.529 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T19:00:26.529Z,1635534026.529 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T19:00:26.529Z,1635534026.529 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T19:00:30.500Z,1635534030.500 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-29T19:05:27.083Z,1635534327.083 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T19:05:27.083Z,1635534327.083 [Default:CheckIn:C.Wait] Stopped
2021-10-29T19:05:27.083Z,1635534327.083 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T19:05:27.083Z,1635534327.083 [Default:CheckIn:D] Running Loop=1
2021-10-29T19:05:27.474Z,1635534327.474 [Default:CheckIn:D] Stopped
2021-10-29T19:05:27.474Z,1635534327.474 [Default:CheckIn:E] Running Loop=1
2021-10-29T19:05:27.879Z,1635534327.879 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 127.020931 min 
2021-10-29T19:05:27.879Z,1635534327.879 [Default:CheckIn:E] Stopped
2021-10-29T19:05:27.879Z,1635534327.879 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T19:05:27.879Z,1635534327.879 [Default:CheckIn] Stopped
2021-10-29T19:05:27.879Z,1635534327.879 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T19:05:27.879Z,1635534327.879 [Default:CheckIn](INFO): Running loop #21
2021-10-29T19:05:27.879Z,1635534327.879 [Default:CheckIn] Running Loop=21
2021-10-29T19:05:27.880Z,1635534327.880 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T19:05:27.880Z,1635534327.880 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T19:05:29.892Z,1635534329.892 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190529.00,A,3648.16751,N,12147.28064,W,0.175,64.27,291021,,,A*43
2021-10-29T19:05:29.895Z,1635534329.895 [NAL9602](INFO): GPS fix at 20211029T190529: (36.802792, -121.788011)
2021-10-29T19:05:29.905Z,1635534329.905 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T19:05:29.905Z,1635534329.905 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T19:05:37.982Z,1635534337.982 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211029T165424/Courier0064.lzma
2021-10-29T19:05:38.985Z,1635534338.985 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0064.lzma.bak
2021-10-29T19:05:38.985Z,1635534338.985 [DataOverHttps](INFO): SBD MOMSN=16170314
2021-10-29T19:05:55.763Z,1635534355.763 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20211029T165424/Express0065.lzma
2021-10-29T19:05:56.765Z,1635534356.765 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0065.lzma.bak
2021-10-29T19:05:56.765Z,1635534356.765 [DataOverHttps](INFO): SBD MOMSN=16170317
2021-10-29T19:05:59.012Z,1635534359.012 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T19:05:59.013Z,1635534359.013 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T19:05:59.013Z,1635534359.013 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T19:06:00.600Z,1635534360.600 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2021-10-29T19:06:00.675Z,1635534360.675 [NAL9602](ERROR): received: 
+CSQ:0

OK80, 2, 0, 0, 0

OK
2021-10-29T19:06:56.350Z,1635534416.350 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T19:07:09.678Z,1635534429.678 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T19:07:23.532Z,1635534443.532 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T19:07:37.164Z,1635534457.164 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T19:07:50.553Z,1635534470.553 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T19:08:04.657Z,1635534484.657 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T19:08:18.394Z,1635534498.394 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T19:08:31.731Z,1635534511.731 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T19:08:45.461Z,1635534525.461 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T19:08:58.799Z,1635534538.799 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T19:09:11.914Z,1635534551.914 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T19:09:23.966Z,1635534563.966 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2021-10-29T19:09:23.974Z,1635534563.974 [BPC1](INFO): Calculating totals. Valid battery stick count: 30. Valid reserve battery stick count: 3.
2021-10-29T19:09:23.976Z,1635534563.976 [BPC1](INFO): Received data from all battery sticks.
2021-10-29T19:10:32.244Z,1635534632.244 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-10-29T19:10:59.726Z,1635534659.726 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T19:10:59.726Z,1635534659.726 [Default:CheckIn:C.Wait] Stopped
2021-10-29T19:10:59.726Z,1635534659.726 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T19:10:59.726Z,1635534659.726 [Default:CheckIn:D] Running Loop=1
2021-10-29T19:11:00.132Z,1635534660.132 [Default:CheckIn:D] Stopped
2021-10-29T19:11:00.132Z,1635534660.132 [Default:CheckIn:E] Running Loop=1
2021-10-29T19:11:00.544Z,1635534660.544 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 132.565226 min 
2021-10-29T19:11:00.544Z,1635534660.544 [Default:CheckIn:E] Stopped
2021-10-29T19:11:00.544Z,1635534660.544 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T19:11:00.544Z,1635534660.544 [Default:CheckIn] Stopped
2021-10-29T19:11:00.544Z,1635534660.544 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T19:11:00.545Z,1635534660.545 [Default:CheckIn](INFO): Running loop #22
2021-10-29T19:11:00.545Z,1635534660.545 [Default:CheckIn] Running Loop=22
2021-10-29T19:11:00.545Z,1635534660.545 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T19:11:00.545Z,1635534660.545 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T19:11:02.554Z,1635534662.554 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191101.00,A,3648.16721,N,12147.28421,W,0.311,64.27,291021,,,A*4E
2021-10-29T19:11:02.576Z,1635534662.576 [NAL9602](INFO): GPS fix at 20211029T191101: (36.802787, -121.788070)
2021-10-29T19:11:02.595Z,1635534662.595 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T19:11:02.595Z,1635534662.595 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T19:11:13.594Z,1635534673.594 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20211029T165424/Courier0067.lzma
2021-10-29T19:11:14.597Z,1635534674.597 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0067.lzma.bak
2021-10-29T19:11:14.597Z,1635534674.597 [DataOverHttps](INFO): SBD MOMSN=16170376
2021-10-29T19:11:31.415Z,1635534691.415 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20211029T165424/Express0068.lzma
2021-10-29T19:11:32.417Z,1635534692.417 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0068.lzma.bak
2021-10-29T19:11:32.417Z,1635534692.417 [DataOverHttps](INFO): SBD MOMSN=16170379
2021-10-29T19:11:34.488Z,1635534694.488 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-29T19:11:34.536Z,1635534694.536 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T19:11:34.536Z,1635534694.536 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T19:11:34.536Z,1635534694.536 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T19:16:35.095Z,1635534995.095 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T19:16:35.095Z,1635534995.095 [Default:CheckIn:C.Wait] Stopped
2021-10-29T19:16:35.095Z,1635534995.095 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T19:16:35.096Z,1635534995.096 [Default:CheckIn:D] Running Loop=1
2021-10-29T19:16:35.486Z,1635534995.486 [Default:CheckIn:D] Stopped
2021-10-29T19:16:35.486Z,1635534995.486 [Default:CheckIn:E] Running Loop=1
2021-10-29T19:16:35.907Z,1635534995.907 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 138.154460 min 
2021-10-29T19:16:35.907Z,1635534995.907 [Default:CheckIn:E] Stopped
2021-10-29T19:16:35.907Z,1635534995.907 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T19:16:35.907Z,1635534995.907 [Default:CheckIn] Stopped
2021-10-29T19:16:35.908Z,1635534995.908 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T19:16:35.908Z,1635534995.908 [Default:CheckIn](INFO): Running loop #23
2021-10-29T19:16:35.908Z,1635534995.908 [Default:CheckIn] Running Loop=23
2021-10-29T19:16:35.908Z,1635534995.908 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T19:16:35.908Z,1635534995.908 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T19:16:37.902Z,1635534997.902 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191637.00,A,3648.16641,N,12147.28553,W,0.194,0.00,291021,,,A*77
2021-10-29T19:16:37.913Z,1635534997.913 [NAL9602](INFO): GPS fix at 20211029T191637: (36.802774, -121.788092)
2021-10-29T19:16:37.924Z,1635534997.924 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T19:16:37.924Z,1635534997.924 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T19:16:45.318Z,1635535005.318 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211029T165424/Courier0070.lzma
2021-10-29T19:16:46.321Z,1635535006.321 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0070.lzma.bak
2021-10-29T19:16:46.321Z,1635535006.321 [DataOverHttps](INFO): SBD MOMSN=16170383
2021-10-29T19:17:03.619Z,1635535023.619 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20211029T165424/Express0071.lzma
2021-10-29T19:17:04.621Z,1635535024.621 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0071.lzma.bak
2021-10-29T19:17:04.621Z,1635535024.621 [DataOverHttps](INFO): SBD MOMSN=16170386
2021-10-29T19:17:07.433Z,1635535027.433 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T19:17:07.433Z,1635535027.433 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T19:17:07.433Z,1635535027.433 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T19:17:08.628Z,1635535028.628 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2021-10-29T19:17:08.707Z,1635535028.707 [NAL9602](ERROR): received: 
+CSQ:0

OK80, 2, 0, 0, 0

OK
2021-10-29T19:21:40.188Z,1635535300.188 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-10-29T19:22:08.069Z,1635535328.069 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T19:22:08.069Z,1635535328.069 [Default:CheckIn:C.Wait] Stopped
2021-10-29T19:22:08.070Z,1635535328.070 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T19:22:08.070Z,1635535328.070 [Default:CheckIn:D] Running Loop=1
2021-10-29T19:22:08.486Z,1635535328.486 [Default:CheckIn:D] Stopped
2021-10-29T19:22:08.486Z,1635535328.486 [Default:CheckIn:E] Running Loop=1
2021-10-29T19:22:08.905Z,1635535328.905 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 143.704460 min 
2021-10-29T19:22:08.905Z,1635535328.905 [Default:CheckIn:E] Stopped
2021-10-29T19:22:08.905Z,1635535328.905 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T19:22:08.905Z,1635535328.905 [Default:CheckIn] Stopped
2021-10-29T19:22:08.905Z,1635535328.905 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T19:22:08.905Z,1635535328.905 [Default:CheckIn](INFO): Running loop #24
2021-10-29T19:22:08.905Z,1635535328.905 [Default:CheckIn] Running Loop=24
2021-10-29T19:22:08.905Z,1635535328.905 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T19:22:08.906Z,1635535328.906 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T19:22:10.894Z,1635535330.894 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192210.00,A,3648.16864,N,12147.28287,W,0.330,0.00,291021,,,A*7E
2021-10-29T19:22:10.897Z,1635535330.897 [NAL9602](INFO): GPS fix at 20211029T192210: (36.802811, -121.788048)
2021-10-29T19:22:10.928Z,1635535330.928 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T19:22:10.928Z,1635535330.928 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T19:22:18.566Z,1635535338.566 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211029T165424/Courier0073.lzma
2021-10-29T19:22:19.569Z,1635535339.569 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0073.lzma.bak
2021-10-29T19:22:19.569Z,1635535339.569 [DataOverHttps](INFO): SBD MOMSN=16170389
2021-10-29T19:22:36.855Z,1635535356.855 [DataOverHttps](INFO): Sending 217 bytes from file Logs/20211029T165424/Express0074.lzma
2021-10-29T19:22:37.857Z,1635535357.857 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0074.lzma.bak
2021-10-29T19:22:37.857Z,1635535357.857 [DataOverHttps](INFO): SBD MOMSN=16170392
2021-10-29T19:22:40.019Z,1635535360.019 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T19:22:40.019Z,1635535360.019 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T19:22:40.019Z,1635535360.019 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T19:22:43.612Z,1635535363.612 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-29T19:27:40.584Z,1635535660.584 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T19:27:40.584Z,1635535660.584 [Default:CheckIn:C.Wait] Stopped
2021-10-29T19:27:40.584Z,1635535660.584 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T19:27:40.584Z,1635535660.584 [Default:CheckIn:D] Running Loop=1
2021-10-29T19:27:40.979Z,1635535660.979 [Default:CheckIn:D] Stopped
2021-10-29T19:27:40.979Z,1635535660.979 [Default:CheckIn:E] Running Loop=1
2021-10-29T19:27:41.374Z,1635535661.374 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 149.246012 min 
2021-10-29T19:27:41.374Z,1635535661.374 [Default:CheckIn:E] Stopped
2021-10-29T19:27:41.374Z,1635535661.374 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T19:27:41.374Z,1635535661.374 [Default:CheckIn] Stopped
2021-10-29T19:27:41.412Z,1635535661.412 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T19:27:41.413Z,1635535661.413 [Default:CheckIn](INFO): Running loop #25
2021-10-29T19:27:41.415Z,1635535661.415 [Default:CheckIn] Running Loop=25
2021-10-29T19:27:41.419Z,1635535661.419 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T19:27:41.420Z,1635535661.420 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T19:27:43.387Z,1635535663.387 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192742.00,A,3648.16079,N,12147.29199,W,0.175,223.49,291021,,,A*78
2021-10-29T19:27:43.389Z,1635535663.389 [NAL9602](INFO): GPS fix at 20211029T192742: (36.802680, -121.788200)
2021-10-29T19:27:43.400Z,1635535663.400 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T19:27:43.400Z,1635535663.400 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T19:27:51.114Z,1635535671.114 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211029T165424/Courier0076.lzma
2021-10-29T19:27:52.117Z,1635535672.117 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0076.lzma.bak
2021-10-29T19:27:52.117Z,1635535672.117 [DataOverHttps](INFO): SBD MOMSN=16170396
2021-10-29T19:28:08.915Z,1635535688.915 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20211029T165424/Express0077.lzma
2021-10-29T19:28:09.917Z,1635535689.917 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0077.lzma.bak
2021-10-29T19:28:09.917Z,1635535689.917 [DataOverHttps](INFO): SBD MOMSN=16170400
2021-10-29T19:28:12.100Z,1635535692.100 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T19:28:12.100Z,1635535692.100 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T19:28:12.100Z,1635535692.100 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T19:28:14.094Z,1635535694.094 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2021-10-29T19:28:14.167Z,1635535694.167 [NAL9602](ERROR): received: 
+CSQ:0

OK80, 2, 0, 0, 0

OK
2021-10-29T19:32:45.172Z,1635535965.172 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-10-29T19:33:12.723Z,1635535992.723 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T19:33:12.723Z,1635535992.723 [Default:CheckIn:C.Wait] Stopped
2021-10-29T19:33:12.723Z,1635535992.723 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T19:33:12.723Z,1635535992.723 [Default:CheckIn:D] Running Loop=1
2021-10-29T19:33:13.131Z,1635535993.131 [Default:CheckIn:D] Stopped
2021-10-29T19:33:13.131Z,1635535993.131 [Default:CheckIn:E] Running Loop=1
2021-10-29T19:33:13.579Z,1635535993.579 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 154.781868 min 
2021-10-29T19:33:13.579Z,1635535993.579 [Default:CheckIn:E] Stopped
2021-10-29T19:33:13.580Z,1635535993.580 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T19:33:13.580Z,1635535993.580 [Default:CheckIn] Stopped
2021-10-29T19:33:13.580Z,1635535993.580 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T19:33:13.580Z,1635535993.580 [Default:CheckIn](INFO): Running loop #26
2021-10-29T19:33:13.580Z,1635535993.580 [Default:CheckIn] Running Loop=26
2021-10-29T19:33:13.580Z,1635535993.580 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T19:33:13.580Z,1635535993.580 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T19:33:15.528Z,1635535995.528 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193314.00,A,3648.16894,N,12147.28455,W,0.330,223.49,291021,,,A*72
2021-10-29T19:33:15.530Z,1635535995.530 [NAL9602](INFO): GPS fix at 20211029T193314: (36.802816, -121.788076)
2021-10-29T19:33:15.548Z,1635535995.548 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T19:33:15.548Z,1635535995.548 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T19:33:22.818Z,1635536002.818 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211029T165424/Courier0079.lzma
2021-10-29T19:33:23.821Z,1635536003.821 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0079.lzma.bak
2021-10-29T19:33:23.821Z,1635536003.821 [DataOverHttps](INFO): SBD MOMSN=16170403
2021-10-29T19:33:40.603Z,1635536020.603 [DataOverHttps](INFO): Sending 217 bytes from file Logs/20211029T165424/Express0080.lzma
2021-10-29T19:33:41.605Z,1635536021.605 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0080.lzma.bak
2021-10-29T19:33:41.605Z,1635536021.605 [DataOverHttps](INFO): SBD MOMSN=16170406
2021-10-29T19:33:43.810Z,1635536023.810 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T19:33:43.810Z,1635536023.810 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T19:33:43.810Z,1635536023.810 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T19:33:47.436Z,1635536027.436 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-29T19:38:44.498Z,1635536324.498 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T19:38:44.498Z,1635536324.498 [Default:CheckIn:C.Wait] Stopped
2021-10-29T19:38:44.498Z,1635536324.498 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T19:38:44.498Z,1635536324.498 [Default:CheckIn:D] Running Loop=1
2021-10-29T19:38:44.898Z,1635536324.898 [Default:CheckIn:D] Stopped
2021-10-29T19:38:44.899Z,1635536324.899 [Default:CheckIn:E] Running Loop=1
2021-10-29T19:38:45.310Z,1635536325.310 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 160.311344 min 
2021-10-29T19:38:45.311Z,1635536325.311 [Default:CheckIn:E] Stopped
2021-10-29T19:38:45.311Z,1635536325.311 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T19:38:45.311Z,1635536325.311 [Default:CheckIn] Stopped
2021-10-29T19:38:45.311Z,1635536325.311 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T19:38:45.311Z,1635536325.311 [Default:CheckIn](INFO): Running loop #27
2021-10-29T19:38:45.311Z,1635536325.311 [Default:CheckIn] Running Loop=27
2021-10-29T19:38:45.311Z,1635536325.311 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T19:38:45.311Z,1635536325.311 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T19:38:47.318Z,1635536327.318 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193846.00,A,3648.16496,N,12147.28380,W,0.233,212.78,291021,,,A*7D
2021-10-29T19:38:47.320Z,1635536327.320 [NAL9602](INFO): GPS fix at 20211029T193846: (36.802749, -121.788063)
2021-10-29T19:38:47.352Z,1635536327.352 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T19:38:47.352Z,1635536327.352 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T19:38:54.810Z,1635536334.810 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211029T165424/Courier0082.lzma
2021-10-29T19:38:55.813Z,1635536335.813 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0082.lzma.bak
2021-10-29T19:38:55.813Z,1635536335.813 [DataOverHttps](INFO): SBD MOMSN=16170410
2021-10-29T19:39:15.979Z,1635536355.979 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20211029T165424/Express0083.lzma
2021-10-29T19:39:16.981Z,1635536356.981 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0083.lzma.bak
2021-10-29T19:39:16.981Z,1635536356.981 [DataOverHttps](INFO): SBD MOMSN=16170413
2021-10-29T19:39:18.064Z,1635536358.064 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2021-10-29T19:39:18.139Z,1635536358.139 [NAL9602](ERROR): received: 
+CSQ:0

OK80, 2, 0, 0, 0

OK
2021-10-29T19:39:19.327Z,1635536359.327 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T19:39:19.327Z,1635536359.327 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T19:39:19.328Z,1635536359.328 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T19:43:14.467Z,1635536594.467 [NAL9602](INFO): SBD MO Status=2, MOMSN=6480, MT Status=2, MTMSN=0
2021-10-29T19:43:14.467Z,1635536594.467 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-10-29T19:43:49.617Z,1635536629.617 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-10-29T19:44:19.926Z,1635536659.926 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T19:44:19.926Z,1635536659.926 [Default:CheckIn:C.Wait] Stopped
2021-10-29T19:44:19.926Z,1635536659.926 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T19:44:19.926Z,1635536659.926 [Default:CheckIn:D] Running Loop=1
2021-10-29T19:44:20.311Z,1635536660.311 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-29T19:44:20.348Z,1635536660.348 [Default:CheckIn:D] Stopped
2021-10-29T19:44:20.348Z,1635536660.348 [Default:CheckIn:E] Running Loop=1
2021-10-29T19:44:20.730Z,1635536660.730 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 165.902165 min 
2021-10-29T19:44:20.730Z,1635536660.730 [Default:CheckIn:E] Stopped
2021-10-29T19:44:20.747Z,1635536660.747 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T19:44:20.747Z,1635536660.747 [Default:CheckIn] Stopped
2021-10-29T19:44:20.747Z,1635536660.747 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T19:44:20.747Z,1635536660.747 [Default:CheckIn](INFO): Running loop #28
2021-10-29T19:44:20.747Z,1635536660.747 [Default:CheckIn] Running Loop=28
2021-10-29T19:44:20.747Z,1635536660.747 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T19:44:20.748Z,1635536660.748 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T19:44:22.742Z,1635536662.742 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194422.00,A,3648.16599,N,12147.28076,W,0.078,194.11,291021,,,A*7F
2021-10-29T19:44:22.745Z,1635536662.745 [NAL9602](INFO): GPS fix at 20211029T194422: (36.802766, -121.788013)
2021-10-29T19:44:22.755Z,1635536662.755 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T19:44:22.755Z,1635536662.755 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T19:44:30.086Z,1635536670.086 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211029T165424/Courier0085.lzma
2021-10-29T19:44:31.089Z,1635536671.089 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0085.lzma.bak
2021-10-29T19:44:31.089Z,1635536671.089 [DataOverHttps](INFO): SBD MOMSN=16170469
2021-10-29T19:44:47.851Z,1635536687.851 [DataOverHttps](INFO): Sending 214 bytes from file Logs/20211029T165424/Express0086.lzma
2021-10-29T19:44:48.853Z,1635536688.853 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0086.lzma.bak
2021-10-29T19:44:48.853Z,1635536688.853 [DataOverHttps](INFO): SBD MOMSN=16170472
2021-10-29T19:44:51.039Z,1635536691.039 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T19:44:51.039Z,1635536691.039 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T19:44:51.039Z,1635536691.039 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T19:44:53.440Z,1635536693.440 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2021-10-29T19:44:53.515Z,1635536693.515 [NAL9602](ERROR): received: 
+CSQ:0

OK80, 2, 0, 0, 0

OK
2021-10-29T19:46:22.374Z,1635536782.374 [NAL9602](INFO): SBD MO Status=2, MOMSN=6480, MT Status=2, MTMSN=0
2021-10-29T19:46:22.374Z,1635536782.374 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-10-29T19:49:25.390Z,1635536965.390 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-10-29T19:49:51.684Z,1635536991.684 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T19:49:51.684Z,1635536991.684 [Default:CheckIn:C.Wait] Stopped
2021-10-29T19:49:51.684Z,1635536991.684 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T19:49:51.684Z,1635536991.684 [Default:CheckIn:D] Running Loop=1
2021-10-29T19:49:52.098Z,1635536992.098 [Default:CheckIn:D] Stopped
2021-10-29T19:49:52.098Z,1635536992.098 [Default:CheckIn:E] Running Loop=1
2021-10-29T19:49:52.490Z,1635536992.490 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 171.431331 min 
2021-10-29T19:49:52.490Z,1635536992.490 [Default:CheckIn:E] Stopped
2021-10-29T19:49:52.490Z,1635536992.490 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T19:49:52.490Z,1635536992.490 [Default:CheckIn] Stopped
2021-10-29T19:49:52.491Z,1635536992.491 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T19:49:52.491Z,1635536992.491 [Default:CheckIn](INFO): Running loop #29
2021-10-29T19:49:52.491Z,1635536992.491 [Default:CheckIn] Running Loop=29
2021-10-29T19:49:52.491Z,1635536992.491 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T19:49:52.491Z,1635536992.491 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T19:49:54.502Z,1635536994.502 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194953.00,A,3648.17057,N,12147.27984,W,0.292,194.11,291021,,,A*7F
2021-10-29T19:49:54.506Z,1635536994.506 [NAL9602](INFO): GPS fix at 20211029T194953: (36.802843, -121.787997)
2021-10-29T19:49:54.519Z,1635536994.519 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T19:49:54.519Z,1635536994.519 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T19:50:01.522Z,1635537001.522 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211029T165424/Courier0088.lzma
2021-10-29T19:50:02.525Z,1635537002.525 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0088.lzma.bak
2021-10-29T19:50:02.525Z,1635537002.525 [DataOverHttps](INFO): SBD MOMSN=16170502
2021-10-29T19:50:19.267Z,1635537019.267 [DataOverHttps](INFO): Sending 218 bytes from file Logs/20211029T165424/Express0089.lzma
2021-10-29T19:50:20.269Z,1635537020.269 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0089.lzma.bak
2021-10-29T19:50:20.269Z,1635537020.269 [DataOverHttps](INFO): SBD MOMSN=16170505
2021-10-29T19:50:22.439Z,1635537022.439 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T19:50:22.439Z,1635537022.439 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T19:50:22.439Z,1635537022.439 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T19:50:26.424Z,1635537026.424 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-29T19:55:23.006Z,1635537323.006 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T19:55:23.006Z,1635537323.006 [Default:CheckIn:C.Wait] Stopped
2021-10-29T19:55:23.006Z,1635537323.006 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T19:55:23.006Z,1635537323.006 [Default:CheckIn:D] Running Loop=1
2021-10-29T19:55:23.410Z,1635537323.410 [Default:CheckIn:D] Stopped
2021-10-29T19:55:23.410Z,1635537323.410 [Default:CheckIn:E] Running Loop=1
2021-10-29T19:55:23.811Z,1635537323.811 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 176.953206 min 
2021-10-29T19:55:23.812Z,1635537323.812 [Default:CheckIn:E] Stopped
2021-10-29T19:55:23.812Z,1635537323.812 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T19:55:23.812Z,1635537323.812 [Default:CheckIn] Stopped
2021-10-29T19:55:23.812Z,1635537323.812 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T19:55:23.812Z,1635537323.812 [Default:CheckIn](INFO): Running loop #30
2021-10-29T19:55:23.812Z,1635537323.812 [Default:CheckIn] Running Loop=30
2021-10-29T19:55:23.812Z,1635537323.812 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T19:55:23.812Z,1635537323.812 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T19:55:25.822Z,1635537325.822 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195525.00,A,3648.16340,N,12147.27313,W,0.078,194.11,291021,,,A*75
2021-10-29T19:55:25.825Z,1635537325.825 [NAL9602](INFO): GPS fix at 20211029T195525: (36.802723, -121.787886)
2021-10-29T19:55:25.835Z,1635537325.835 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T19:55:25.836Z,1635537325.836 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T19:55:32.978Z,1635537332.978 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211029T165424/Courier0091.lzma
2021-10-29T19:55:33.981Z,1635537333.981 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0091.lzma.bak
2021-10-29T19:55:33.981Z,1635537333.981 [DataOverHttps](INFO): SBD MOMSN=16170509
2021-10-29T19:55:50.858Z,1635537350.858 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20211029T165424/Express0092.lzma
2021-10-29T19:55:51.862Z,1635537351.862 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0092.lzma.bak
2021-10-29T19:55:51.862Z,1635537351.862 [DataOverHttps](INFO): SBD MOMSN=16170512
2021-10-29T19:55:54.124Z,1635537354.124 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T19:55:54.124Z,1635537354.124 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T19:55:54.124Z,1635537354.124 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T19:55:56.524Z,1635537356.524 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2021-10-29T19:55:56.599Z,1635537356.599 [NAL9602](ERROR): received: 
+CSQ:0

OK80, 2, 0, 0, 0

OK
2021-10-29T20:00:28.472Z,1635537628.472 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-10-29T20:00:54.738Z,1635537654.738 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T20:00:54.738Z,1635537654.738 [Default:CheckIn:C.Wait] Stopped
2021-10-29T20:00:54.738Z,1635537654.738 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T20:00:54.739Z,1635537654.739 [Default:CheckIn:D] Running Loop=1
2021-10-29T20:00:55.151Z,1635537655.151 [Default:CheckIn:D] Stopped
2021-10-29T20:00:55.151Z,1635537655.151 [Default:CheckIn:E] Running Loop=1
2021-10-29T20:00:55.546Z,1635537655.546 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 182.482210 min 
2021-10-29T20:00:55.546Z,1635537655.546 [Default:CheckIn:E] Stopped
2021-10-29T20:00:55.546Z,1635537655.546 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T20:00:55.546Z,1635537655.546 [Default:CheckIn] Stopped
2021-10-29T20:00:55.546Z,1635537655.546 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T20:00:55.546Z,1635537655.546 [Default:CheckIn](INFO): Running loop #31
2021-10-29T20:00:55.567Z,1635537655.567 [Default:CheckIn] Running Loop=31
2021-10-29T20:00:55.567Z,1635537655.567 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T20:00:55.567Z,1635537655.567 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T20:00:57.558Z,1635537657.558 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200056.00,A,3648.16481,N,12147.28506,W,0.078,0.00,291021,,,A*70
2021-10-29T20:00:57.560Z,1635537657.560 [NAL9602](INFO): GPS fix at 20211029T200056: (36.802747, -121.788084)
2021-10-29T20:00:57.580Z,1635537657.580 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T20:00:57.580Z,1635537657.580 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T20:01:10.750Z,1635537670.750 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20211029T165424/Courier0094.lzma
2021-10-29T20:01:11.756Z,1635537671.756 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0094.lzma.bak
2021-10-29T20:01:11.756Z,1635537671.756 [DataOverHttps](INFO): SBD MOMSN=16170551
2021-10-29T20:01:29.368Z,1635537689.368 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-29T20:01:29.811Z,1635537689.811 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20211029T165424/Express0095.lzma
2021-10-29T20:01:30.813Z,1635537690.813 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0095.lzma.bak
2021-10-29T20:01:30.813Z,1635537690.813 [DataOverHttps](INFO): SBD MOMSN=16170554
2021-10-29T20:01:33.448Z,1635537693.448 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T20:01:33.448Z,1635537693.448 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T20:01:33.448Z,1635537693.448 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T20:06:33.998Z,1635537993.998 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T20:06:33.999Z,1635537993.999 [Default:CheckIn:C.Wait] Stopped
2021-10-29T20:06:33.999Z,1635537993.999 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T20:06:33.999Z,1635537993.999 [Default:CheckIn:D] Running Loop=1
2021-10-29T20:06:34.411Z,1635537994.411 [Default:CheckIn:D] Stopped
2021-10-29T20:06:34.411Z,1635537994.411 [Default:CheckIn:E] Running Loop=1
2021-10-29T20:06:34.819Z,1635537994.819 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 188.136540 min 
2021-10-29T20:06:34.819Z,1635537994.819 [Default:CheckIn:E] Stopped
2021-10-29T20:06:34.820Z,1635537994.820 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T20:06:34.820Z,1635537994.820 [Default:CheckIn] Stopped
2021-10-29T20:06:34.820Z,1635537994.820 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T20:06:34.820Z,1635537994.820 [Default:CheckIn](INFO): Running loop #32
2021-10-29T20:06:34.820Z,1635537994.820 [Default:CheckIn] Running Loop=32
2021-10-29T20:06:34.820Z,1635537994.820 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T20:06:34.820Z,1635537994.820 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T20:06:36.822Z,1635537996.822 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200636.00,A,3648.16549,N,12147.28211,W,0.097,213.25,291021,,,A*72
2021-10-29T20:06:36.825Z,1635537996.825 [NAL9602](INFO): GPS fix at 20211029T200636: (36.802758, -121.788035)
2021-10-29T20:06:36.858Z,1635537996.858 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T20:06:36.858Z,1635537996.858 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T20:06:44.526Z,1635538004.526 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20211029T165424/Courier0097.lzma
2021-10-29T20:06:45.529Z,1635538005.529 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0097.lzma.bak
2021-10-29T20:06:45.529Z,1635538005.529 [DataOverHttps](INFO): SBD MOMSN=16170558
2021-10-29T20:07:02.314Z,1635538022.314 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20211029T165424/Express0098.lzma
2021-10-29T20:07:03.317Z,1635538023.317 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0098.lzma.bak
2021-10-29T20:07:03.317Z,1635538023.317 [DataOverHttps](INFO): SBD MOMSN=16170561
2021-10-29T20:07:06.369Z,1635538026.369 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T20:07:06.369Z,1635538026.369 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T20:07:06.369Z,1635538026.369 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T20:07:07.553Z,1635538027.553 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2021-10-29T20:07:07.627Z,1635538027.627 [NAL9602](ERROR): received: 
+CSQ:0

OK80, 2, 0, 0, 0

OK
2021-10-29T20:11:41.966Z,1635538301.966 [NAL9602](INFO): SBD MO Status=0, MOMSN=6480, MT Status=0, MTMSN=0
2021-10-29T20:11:41.966Z,1635538301.966 [NAL9602](INFO): No messages in MT queue
2021-10-29T20:11:52.539Z,1635538312.539 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T20:12:05.913Z,1635538325.913 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T20:12:07.045Z,1635538327.045 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T20:12:07.045Z,1635538327.045 [Default:CheckIn:C.Wait] Stopped
2021-10-29T20:12:07.045Z,1635538327.045 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T20:12:07.045Z,1635538327.045 [Default:CheckIn:D] Running Loop=1
2021-10-29T20:12:07.452Z,1635538327.452 [Default:CheckIn:D] Stopped
2021-10-29T20:12:07.452Z,1635538327.452 [Default:CheckIn:E] Running Loop=1
2021-10-29T20:12:07.860Z,1635538327.860 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 193.687223 min 
2021-10-29T20:12:07.860Z,1635538327.860 [Default:CheckIn:E] Stopped
2021-10-29T20:12:07.860Z,1635538327.860 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T20:12:07.860Z,1635538327.860 [Default:CheckIn] Stopped
2021-10-29T20:12:07.860Z,1635538327.860 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T20:12:07.861Z,1635538327.861 [Default:CheckIn](INFO): Running loop #33
2021-10-29T20:12:07.861Z,1635538327.861 [Default:CheckIn] Running Loop=33
2021-10-29T20:12:07.861Z,1635538327.861 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T20:12:07.861Z,1635538327.861 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T20:12:09.845Z,1635538329.845 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201209.00,A,3648.16577,N,12147.28234,W,0.564,213.25,291021,,,A*78
2021-10-29T20:12:09.847Z,1635538329.847 [NAL9602](INFO): GPS fix at 20211029T201209: (36.802763, -121.788039)
2021-10-29T20:12:09.858Z,1635538329.858 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T20:12:09.858Z,1635538329.858 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T20:12:18.391Z,1635538338.391 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211029T165424/Courier0100.lzma
2021-10-29T20:12:19.195Z,1635538339.195 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T20:12:19.393Z,1635538339.393 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0100.lzma.bak
2021-10-29T20:12:19.394Z,1635538339.394 [DataOverHttps](INFO): SBD MOMSN=16170604
2021-10-29T20:12:32.876Z,1635538352.876 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T20:12:36.247Z,1635538356.247 [DataOverHttps](INFO): Sending 141 bytes from file Logs/20211029T165424/Express0101.lzma
2021-10-29T20:12:37.250Z,1635538357.250 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0101.lzma.bak
2021-10-29T20:12:37.250Z,1635538357.250 [DataOverHttps](INFO): SBD MOMSN=16170607
2021-10-29T20:12:39.364Z,1635538359.364 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T20:12:39.364Z,1635538359.364 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T20:12:39.364Z,1635538359.364 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T20:12:42.568Z,1635538362.568 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-29T20:12:46.267Z,1635538366.267 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T20:12:59.532Z,1635538379.532 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T20:13:12.865Z,1635538392.865 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T20:13:26.709Z,1635538406.709 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T20:13:39.934Z,1635538419.934 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T20:13:53.264Z,1635538433.264 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T20:14:06.597Z,1635538446.597 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-10-29T20:14:21.552Z,1635538461.552 [BPC1](INFO): Calculating totals. Valid battery stick count: 29. Valid reserve battery stick count: 4.
2021-10-29T20:14:21.555Z,1635538461.555 [BPC1](INFO): Received data from all battery sticks.
2021-10-29T20:17:39.918Z,1635538659.918 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T20:17:39.918Z,1635538659.918 [Default:CheckIn:C.Wait] Stopped
2021-10-29T20:17:39.918Z,1635538659.918 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T20:17:39.918Z,1635538659.918 [Default:CheckIn:D] Running Loop=1
2021-10-29T20:17:40.330Z,1635538660.330 [Default:CheckIn:D] Stopped
2021-10-29T20:17:40.330Z,1635538660.330 [Default:CheckIn:E] Running Loop=1
2021-10-29T20:17:40.729Z,1635538660.729 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 199.235205 min 
2021-10-29T20:17:40.729Z,1635538660.729 [Default:CheckIn:E] Stopped
2021-10-29T20:17:40.729Z,1635538660.729 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T20:17:40.729Z,1635538660.729 [Default:CheckIn] Stopped
2021-10-29T20:17:40.729Z,1635538660.729 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T20:17:40.729Z,1635538660.729 [Default:CheckIn](INFO): Running loop #34
2021-10-29T20:17:40.729Z,1635538660.729 [Default:CheckIn] Running Loop=34
2021-10-29T20:17:40.729Z,1635538660.729 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T20:17:40.730Z,1635538660.730 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T20:17:42.742Z,1635538662.742 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201742.00,A,3648.16396,N,12147.28579,W,0.136,0.00,291021,,,A*71
2021-10-29T20:17:42.753Z,1635538662.753 [NAL9602](INFO): GPS fix at 20211029T201742: (36.802733, -121.788096)
2021-10-29T20:17:42.763Z,1635538662.763 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T20:17:42.763Z,1635538662.763 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T20:17:50.054Z,1635538670.054 [DataOverHttps](INFO): Sending 84 bytes from file Logs/20211029T165424/Courier0103.lzma
2021-10-29T20:17:51.057Z,1635538671.057 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0103.lzma.bak
2021-10-29T20:17:51.057Z,1635538671.057 [DataOverHttps](INFO): SBD MOMSN=16170611
2021-10-29T20:18:07.847Z,1635538687.847 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20211029T165424/Express0104.lzma
2021-10-29T20:18:08.849Z,1635538688.849 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0104.lzma.bak
2021-10-29T20:18:08.849Z,1635538688.849 [DataOverHttps](INFO): SBD MOMSN=16170614
2021-10-29T20:18:11.853Z,1635538691.853 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T20:18:11.853Z,1635538691.853 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T20:18:11.853Z,1635538691.853 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T20:19:48.389Z,1635538788.389 [NAL9602](INFO): SBD MO Status=2, MOMSN=6481, MT Status=2, MTMSN=0
2021-10-29T20:19:48.390Z,1635538788.390 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-10-29T20:21:31.414Z,1635538891.414 [NAL9602](INFO): SBD MO Status=0, MOMSN=6481, MT Status=0, MTMSN=0
2021-10-29T20:21:31.414Z,1635538891.414 [NAL9602](INFO): No messages in MT queue
2021-10-29T20:22:02.133Z,1635538922.133 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-29T20:23:12.513Z,1635538992.513 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T20:23:12.513Z,1635538992.513 [Default:CheckIn:C.Wait] Stopped
2021-10-29T20:23:12.513Z,1635538992.513 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T20:23:12.514Z,1635538992.514 [Default:CheckIn:D] Running Loop=1
2021-10-29T20:23:12.880Z,1635538992.880 [Default:CheckIn:D] Stopped
2021-10-29T20:23:12.880Z,1635538992.880 [Default:CheckIn:E] Running Loop=1
2021-10-29T20:23:13.316Z,1635538993.316 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 204.777702 min 
2021-10-29T20:23:13.316Z,1635538993.316 [Default:CheckIn:E] Stopped
2021-10-29T20:23:13.317Z,1635538993.317 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T20:23:13.317Z,1635538993.317 [Default:CheckIn] Stopped
2021-10-29T20:23:13.317Z,1635538993.317 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T20:23:13.317Z,1635538993.317 [Default:CheckIn](INFO): Running loop #35
2021-10-29T20:23:13.317Z,1635538993.317 [Default:CheckIn] Running Loop=35
2021-10-29T20:23:13.317Z,1635538993.317 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T20:23:13.317Z,1635538993.317 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T20:23:15.286Z,1635538995.286 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202314.00,A,3648.16492,N,12147.27647,W,0.389,0.00,291021,,,A*71
2021-10-29T20:23:15.289Z,1635538995.289 [NAL9602](INFO): GPS fix at 20211029T202314: (36.802749, -121.787941)
2021-10-29T20:23:15.319Z,1635538995.319 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T20:23:15.319Z,1635538995.319 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T20:23:23.002Z,1635539003.002 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211029T165424/Courier0106.lzma
2021-10-29T20:23:24.005Z,1635539004.005 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0106.lzma.bak
2021-10-29T20:23:24.005Z,1635539004.005 [DataOverHttps](INFO): SBD MOMSN=16170699
2021-10-29T20:23:40.798Z,1635539020.798 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20211029T165424/Express0107.lzma
2021-10-29T20:23:41.801Z,1635539021.801 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0107.lzma.bak
2021-10-29T20:23:41.801Z,1635539021.801 [DataOverHttps](INFO): SBD MOMSN=16170702
2021-10-29T20:23:44.000Z,1635539024.000 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T20:23:44.000Z,1635539024.000 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T20:23:44.000Z,1635539024.000 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T20:23:49.222Z,1635539029.222 [NAL9602](INFO): SBD MO Status=2, MOMSN=6482, MT Status=2, MTMSN=0
2021-10-29T20:23:49.222Z,1635539029.222 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-10-29T20:24:03.366Z,1635539043.366 [NAL9602](INFO): SBD MO Status=2, MOMSN=6482, MT Status=2, MTMSN=0
2021-10-29T20:24:03.366Z,1635539043.366 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-10-29T20:25:03.965Z,1635539103.965 [NAL9602](INFO): SBD MO Status=2, MOMSN=6482, MT Status=2, MTMSN=0
2021-10-29T20:25:03.965Z,1635539103.965 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-10-29T20:28:17.555Z,1635539297.555 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-10-29T20:28:44.626Z,1635539324.626 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T20:28:44.626Z,1635539324.626 [Default:CheckIn:C.Wait] Stopped
2021-10-29T20:28:44.626Z,1635539324.626 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T20:28:44.627Z,1635539324.627 [Default:CheckIn:D] Running Loop=1
2021-10-29T20:28:45.030Z,1635539325.030 [Default:CheckIn:D] Stopped
2021-10-29T20:28:45.030Z,1635539325.030 [Default:CheckIn:E] Running Loop=1
2021-10-29T20:28:45.431Z,1635539325.431 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 210.313525 min 
2021-10-29T20:28:45.432Z,1635539325.432 [Default:CheckIn:E] Stopped
2021-10-29T20:28:45.432Z,1635539325.432 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T20:28:45.432Z,1635539325.432 [Default:CheckIn] Stopped
2021-10-29T20:28:45.432Z,1635539325.432 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T20:28:45.432Z,1635539325.432 [Default:CheckIn](INFO): Running loop #36
2021-10-29T20:28:45.432Z,1635539325.432 [Default:CheckIn] Running Loop=36
2021-10-29T20:28:45.432Z,1635539325.432 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T20:28:45.432Z,1635539325.432 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T20:28:47.446Z,1635539327.446 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202846.00,A,3648.16191,N,12147.27804,W,0.097,95.72,291021,,,A*47
2021-10-29T20:28:47.449Z,1635539327.449 [NAL9602](INFO): GPS fix at 20211029T202846: (36.802698, -121.787967)
2021-10-29T20:28:47.479Z,1635539327.479 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T20:28:47.480Z,1635539327.480 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T20:28:54.794Z,1635539334.794 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211029T165424/Courier0109.lzma
2021-10-29T20:28:55.800Z,1635539335.800 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0109.lzma.bak
2021-10-29T20:28:55.800Z,1635539335.800 [DataOverHttps](INFO): SBD MOMSN=16170772
2021-10-29T20:29:15.739Z,1635539355.739 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20211029T165424/Express0110.lzma
2021-10-29T20:29:16.741Z,1635539356.741 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0110.lzma.bak
2021-10-29T20:29:16.741Z,1635539356.741 [DataOverHttps](INFO): SBD MOMSN=16170775
2021-10-29T20:29:19.023Z,1635539359.023 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T20:29:19.023Z,1635539359.023 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T20:29:19.024Z,1635539359.024 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T20:29:19.396Z,1635539359.396 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-29T20:34:19.650Z,1635539659.650 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T20:34:19.650Z,1635539659.650 [Default:CheckIn:C.Wait] Stopped
2021-10-29T20:34:19.650Z,1635539659.650 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T20:34:19.650Z,1635539659.650 [Default:CheckIn:D] Running Loop=1
2021-10-29T20:34:20.055Z,1635539660.055 [Default:CheckIn:D] Stopped
2021-10-29T20:34:20.055Z,1635539660.055 [Default:CheckIn:E] Running Loop=1
2021-10-29T20:34:20.467Z,1635539660.467 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 215.897282 min 
2021-10-29T20:34:20.467Z,1635539660.467 [Default:CheckIn:E] Stopped
2021-10-29T20:34:20.467Z,1635539660.467 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T20:34:20.467Z,1635539660.467 [Default:CheckIn] Stopped
2021-10-29T20:34:20.467Z,1635539660.467 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T20:34:20.467Z,1635539660.467 [Default:CheckIn](INFO): Running loop #37
2021-10-29T20:34:20.467Z,1635539660.467 [Default:CheckIn] Running Loop=37
2021-10-29T20:34:20.468Z,1635539660.468 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T20:34:20.468Z,1635539660.468 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T20:34:22.482Z,1635539662.482 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203421.00,A,3648.16565,N,12147.28176,W,0.136,352.46,291021,,,A*72
2021-10-29T20:34:22.485Z,1635539662.485 [NAL9602](INFO): GPS fix at 20211029T203421: (36.802761, -121.788029)
2021-10-29T20:34:22.496Z,1635539662.496 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T20:34:22.496Z,1635539662.496 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T20:34:29.718Z,1635539669.718 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211029T165424/Courier0112.lzma
2021-10-29T20:34:30.721Z,1635539670.721 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0112.lzma.bak
2021-10-29T20:34:30.721Z,1635539670.721 [DataOverHttps](INFO): SBD MOMSN=16170779
2021-10-29T20:34:47.569Z,1635539687.569 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20211029T165424/Express0113.lzma
2021-10-29T20:34:48.569Z,1635539688.569 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0113.lzma.bak
2021-10-29T20:34:48.569Z,1635539688.569 [DataOverHttps](INFO): SBD MOMSN=16170782
2021-10-29T20:34:51.193Z,1635539691.193 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T20:34:51.193Z,1635539691.193 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T20:34:51.193Z,1635539691.193 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T20:34:53.172Z,1635539693.172 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2021-10-29T20:34:53.251Z,1635539693.251 [NAL9602](ERROR): received: 
+CSQ:0

OK82, 2, 0, 0, 0

OK
2021-10-29T20:38:32.205Z,1635539912.205 [NAL9602](INFO): SBD MO Status=2, MOMSN=6482, MT Status=2, MTMSN=0
2021-10-29T20:38:32.206Z,1635539912.206 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-10-29T20:39:24.316Z,1635539964.316 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-10-29T20:39:51.810Z,1635539991.810 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T20:39:51.811Z,1635539991.811 [Default:CheckIn:C.Wait] Stopped
2021-10-29T20:39:51.811Z,1635539991.811 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T20:39:51.811Z,1635539991.811 [Default:CheckIn:D] Running Loop=1
2021-10-29T20:39:52.202Z,1635539992.202 [Default:CheckIn:D] Stopped
2021-10-29T20:39:52.203Z,1635539992.203 [Default:CheckIn:E] Running Loop=1
2021-10-29T20:39:52.613Z,1635539992.613 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 221.433073 min 
2021-10-29T20:39:52.613Z,1635539992.613 [Default:CheckIn:E] Stopped
2021-10-29T20:39:52.613Z,1635539992.613 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T20:39:52.613Z,1635539992.613 [Default:CheckIn] Stopped
2021-10-29T20:39:52.613Z,1635539992.613 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T20:39:52.614Z,1635539992.614 [Default:CheckIn](INFO): Running loop #38
2021-10-29T20:39:52.614Z,1635539992.614 [Default:CheckIn] Running Loop=38
2021-10-29T20:39:52.614Z,1635539992.614 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T20:39:52.614Z,1635539992.614 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T20:39:54.618Z,1635539994.618 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203953.00,A,3648.16492,N,12147.28100,W,0.486,352.46,291021,,,A*7C
2021-10-29T20:39:54.620Z,1635539994.620 [NAL9602](INFO): GPS fix at 20211029T203953: (36.802749, -121.788017)
2021-10-29T20:39:54.648Z,1635539994.648 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T20:39:54.648Z,1635539994.648 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T20:40:02.418Z,1635540002.418 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20211029T165424/Courier0115.lzma
2021-10-29T20:40:03.421Z,1635540003.421 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0115.lzma.bak
2021-10-29T20:40:03.421Z,1635540003.421 [DataOverHttps](INFO): SBD MOMSN=16170788
2021-10-29T20:40:20.115Z,1635540020.115 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20211029T165424/Express0116.lzma
2021-10-29T20:40:21.117Z,1635540021.117 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0116.lzma.bak
2021-10-29T20:40:21.117Z,1635540021.117 [DataOverHttps](INFO): SBD MOMSN=16170791
2021-10-29T20:40:23.324Z,1635540023.324 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T20:40:23.324Z,1635540023.324 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T20:40:23.324Z,1635540023.324 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T20:40:27.340Z,1635540027.340 [NAL9602](INFO): Not Powering down - fast GPS
2021-10-29T20:45:23.946Z,1635540323.946 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-10-29T20:45:23.946Z,1635540323.946 [Default:CheckIn:C.Wait] Stopped
2021-10-29T20:45:23.946Z,1635540323.946 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T20:45:23.946Z,1635540323.946 [Default:CheckIn:D] Running Loop=1
2021-10-29T20:45:24.352Z,1635540324.352 [Default:CheckIn:D] Stopped
2021-10-29T20:45:24.352Z,1635540324.352 [Default:CheckIn:E] Running Loop=1
2021-10-29T20:45:24.756Z,1635540324.756 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 226.968896 min 
2021-10-29T20:45:24.756Z,1635540324.756 [Default:CheckIn:E] Stopped
2021-10-29T20:45:24.756Z,1635540324.756 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-10-29T20:45:24.756Z,1635540324.756 [Default:CheckIn] Stopped
2021-10-29T20:45:24.757Z,1635540324.757 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T20:45:24.757Z,1635540324.757 [Default:CheckIn](INFO): Running loop #39
2021-10-29T20:45:24.757Z,1635540324.757 [Default:CheckIn] Running Loop=39
2021-10-29T20:45:24.757Z,1635540324.757 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-10-29T20:45:24.757Z,1635540324.757 [Default:CheckIn:Read_GPS] Running Loop=1
2021-10-29T20:45:26.766Z,1635540326.766 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204526.00,A,3648.16256,N,12147.28052,W,0.058,0.00,291021,,,A*7C
2021-10-29T20:45:26.768Z,1635540326.768 [NAL9602](INFO): GPS fix at 20211029T204526: (36.802709, -121.788009)
2021-10-29T20:45:26.780Z,1635540326.780 [Default:CheckIn:Read_GPS] Stopped
2021-10-29T20:45:26.780Z,1635540326.780 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-10-29T20:45:34.430Z,1635540334.430 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211029T165424/Courier0118.lzma
2021-10-29T20:45:35.433Z,1635540335.433 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Courier0118.lzma.bak
2021-10-29T20:45:35.433Z,1635540335.433 [DataOverHttps](INFO): SBD MOMSN=16170807
2021-10-29T20:45:52.518Z,1635540352.518 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20211029T165424/Express0119.lzma
2021-10-29T20:45:53.521Z,1635540353.521 [DataOverHttps](INFO): Moved sent file to Logs/20211029T165424/Express0119.lzma.bak
2021-10-29T20:45:53.521Z,1635540353.521 [DataOverHttps](INFO): SBD MOMSN=16170810
2021-10-29T20:45:55.894Z,1635540355.894 [Default:CheckIn:Read_Iridium] Stopped
2021-10-29T20:45:55.894Z,1635540355.894 [Default:CheckIn:C.Wait] Running Loop=1
2021-10-29T20:45:55.899Z,1635540355.899 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-10-29T20:45:57.472Z,1635540357.472 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2021-10-29T20:45:57.555Z,1635540357.555 [NAL9602](ERROR): received: 
+CSQ:0

OK82, 2, 0, 0, 0

OK
2021-10-29T20:47:57.862Z,1635540477.862 [NAL9602](INFO): SBD MO Status=2, MOMSN=6482, MT Status=2, MTMSN=0
2021-10-29T20:47:57.862Z,1635540477.862 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-10-29T20:48:56.850Z,1635540536.850 [NAL9602](INFO): SBD MO Status=2, MOMSN=6482, MT Status=2, MTMSN=0
2021-10-29T20:48:56.850Z,1635540536.850 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-10-29T20:49:11.816Z,1635540551.816 [DataOverHttps](IMPORTANT): SBD MTMSN=20211029T204910
2021-10-29T20:49:19.355Z,1635540559.355 [DataOverHttps](INFO): Received command: restart app
2021-10-29T20:49:19.376Z,1635540559.376 [CommandExec](IMPORTANT): got command restart application
2021-10-29T20:49:20.379Z,1635540560.379 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2021-10-29T20:49:20.379Z,1635540560.379 [CommandExec](INFO): Uninitializing the command executive.
2021-10-29T20:49:20.379Z,1635540560.379 [CommandExec](INFO): Uninitializing the command scheduler.
2021-10-29T20:49:20.380Z,1635540560.380 [CommandExec ThreadHandler](INFO): Thread cancelled.
2021-10-29T20:49:20.563Z,1635540560.563 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2021-10-29T20:49:20.563Z,1635540560.563 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2021-10-29T20:49:20.563Z,1635540560.563 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-10-29T20:49:20.564Z,1635540560.564 [NavChartDb](INFO): Join timeout helper Thread ID is 506
2021-10-29T20:49:20.919Z,1635540560.919 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2021-10-29T20:49:20.919Z,1635540560.919 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-10-29T20:49:20.935Z,1635540560.935 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2021-10-29T20:49:20.935Z,1635540560.935 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2021-10-29T20:49:20.935Z,1635540560.935 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 507
2021-10-29T20:49:21.247Z,1635540561.247 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2021-10-29T20:49:21.247Z,1635540561.247 [WetLabsBB2FL](INFO): Powering down
2021-10-29T20:49:21.248Z,1635540561.248 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2021-10-29T20:49:21.251Z,1635540561.251 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2021-10-29T20:49:21.251Z,1635540561.251 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-10-29T20:49:21.251Z,1635540561.251 [CTD_Seabird](INFO): Join timeout helper Thread ID is 508
2021-10-29T20:49:21.307Z,1635540561.307 [CTD_Seabird](INFO): Powering down
2021-10-29T20:49:21.319Z,1635540561.319 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2021-10-29T20:49:21.319Z,1635540561.319 [CTD_Seabird](INFO): Powering down
2021-10-29T20:49:21.331Z,1635540561.331 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-10-29T20:49:21.339Z,1635540561.339 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2021-10-29T20:49:21.339Z,1635540561.339 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-10-29T20:49:21.339Z,1635540561.339 [Radio_Surface](INFO): Join timeout helper Thread ID is 509
2021-10-29T20:49:21.675Z,1635540561.675 [Radio_Surface](INFO): Powering down
2021-10-29T20:49:21.676Z,1635540561.676 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2021-10-29T20:49:21.676Z,1635540561.676 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-10-29T20:49:21.679Z,1635540561.679 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2021-10-29T20:49:21.679Z,1635540561.679 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-10-29T20:49:21.679Z,1635540561.679 [Onboard](INFO): Join timeout helper Thread ID is 510
2021-10-29T20:49:22.363Z,1635540562.363 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2021-10-29T20:49:25.595Z,1635540565.595 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2021-10-29T20:49:25.595Z,1635540565.595 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-10-29T20:49:25.608Z,1635540565.608 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2021-10-29T20:49:25.608Z,1635540565.608 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-10-29T20:49:25.608Z,1635540565.608 [DataOverHttps](INFO): Join timeout helper Thread ID is 511
2021-10-29T20:49:26.379Z,1635540566.379 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2021-10-29T20:49:26.379Z,1635540566.379 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-10-29T20:49:26.388Z,1635540566.388 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2021-10-29T20:49:26.388Z,1635540566.388 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2021-10-29T20:49:26.388Z,1635540566.388 [BackseatComponent](INFO): Join timeout helper Thread ID is 512
2021-10-29T20:49:26.423Z,1635540566.423 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2021-10-29T20:49:26.423Z,1635540566.423 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2021-10-29T20:49:26.436Z,1635540566.436 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2021-10-29T20:49:26.436Z,1635540566.436 [logger ThreadHandler](INFO): Thread cancelled.
2021-10-29T20:49:26.436Z,1635540566.436 [logger](INFO): Join timeout helper Thread ID is 513
2021-10-29T20:49:26.468Z,1635540566.468 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2021-10-29T20:49:26.468Z,1635540566.468 [logger ThreadHandler](INFO): Thread cancelled.
2021-10-29T20:49:26.475Z,1635540566.475 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2021-10-29T20:49:26.476Z,1635540566.476 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-10-29T20:49:26.476Z,1635540566.476 [CommandLine](INFO): Join timeout helper Thread ID is 514
2021-10-29T20:49:26.495Z,1635540566.495 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2021-10-29T20:49:26.495Z,1635540566.495 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-10-29T20:49:26.515Z,1635540566.515 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2021-10-29T20:49:26.516Z,1635540566.516 [CommandExec ThreadHandler](INFO): Thread cancelled.
2021-10-29T20:49:26.516Z,1635540566.516 [CommandExec](INFO): Join timeout helper Thread ID is 515
2021-10-29T20:49:26.517Z,1635540566.517 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2021-10-29T20:49:26.517Z,1635540566.517 [controlThread ThreadHandler](INFO): Thread cancelled.
2021-10-29T20:49:26.518Z,1635540566.518 [controlThread](INFO): Join timeout helper Thread ID is 516
2021-10-29T20:49:26.787Z,1635540566.787 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2021-10-29T20:49:26.787Z,1635540566.787 [controlThread](DEBUG): Uninitializing ControlThread
2021-10-29T20:49:26.788Z,1635540566.788 [AHRS_M2](INFO): Powering down
2021-10-29T20:49:26.860Z,1635540566.860 [NAL9602](INFO): Powering down
2021-10-29T20:49:26.862Z,1635540566.862 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2021-10-29T20:49:26.863Z,1635540566.863 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2021-10-29T20:49:26.863Z,1635540566.863 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2021-10-29T20:49:26.864Z,1635540566.864 [MissionManager](INFO): Uninitializing Mission Default
2021-10-29T20:49:26.864Z,1635540566.864 [Default] Stopped
2021-10-29T20:49:26.864Z,1635540566.864 [Default](DEBUG): Aggregate::uninitialize Default
2021-10-29T20:49:26.864Z,1635540566.864 [Default:B.GoToSurface] Stopped
2021-10-29T20:49:26.864Z,1635540566.864 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-10-29T20:49:26.864Z,1635540566.864 [Default:CheckIn] Stopped
2021-10-29T20:49:26.864Z,1635540566.864 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-10-29T20:49:26.865Z,1635540566.865 [Default:CheckIn:C.Wait] Stopped
2021-10-29T20:49:26.865Z,1635540566.865 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-10-29T20:49:26.868Z,1635540566.868 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2021-10-29T20:49:26.868Z,1635540566.868 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2021-10-29T20:49:26.868Z,1635540566.868 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2021-10-29T20:49:26.869Z,1635540566.869 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2021-10-29T20:49:26.869Z,1635540566.869 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2021-10-29T20:49:26.869Z,1635540566.869 [BuoyancyServo](INFO): Powering down
2021-10-29T20:49:26.883Z,1635540566.883 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2021-10-29T20:49:26.883Z,1635540566.883 [ElevatorServo](INFO): Powering down
2021-10-29T20:49:26.884Z,1635540566.884 [MassServo](DEBUG): Uninitialize Mass Servo.
2021-10-29T20:49:26.884Z,1635540566.884 [MassServo](INFO): Powering down
2021-10-29T20:49:26.885Z,1635540566.885 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2021-10-29T20:49:26.885Z,1635540566.885 [RudderServo](INFO): Powering down
2021-10-29T20:49:26.886Z,1635540566.886 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2021-10-29T20:49:26.886Z,1635540566.886 [ThrusterHE](INFO): Powering down
2021-10-29T20:49:26.887Z,1635540566.887 [SBIT](DEBUG): Uninitialize SBIT Component.
2021-10-29T20:49:26.887Z,1635540566.887 [IBIT](DEBUG): Uninitialize IBIT Component.
2021-10-29T20:49:26.888Z,1635540566.888 [CBIT](DEBUG): Uninitialize CBIT Component.
2021-10-29T20:49:26.888Z,1635540566.888 [CBIT](DEBUG): Powering off loads.
2021-10-29T20:49:26.899Z,1635540566.899 [CBIT](DEBUG): Disabling WDT.
2021-10-29T20:49:26.911Z,1635540566.911 [CBIT](DEBUG): Opening all GF detection circuits.
2021-10-29T20:49:26.912Z,1635540566.912 [controlThread ThreadHandler](INFO): Thread cancelled.
2021-10-29T20:49:26.955Z,1635540566.955 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-10-29T20:49:26.958Z,1635540566.958 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-10-29T20:49:26.965Z,1635540566.965 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-10-29T20:49:27.008Z,1635540567.008 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2021-10-29T20:49:27.045Z,1635540567.045 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2021-10-29T20:49:27.050Z,1635540567.050 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-10-29T20:49:27.082Z,1635540567.082 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-10-29T20:49:27.155Z,1635540567.155 [logger ThreadHandler](INFO): Thread cancelled.