2021-07-23T19:22:25.465Z,1627068145.465 [Supervisor](DEBUG): Initializing supervisor.
2021-07-23T19:22:25.470Z,1627068145.470 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2021-07-23T19:22:25.470Z,1627068145.470 [SyncHandler](INFO): Protected caller Thread ID is 818
2021-07-23T19:22:25.471Z,1627068145.471 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2021-07-23T19:22:25.471Z,1627068145.471 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2021-07-23T19:22:25.472Z,1627068145.472 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 819
2021-07-23T19:22:25.476Z,1627068145.476 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2021-07-23T19:22:25.497Z,1627068145.497 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2021-07-23T19:22:25.498Z,1627068145.498 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2021-07-23T19:22:25.498Z,1627068145.498 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 820
2021-07-23T19:22:25.500Z,1627068145.500 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2021-07-23T19:22:25.501Z,1627068145.501 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2021-07-23T19:22:25.502Z,1627068145.502 [logger ThreadHandler](INFO): Protected caller Thread ID is 821
2021-07-23T19:22:25.506Z,1627068145.506 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2021-07-23T19:22:25.506Z,1627068145.506 [Supervisor](INFO): Looking for Config files in directory: Config/
2021-07-23T19:22:25.510Z,1627068145.510 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2021-07-23T19:22:26.036Z,1627068146.036 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2021-07-23T19:22:26.038Z,1627068146.038 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2021-07-23T19:22:26.278Z,1627068146.278 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2021-07-23T19:22:26.280Z,1627068146.280 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2021-07-23T19:22:26.498Z,1627068146.498 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2021-07-23T19:22:26.498Z,1627068146.498 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2021-07-23T19:22:26.613Z,1627068146.613 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2021-07-23T19:22:26.614Z,1627068146.614 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2021-07-23T19:22:27.034Z,1627068147.034 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2021-07-23T19:22:27.034Z,1627068147.034 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2021-07-23T19:22:27.416Z,1627068147.416 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2021-07-23T19:22:27.417Z,1627068147.417 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2021-07-23T19:22:27.518Z,1627068147.518 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2021-07-23T19:22:27.519Z,1627068147.519 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2021-07-23T19:22:27.682Z,1627068147.682 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2021-07-23T19:22:27.682Z,1627068147.682 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2021-07-23T19:22:28.282Z,1627068148.282 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2021-07-23T19:22:28.282Z,1627068148.282 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2021-07-23T19:22:28.688Z,1627068148.688 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2021-07-23T19:22:29.126Z,1627068149.126 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2021-07-23T19:22:29.661Z,1627068149.661 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2021-07-23T19:22:29.890Z,1627068149.890 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2021-07-23T19:22:29.890Z,1627068149.890 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2021-07-23T19:22:30.026Z,1627068150.026 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2021-07-23T19:22:30.027Z,1627068150.027 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2021-07-23T19:22:30.785Z,1627068150.785 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2021-07-23T19:22:30.786Z,1627068150.786 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2021-07-23T19:22:30.867Z,1627068150.867 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2021-07-23T19:22:31.145Z,1627068151.145 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2021-07-23T19:22:31.147Z,1627068151.147 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-galene/
2021-07-23T19:22:31.149Z,1627068151.149 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/vehicle.cfg
2021-07-23T19:22:31.341Z,1627068151.341 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/logger.cfg
2021-07-23T19:22:31.440Z,1627068151.440 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Servo.cfg
2021-07-23T19:22:31.559Z,1627068151.559 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Control.cfg
2021-07-23T19:22:31.666Z,1627068151.666 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/secure.cfg
2021-07-23T19:22:31.754Z,1627068151.754 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Simulator.cfg
2021-07-23T19:22:31.843Z,1627068151.843 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Science.cfg
2021-07-23T19:22:31.965Z,1627068151.965 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/BIT.cfg
2021-07-23T19:22:32.070Z,1627068152.070 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Sensor.cfg
2021-07-23T19:22:32.228Z,1627068152.228 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Battery.cfg
2021-07-23T19:22:32.508Z,1627068152.508 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2021-07-23T19:22:32.508Z,1627068152.508 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Navigation.cfg
2021-07-23T19:22:32.607Z,1627068152.607 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2021-07-23T19:22:32.625Z,1627068152.625 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2021-07-23T19:22:33.036Z,1627068153.036 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2021-07-23T19:22:33.036Z,1627068153.036 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2021-07-23T19:22:33.143Z,1627068153.143 [DeadReckonUsingMultipleVelocitySources] Loaded
2021-07-23T19:22:33.143Z,1627068153.143 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2021-07-23T19:22:33.180Z,1627068153.180 [DeadReckonUsingSpeedCalculator] Loaded
2021-07-23T19:22:33.181Z,1627068153.181 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2021-07-23T19:22:33.195Z,1627068153.195 [NavChart] Loaded
2021-07-23T19:22:33.195Z,1627068153.195 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2021-07-23T19:22:33.201Z,1627068153.201 [UniversalFixResidualReporter] Loaded
2021-07-23T19:22:33.202Z,1627068153.202 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2021-07-23T19:22:33.202Z,1627068153.202 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2021-07-23T19:22:33.203Z,1627068153.203 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2021-07-23T19:22:33.220Z,1627068153.220 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2021-07-23T19:22:33.220Z,1627068153.220 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2021-07-23T19:22:33.453Z,1627068153.453 [ESPComponent] Loaded
2021-07-23T19:22:33.453Z,1627068153.453 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2021-07-23T19:22:33.454Z,1627068153.454 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2021-07-23T19:22:33.455Z,1627068153.455 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2021-07-23T19:22:33.530Z,1627068153.530 [VerticalControl](DEBUG): Construct VerticalControl.
2021-07-23T19:22:33.596Z,1627068153.596 [VerticalControl] Loaded
2021-07-23T19:22:33.596Z,1627068153.596 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2021-07-23T19:22:33.599Z,1627068153.599 [HorizontalControl](DEBUG): Construct HorizontalControl.
2021-07-23T19:22:33.640Z,1627068153.640 [HorizontalControl] Loaded
2021-07-23T19:22:33.641Z,1627068153.641 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2021-07-23T19:22:33.643Z,1627068153.643 [SpeedControl](DEBUG): Construct SpeedControl.
2021-07-23T19:22:33.647Z,1627068153.647 [SpeedControl] Loaded
2021-07-23T19:22:33.647Z,1627068153.647 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2021-07-23T19:22:33.650Z,1627068153.650 [LoopControl](DEBUG): Construct LoopControl.
2021-07-23T19:22:33.651Z,1627068153.651 [LoopControl] Loaded
2021-07-23T19:22:33.651Z,1627068153.651 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2021-07-23T19:22:33.651Z,1627068153.651 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2021-07-23T19:22:33.652Z,1627068153.652 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2021-07-23T19:22:33.715Z,1627068153.715 [DepthRateCalculator] Loaded
2021-07-23T19:22:33.715Z,1627068153.715 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2021-07-23T19:22:33.720Z,1627068153.720 [PitchRateCalculator] Loaded
2021-07-23T19:22:33.720Z,1627068153.720 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2021-07-23T19:22:33.731Z,1627068153.731 [SpeedCalculator] Loaded
2021-07-23T19:22:33.731Z,1627068153.731 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2021-07-23T19:22:33.775Z,1627068153.775 [TempGradientCalculator] Loaded
2021-07-23T19:22:33.775Z,1627068153.775 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2021-07-23T19:22:33.780Z,1627068153.780 [YawRateCalculator] Loaded
2021-07-23T19:22:33.780Z,1627068153.780 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2021-07-23T19:22:33.966Z,1627068153.966 [ElevatorOffsetCalculator] Loaded
2021-07-23T19:22:33.967Z,1627068153.967 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2021-07-23T19:22:33.967Z,1627068153.967 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2021-07-23T19:22:33.968Z,1627068153.968 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2021-07-23T19:22:34.744Z,1627068154.744 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2021-07-23T19:22:34.745Z,1627068154.745 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2021-07-23T19:22:34.836Z,1627068154.836 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2021-07-23T19:22:34.837Z,1627068154.837 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2021-07-23T19:22:35.027Z,1627068155.027 [BuoyancyServo] Loaded
2021-07-23T19:22:35.027Z,1627068155.027 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2021-07-23T19:22:35.048Z,1627068155.048 [ElevatorServo] Loaded
2021-07-23T19:22:35.048Z,1627068155.048 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2021-07-23T19:22:35.068Z,1627068155.068 [RudderServo] Loaded
2021-07-23T19:22:35.068Z,1627068155.068 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2021-07-23T19:22:35.087Z,1627068155.087 [ThrusterServo] Loaded
2021-07-23T19:22:35.088Z,1627068155.088 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2021-07-23T19:22:35.088Z,1627068155.088 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2021-07-23T19:22:35.090Z,1627068155.090 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2021-07-23T19:22:35.234Z,1627068155.234 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2021-07-23T19:22:35.235Z,1627068155.235 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2021-07-23T19:22:36.829Z,1627068156.829 [BPC1] Loaded
2021-07-23T19:22:36.829Z,1627068156.829 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2021-07-23T19:22:37.157Z,1627068157.157 [DataOverHttps] Loaded
2021-07-23T19:22:37.158Z,1627068157.158 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2021-07-23T19:22:37.159Z,1627068157.159 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409B34E0
2021-07-23T19:22:37.159Z,1627068157.159 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 903
2021-07-23T19:22:37.181Z,1627068157.181 [Depth_Keller] Loaded
2021-07-23T19:22:37.182Z,1627068157.182 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2021-07-23T19:22:37.246Z,1627068157.246 [NAL9602] Loaded
2021-07-23T19:22:37.246Z,1627068157.246 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2021-07-23T19:22:37.275Z,1627068157.275 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/voltage_now
2021-07-23T19:22:37.276Z,1627068157.276 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/current_now
2021-07-23T19:22:37.276Z,1627068157.276 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/charge_now
2021-07-23T19:22:37.277Z,1627068157.277 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/charge_full
2021-07-23T19:22:37.278Z,1627068157.278 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/voltage_now
2021-07-23T19:22:37.278Z,1627068157.278 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/current_now
2021-07-23T19:22:37.279Z,1627068157.279 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/charge_now
2021-07-23T19:22:37.279Z,1627068157.279 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/charge_full
2021-07-23T19:22:37.279Z,1627068157.279 [Onboard] Loaded
2021-07-23T19:22:37.280Z,1627068157.280 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2021-07-23T19:22:37.281Z,1627068157.281 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409E34E0
2021-07-23T19:22:37.281Z,1627068157.281 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 904
2021-07-23T19:22:37.296Z,1627068157.296 [Power24vConverter] Loaded
2021-07-23T19:22:37.296Z,1627068157.296 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2021-07-23T19:22:37.310Z,1627068157.310 [Radio_Surface] Loaded
2021-07-23T19:22:37.311Z,1627068157.311 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2021-07-23T19:22:37.312Z,1627068157.312 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40A134E0
2021-07-23T19:22:37.312Z,1627068157.312 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 905
2021-07-23T19:22:37.402Z,1627068157.402 [DAT] Loaded
2021-07-23T19:22:37.402Z,1627068157.402 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2021-07-23T19:22:37.403Z,1627068157.403 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2021-07-23T19:22:37.403Z,1627068157.403 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2021-07-23T19:22:37.594Z,1627068157.594 [SBIT](DEBUG): Construct Startup Built In Test.
2021-07-23T19:22:37.604Z,1627068157.604 [SBIT] Loaded
2021-07-23T19:22:37.604Z,1627068157.604 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2021-07-23T19:22:37.607Z,1627068157.607 [IBIT](DEBUG): Construct Initiated Built In Test.
2021-07-23T19:22:37.622Z,1627068157.622 [IBIT] Loaded
2021-07-23T19:22:37.623Z,1627068157.623 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2021-07-23T19:22:37.629Z,1627068157.629 [CBIT](DEBUG): Construct Continuous Built In Test.
2021-07-23T19:22:37.740Z,1627068157.740 [CBIT] Loaded
2021-07-23T19:22:37.740Z,1627068157.740 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2021-07-23T19:22:37.741Z,1627068157.741 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2021-07-23T19:22:37.741Z,1627068157.741 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2021-07-23T19:22:37.786Z,1627068157.786 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2021-07-23T19:22:37.792Z,1627068157.792 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2021-07-23T19:22:37.795Z,1627068157.795 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2021-07-23T19:22:37.805Z,1627068157.805 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2021-07-23T19:22:37.806Z,1627068157.806 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A9E4E0
2021-07-23T19:22:37.807Z,1627068157.807 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 906
2021-07-23T19:22:37.812Z,1627068157.812 [Supervisor](INFO): Main Thread ID is 813
2021-07-23T19:22:37.812Z,1627068157.812 [Supervisor](DEBUG): Running supervisor.
2021-07-23T19:22:37.812Z,1627068157.812 [CommandLine ThreadHandler](INFO): Handler Thread ID is 907
2021-07-23T19:22:37.815Z,1627068157.815 [controlThread ThreadHandler](INFO): Handler Thread ID is 908
2021-07-23T19:22:37.815Z,1627068157.815 [controlThread](DEBUG): Initializing ControlThread
2021-07-23T19:22:37.817Z,1627068157.817 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2021-07-23T19:22:37.817Z,1627068157.817 [NavChart](DEBUG): Initialize NavChart Navigation.
2021-07-23T19:22:37.818Z,1627068157.818 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2021-07-23T19:22:37.818Z,1627068157.818 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2021-07-23T19:22:37.820Z,1627068157.820 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2021-07-23T19:22:37.821Z,1627068157.821 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2021-07-23T19:22:37.821Z,1627068157.821 [LoopControl](DEBUG): Initialize LoopControlComponent.
2021-07-23T19:22:37.822Z,1627068157.822 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2021-07-23T19:22:37.822Z,1627068157.822 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2021-07-23T19:22:37.822Z,1627068157.822 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2021-07-23T19:22:37.822Z,1627068157.822 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2021-07-23T19:22:37.823Z,1627068157.823 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2021-07-23T19:22:37.823Z,1627068157.823 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2021-07-23T19:22:37.830Z,1627068157.830 [SBIT](INFO): Initialize SBIT Component.
2021-07-23T19:22:37.830Z,1627068157.830 [SBIT](IMPORTANT): git: 2021-06-24-10-g1c68dac98
2021-07-23T19:22:37.831Z,1627068157.831 [SBIT](INFO): git hash: 1c68dac98e3954a039edc16fe17de653428a8fd0
2021-07-23T19:22:37.831Z,1627068157.831 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2021-07-23T19:22:37.832Z,1627068157.832 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
2021-07-23T19:22:37.834Z,1627068157.834 [SBIT](INFO): Beginning SBIT in 20.000000 seconds.
2021-07-23T19:22:37.834Z,1627068157.834 [IBIT](INFO): Initialize IBIT Component.
2021-07-23T19:22:37.835Z,1627068157.835 [CBIT](DEBUG): Initialize CBIT Component.
2021-07-23T19:22:37.836Z,1627068157.836 [logger ThreadHandler](INFO): Handler Thread ID is 909
2021-07-23T19:22:37.849Z,1627068157.849 [CBIT](DEBUG): Initialized mux pins.
2021-07-23T19:22:37.849Z,1627068157.849 [CBIT](DEBUG): Initializing the watchdog timer.
2021-07-23T19:22:37.853Z,1627068157.853 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 910
2021-07-23T19:22:37.854Z,1627068157.854 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2021-07-23T19:22:37.861Z,1627068157.861 [Onboard ThreadHandler](INFO): Handler Thread ID is 911
2021-07-23T19:22:37.874Z,1627068157.874 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2021-07-23T19:22:37.879Z,1627068157.879 [CBIT](FAULT): Found backtrace file:
1627067694.148947 [CBIT]: Backtrace:
./bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x1a1308]
./bin/LRAUV(_ZN7PCaller10PThreadRunEPv+0xc8) [0x1a0d54]
2021-07-23T19:22:37.880Z,1627068157.880 [CBIT](FAULT): Renaming backtrace file to Data/backtrace1
2021-07-23T19:22:37.881Z,1627068157.881 [CBIT](DEBUG): Initializing heartbeat.
2021-07-23T19:22:37.882Z,1627068157.882 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 912
2021-07-23T19:22:37.897Z,1627068157.897 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 913
2021-07-23T19:22:37.906Z,1627068157.906 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2021-07-23T19:22:37.906Z,1627068157.906 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2021-07-23T19:22:37.907Z,1627068157.907 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2021-07-23T19:22:37.907Z,1627068157.907 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2021-07-23T19:22:37.907Z,1627068157.907 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2021-07-23T19:22:37.907Z,1627068157.907 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2021-07-23T19:22:37.907Z,1627068157.907 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2021-07-23T19:22:37.907Z,1627068157.907 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2021-07-23T19:22:37.908Z,1627068157.908 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2021-07-23T19:22:37.908Z,1627068157.908 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2021-07-23T19:22:37.908Z,1627068157.908 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2021-07-23T19:22:37.908Z,1627068157.908 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2021-07-23T19:22:37.908Z,1627068157.908 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2021-07-23T19:22:37.908Z,1627068157.908 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2021-07-23T19:22:37.909Z,1627068157.909 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2021-07-23T19:22:37.909Z,1627068157.909 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2021-07-23T19:22:37.953Z,1627068157.953 [CBIT](DEBUG): Deactivating GF circuits.
2021-07-23T19:22:37.953Z,1627068157.953 [CBIT](DEBUG): Deactivating emergency mode.
2021-07-23T19:22:37.989Z,1627068157.989 [CBIT](DEBUG): Backplane powered.
2021-07-23T19:22:37.990Z,1627068157.990 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2021-07-23T19:22:38.017Z,1627068158.017 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2021-07-23T19:22:38.065Z,1627068158.065 [MissionManager](DEBUG):
2021-07-23T19:22:38.066Z,1627068158.066 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2021-07-23T19:22:38.154Z,1627068158.154 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2021-07-23T19:22:38.155Z,1627068158.155 [Default:A.Wait](DEBUG): Construct Wait.
2021-07-23T19:22:38.169Z,1627068158.169 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2021-07-23T19:22:38.210Z,1627068158.210 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2021-07-23T19:22:38.229Z,1627068158.229 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2021-07-23T19:22:38.235Z,1627068158.235 [Default:E.Execute](DEBUG): Construct Execute.
2021-07-23T19:22:38.259Z,1627068158.259 [MissionManager](DEBUG):
0
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
13
Burn on
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2021-07-23T19:22:38.263Z,1627068158.263 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,BPC1,Depth_Keller,NAL9602,Power24vConverter,DAT,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2021-07-23T19:22:38.285Z,1627068158.285 [Radio_Surface](INFO): Powering up
2021-07-23T19:22:38.326Z,1627068158.326 [Depth_Keller](ERROR): Pressure reading out of range: 1628.471313 decibar
2021-07-23T19:22:38.326Z,1627068158.326 [Power24vConverter](INFO): Powering up.
2021-07-23T19:22:38.327Z,1627068158.327 [DAT](INFO): Powering up
2021-07-23T19:22:38.327Z,1627068158.327 [DAT](DEBUG): Initializing DAT.
2021-07-23T19:22:38.349Z,1627068158.349 [DepthRateCalculator](ERROR): Depth measurement is not active
2021-07-23T19:22:38.591Z,1627068158.591 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2021-07-23T19:22:38.597Z,1627068158.597 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2021-07-23T19:22:38.598Z,1627068158.598 [ElevatorServo](DEBUG): Initializing EZServoServo.
2021-07-23T19:22:38.605Z,1627068158.605 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2021-07-23T19:22:38.606Z,1627068158.606 [RudderServo](DEBUG): Initializing EZServoServo.
2021-07-23T19:22:38.613Z,1627068158.613 [RudderServo](DEBUG): Initializing RudderServo.
2021-07-23T19:22:38.614Z,1627068158.614 [ThrusterServo](DEBUG): Initializing EZServoServo.
2021-07-23T19:22:38.625Z,1627068158.625 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2021-07-23T19:22:58.483Z,1627068178.483 [SBIT](IMPORTANT): Beginning Startup BIT
2021-07-23T19:22:58.488Z,1627068178.488 [CBIT](IMPORTANT): Beginning ground fault scan
2021-07-23T19:23:07.358Z,1627068187.358 [NAL9602](INFO): Powering up NAL9602
2021-07-23T19:23:09.399Z,1627068189.399 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.009180
CHAN A1 (24V): 0.001782
CHAN A2 (12V): -0.005872
CHAN A3 (5V): -0.003119
CHAN B0 (3.3V): -0.001288
CHAN B1 (3.15aV): -0.001252
CHAN B2 (3.15bV): -0.001267
CHAN B3 (GND): -0.000530
OPEN: -0.001225
Full Scale Calc: 4.765 mA, -1.589 mA
2021-07-23T19:23:11.828Z,1627068191.828 [SBIT](ERROR): Could not read massPosReader_.
2021-07-23T19:23:18.266Z,1627068198.266 [NAL9602](INFO): NAL9602 initialized
2021-07-23T19:23:38.469Z,1627068218.469 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2021-07-23T19:23:38.469Z,1627068218.469 [DAT] Communications Fault, FailCount= 1
2021-07-23T19:23:38.469Z,1627068218.469 [DAT](ERROR): Communications Fault
2021-07-23T19:23:38.481Z,1627068218.481 [SBIT](ERROR): Could not read massPosReader_.
2021-07-23T19:23:38.481Z,1627068218.481 [SBIT](FAULT): Control surface position failure.
2021-07-23T19:23:38.484Z,1627068218.484 [CBIT](ERROR): Communications Fault in component: DAT
2021-07-23T19:23:38.899Z,1627068218.899 [DAT](INFO): Powering down
2021-07-23T19:23:39.699Z,1627068219.699 [CBIT](INFO): Clearing failed state for component DAT
2021-07-23T19:23:39.699Z,1627068219.699 [DAT] No Fault, FailCount= 1
2021-07-23T19:23:42.121Z,1627068222.121 [DAT](INFO): Powering up
2021-07-23T19:23:42.122Z,1627068222.122 [DAT](DEBUG): Initializing DAT.
2021-07-23T19:23:52.227Z,1627068232.227 [SBIT](ERROR): Could not read massPosReader_.
2021-07-23T19:23:52.227Z,1627068232.227 [SBIT](FAULT): Control surface position failure.
2021-07-23T19:23:52.648Z,1627068232.648 [SBIT](CRITICAL): SBIT FAILED
2021-07-23T19:23:52.648Z,1627068232.648 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2021-07-23T19:23:52.670Z,1627068232.670 [SBIT](IMPORTANT): AHRS_M2.loadAtStartup=0 bool;
2021-07-23T19:23:52.670Z,1627068232.670 [SBIT](IMPORTANT): CTD_NeilBrown.loadAtStartup=0 bool;
2021-07-23T19:23:52.670Z,1627068232.670 [SBIT](IMPORTANT): CTD_Seabird.loadAtStartup=0 bool;
2021-07-23T19:23:52.671Z,1627068232.671 [SBIT](IMPORTANT): DAT.loadAtStartup=1 bool;
2021-07-23T19:23:52.671Z,1627068232.671 [SBIT](IMPORTANT): DropWeight.loadAtStartup=0 bool;
2021-07-23T19:23:52.671Z,1627068232.671 [SBIT](IMPORTANT): ESPComponent.loadAtStartup=1 bool;
2021-07-23T19:23:52.671Z,1627068232.671 [SBIT](IMPORTANT): IBIT.batteryCapacityThreshold=5 ampere_hour;
2021-07-23T19:23:52.671Z,1627068232.671 [SBIT](IMPORTANT): IBIT.batteryVoltageThreshold=11 volt;
2021-07-23T19:23:52.671Z,1627068232.671 [SBIT](IMPORTANT): MassServo.loadAtStartup=0 bool;
2021-07-23T19:23:52.671Z,1627068232.671 [SBIT](IMPORTANT): MassServo.overloadTimeout=10 second;
2021-07-23T19:23:52.672Z,1627068232.672 [SBIT](IMPORTANT): NAL9602.fastGPSFix=1 bool;
2021-07-23T19:23:52.672Z,1627068232.672 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=235 cubic_centimeter;
2021-07-23T19:23:52.672Z,1627068232.672 [SBIT](IMPORTANT): VerticalControl.massDefault=0 centimeter;
2021-07-23T19:23:52.672Z,1627068232.672 [SBIT](IMPORTANT): WetLabsBB2FL.loadAtStartup=0 bool;
2021-07-23T19:23:52.674Z,1627068232.674 [CommandLine](FAULT): Scheduling is paused
2021-07-23T19:23:52.674Z,1627068232.674 [CBIT](INFO): Critical error at 20210723T192352
2021-07-23T19:23:52.674Z,1627068232.674 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2021-07-23T19:23:53.039Z,1627068233.039 [MissionManager](IMPORTANT): Started mission Startup
2021-07-23T19:23:53.039Z,1627068233.039 [Startup] Running Loop=1
2021-07-23T19:23:53.040Z,1627068233.040 [Startup](DEBUG): Aggregate::initialize Startup
2021-07-23T19:23:53.040Z,1627068233.040 [Startup:A.GoToSurface] Running Loop=1
2021-07-23T19:23:53.040Z,1627068233.040 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-07-23T19:23:53.040Z,1627068233.040 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-07-23T19:23:53.041Z,1627068233.041 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-07-23T19:23:53.041Z,1627068233.041 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-07-23T19:23:53.042Z,1627068233.042 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-07-23T19:23:53.042Z,1627068233.042 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-07-23T19:23:53.044Z,1627068233.044 [Startup:StartupSatComms] Running Loop=1
2021-07-23T19:23:53.044Z,1627068233.044 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2021-07-23T19:23:53.044Z,1627068233.044 [Startup:StartupSatComms:A] Running Loop=1
2021-07-23T19:23:53.446Z,1627068233.446 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2021-07-23T19:24:37.863Z,1627068277.863 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2021-07-23T19:24:37.863Z,1627068277.863 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2021-07-23T19:24:37.863Z,1627068277.863 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-07-23T19:24:37.883Z,1627068277.883 [DeadReckonUsingSpeedCalculator](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2021-07-23T19:24:37.883Z,1627068277.883 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2021-07-23T19:24:37.883Z,1627068277.883 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2021-07-23T19:24:37.894Z,1627068277.894 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-07-23T19:24:37.894Z,1627068277.894 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2021-07-23T19:24:38.277Z,1627068278.277 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-07-23T19:24:38.277Z,1627068278.277 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2021-07-23T19:24:38.277Z,1627068278.277 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2021-07-23T19:24:38.277Z,1627068278.277 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2021-07-23T19:24:38.671Z,1627068278.671 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2021-07-23T19:24:42.303Z,1627068282.303 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2021-07-23T19:24:42.303Z,1627068282.303 [DAT] Communications Fault, FailCount= 2
2021-07-23T19:24:42.303Z,1627068282.303 [DAT](ERROR): Communications Fault
2021-07-23T19:24:42.319Z,1627068282.319 [CBIT](ERROR): Communications Fault in component: DAT
2021-07-23T19:24:42.708Z,1627068282.708 [DAT](INFO): Powering down
2021-07-23T19:24:43.530Z,1627068283.530 [CBIT](INFO): Clearing failed state for component DAT
2021-07-23T19:24:43.530Z,1627068283.530 [DAT] No Fault, FailCount= 2
2021-07-23T19:24:45.953Z,1627068285.953 [DAT](INFO): Powering up
2021-07-23T19:24:45.953Z,1627068285.953 [DAT](DEBUG): Initializing DAT.
2021-07-23T19:24:53.212Z,1627068293.212 [Startup:StartupSatComms:A](INFO): Timed out from 2021-07-23T19:23:53.0Z
2021-07-23T19:24:53.212Z,1627068293.212 [Startup:StartupSatComms:A] Stopped
2021-07-23T19:24:53.212Z,1627068293.212 [Startup:StartupSatComms:B] Running Loop=1
2021-07-23T19:24:53.618Z,1627068293.618 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-07-23T19:25:17.767Z,1627068317.767 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004669
2021-07-23T19:25:24.730Z,1627068324.730 [DataOverHttps](INFO): Sending 70 bytes from file Logs/20210723T174905/Courier0031.lzma
2021-07-23T19:25:25.731Z,1627068325.731 [DataOverHttps](INFO): Moved sent file to Logs/20210723T174905/Courier0031.lzma.bak
2021-07-23T19:25:25.731Z,1627068325.731 [DataOverHttps](INFO): SBD MOMSN=15758567
2021-07-23T19:25:41.016Z,1627068341.016 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210723T192225/Courier0000.lzma
2021-07-23T19:25:42.018Z,1627068342.018 [DataOverHttps](INFO): Moved sent file to Logs/20210723T192225/Courier0000.lzma.bak
2021-07-23T19:25:42.019Z,1627068342.019 [DataOverHttps](INFO): SBD MOMSN=15758570
2021-07-23T19:25:46.135Z,1627068346.135 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2021-07-23T19:25:46.135Z,1627068346.135 [DAT] Communications Fault, FailCount= 3
2021-07-23T19:25:46.135Z,1627068346.135 [DAT](ERROR): Communications Fault
2021-07-23T19:25:46.151Z,1627068346.151 [CBIT](ERROR): Communications Fault in component: DAT
2021-07-23T19:25:46.535Z,1627068346.535 [DAT](INFO): Powering down
2021-07-23T19:25:47.359Z,1627068347.359 [CBIT](INFO): Clearing failed state for component DAT
2021-07-23T19:25:47.359Z,1627068347.359 [DAT] No Fault, FailCount= 3
2021-07-23T19:25:49.775Z,1627068349.775 [DAT](INFO): Powering up
2021-07-23T19:25:49.775Z,1627068349.775 [DAT](DEBUG): Initializing DAT.
2021-07-23T19:25:53.434Z,1627068353.434 [Startup:StartupSatComms:B](INFO): Timed out from 2021-07-23T19:24:53.2Z
2021-07-23T19:25:53.434Z,1627068353.434 [Startup:StartupSatComms:B] Stopped
2021-07-23T19:25:53.435Z,1627068353.435 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2021-07-23T19:25:53.435Z,1627068353.435 [Startup:StartupSatComms] Stopped
2021-07-23T19:25:53.435Z,1627068353.435 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2021-07-23T19:25:53.436Z,1627068353.436 [Startup](INFO): Completed Startup
2021-07-23T19:25:53.436Z,1627068353.436 [MissionManager](INFO): Startup is completed.
2021-07-23T19:25:53.436Z,1627068353.436 [MissionManager](INFO): Uninitializing Mission Startup
2021-07-23T19:25:53.436Z,1627068353.436 [Startup] Stopped
2021-07-23T19:25:53.436Z,1627068353.436 [Startup](DEBUG): Aggregate::uninitialize Startup
2021-07-23T19:25:53.436Z,1627068353.436 [Startup:A.GoToSurface] Stopped
2021-07-23T19:25:53.436Z,1627068353.436 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-07-23T19:25:53.832Z,1627068353.832 [MissionManager](IMPORTANT): Started mission Default
2021-07-23T19:25:53.832Z,1627068353.832 [Default] Running Loop=1
2021-07-23T19:25:53.833Z,1627068353.833 [Default](DEBUG): Aggregate::initialize Default
2021-07-23T19:25:53.833Z,1627068353.833 [Default:B.GoToSurface] Running Loop=1
2021-07-23T19:25:53.833Z,1627068353.833 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-07-23T19:25:53.833Z,1627068353.833 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-07-23T19:25:53.834Z,1627068353.834 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-07-23T19:25:53.834Z,1627068353.834 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-07-23T19:25:53.834Z,1627068353.834 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-07-23T19:25:53.835Z,1627068353.835 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-07-23T19:25:53.835Z,1627068353.835 [Default:A.Wait] Running Loop=1
2021-07-23T19:25:53.835Z,1627068353.835 [Default:A.Wait](DEBUG): Initialize Wait Component.
2021-07-23T19:25:58.230Z,1627068358.230 [DataOverHttps](INFO): Sending 286 bytes from file Logs/20210723T174905/Express0032.lzma
2021-07-23T19:25:59.231Z,1627068359.231 [DataOverHttps](INFO): Moved sent file to Logs/20210723T174905/Express0032.lzma.bak
2021-07-23T19:25:59.231Z,1627068359.231 [DataOverHttps](INFO): SBD MOMSN=15758574
2021-07-23T19:26:07.149Z,1627068367.149 [Default:A.Wait](INFO): Done Waiting.
2021-07-23T19:26:07.149Z,1627068367.149 [Default:A.Wait] Stopped
2021-07-23T19:26:07.149Z,1627068367.149 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2021-07-23T19:26:07.548Z,1627068367.548 [Default:CheckIn] Running Loop=1
2021-07-23T19:26:07.548Z,1627068367.548 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-23T19:26:07.549Z,1627068367.549 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-23T19:26:07.958Z,1627068367.958 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2021-07-23T19:26:39.060Z,1627068399.060 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2021-07-23T19:26:39.060Z,1627068399.060 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2021-07-23T19:26:39.060Z,1627068399.060 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-07-23T19:26:39.062Z,1627068399.062 [DeadReckonUsingSpeedCalculator](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2021-07-23T19:26:39.062Z,1627068399.062 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2
2021-07-23T19:26:39.062Z,1627068399.062 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2021-07-23T19:26:39.115Z,1627068399.115 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-07-23T19:26:39.115Z,1627068399.115 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2021-07-23T19:26:39.486Z,1627068399.486 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-07-23T19:26:39.486Z,1627068399.486 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2021-07-23T19:26:39.487Z,1627068399.487 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2021-07-23T19:26:39.487Z,1627068399.487 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2
2021-07-23T19:26:39.871Z,1627068399.871 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2021-07-23T19:26:49.963Z,1627068409.963 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2021-07-23T19:26:49.963Z,1627068409.963 [DAT] Communications Fault, FailCount= 4
2021-07-23T19:26:49.963Z,1627068409.963 [DAT](ERROR): Communications Fault
2021-07-23T19:26:49.978Z,1627068409.978 [CBIT](ERROR): Communications Fault in component: DAT
2021-07-23T19:26:50.367Z,1627068410.367 [DAT](INFO): Powering down
2021-07-23T19:26:51.200Z,1627068411.200 [CBIT](INFO): Clearing failed state for component DAT
2021-07-23T19:26:51.200Z,1627068411.200 [DAT] No Fault, FailCount= 4
2021-07-23T19:26:53.683Z,1627068413.683 [DAT](INFO): Powering up
2021-07-23T19:26:53.684Z,1627068413.684 [DAT](DEBUG): Initializing DAT.
2021-07-23T19:27:09.808Z,1627068429.808 [CBIT](CRITICAL): Run-time exception #7
2021-07-23T19:27:09.808Z,1627068429.808 [CBIT] Software Fault, FailCount= 1
2021-07-23T19:27:09.808Z,1627068429.808 [CBIT](ERROR): Software Fault
2021-07-23T19:27:09.811Z,1627068429.811 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2021-07-23T19:27:09.811Z,1627068429.811 [SyncHandler](INFO): Protected caller Thread ID is 965
2021-07-23T19:27:10.177Z,1627068430.177 [CBIT](DEBUG): Uninitialize CBIT Component.
2021-07-23T19:27:10.177Z,1627068430.177 [CBIT](DEBUG): Powering off loads.
2021-07-23T19:27:10.199Z,1627068430.199 [CBIT](DEBUG): Disabling WDT.
2021-07-23T19:27:10.213Z,1627068430.213 [CBIT](DEBUG): Opening all GF detection circuits.
2021-07-23T19:27:38.458Z,1627068458.458 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2021-07-23T19:27:38.977Z,1627068458.977 [NAL9602](ERROR): received:
2021-07-23T19:27:40.713Z,1627068460.713 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-07-23T19:27:42.721Z,1627068462.721 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.255371
2021-07-23T19:27:53.955Z,1627068473.955 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2021-07-23T19:27:53.955Z,1627068473.955 [DAT] Communications Fault, FailCount= 5
2021-07-23T19:27:53.955Z,1627068473.955 [DAT](ERROR): Communications Fault
2021-07-23T19:27:54.359Z,1627068474.359 [DAT](INFO): Powering down
2021-07-23T19:28:09.307Z,1627068489.307 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2021-07-23T19:28:09.821Z,1627068489.821 [NAL9602](ERROR): received:
2021-07-23T19:28:15.853Z,1627068495.853 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-07-23T19:28:21.575Z,1627068501.575 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-07-23T19:28:30.115Z,1627068510.115 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T19:28:40.172Z,1627068520.172 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2021-07-23T19:28:40.172Z,1627068520.172 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2021-07-23T19:28:40.173Z,1627068520.173 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-07-23T19:28:40.195Z,1627068520.195 [DeadReckonUsingSpeedCalculator](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2021-07-23T19:28:40.195Z,1627068520.195 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 3
2021-07-23T19:28:40.195Z,1627068520.195 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2021-07-23T19:28:50.993Z,1627068530.993 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-07-23T19:28:53.193Z,1627068533.193 [NAL9602](ERROR): getFix uart error: serial timeout
2021-07-23T19:29:23.539Z,1627068563.539 [NAL9602](ERROR): parseGSV uart error: serial timeout
2021-07-23T19:29:26.133Z,1627068566.133 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-07-23T19:29:38.548Z,1627068578.548 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003266
2021-07-23T19:29:55.145Z,1627068595.145 [NAL9602](ERROR): getFix uart error: serial timeout
2021-07-23T19:30:03.711Z,1627068603.711 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T19:30:25.479Z,1627068625.479 [NAL9602](ERROR): parseGSV uart error: serial timeout
2021-07-23T19:30:57.129Z,1627068657.129 [NAL9602](ERROR): getFix uart error: serial timeout
2021-07-23T19:31:07.681Z,1627068667.681 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-23T19:26:07.5Z
2021-07-23T19:31:07.681Z,1627068667.681 [Default:CheckIn:Read_GPS] Stopped
2021-07-23T19:31:07.681Z,1627068667.681 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-23T19:31:08.105Z,1627068668.105 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-07-23T19:31:18.652Z,1627068678.652 [DataOverHttps](INFO): Sending 83 bytes from file Logs/20210723T192225/Courier0004.lzma
2021-07-23T19:31:19.654Z,1627068679.654 [DataOverHttps](INFO): Moved sent file to Logs/20210723T192225/Courier0004.lzma.bak
2021-07-23T19:31:19.655Z,1627068679.655 [DataOverHttps](INFO): SBD MOMSN=15758591
2021-07-23T19:31:27.467Z,1627068687.467 [NAL9602](ERROR): parseGSV uart error: serial timeout
2021-07-23T19:31:36.698Z,1627068696.698 [DataOverHttps](INFO): Sending 1184 bytes from file Logs/20210723T192225/Express0001.lzma
2021-07-23T19:31:37.699Z,1627068697.699 [DataOverHttps](INFO): Moved sent file to Logs/20210723T192225/Express0001.lzma.bak
2021-07-23T19:31:37.699Z,1627068697.699 [DataOverHttps](INFO): SBD MOMSN=15758594
2021-07-23T19:31:54.789Z,1627068714.789 [DataOverHttps](INFO): Sending 327 bytes from file Logs/20210723T192225/Express0005.lzma
2021-07-23T19:31:55.823Z,1627068715.823 [DataOverHttps](INFO): Moved sent file to Logs/20210723T192225/Express0005.lzma.bak
2021-07-23T19:31:55.823Z,1627068715.823 [DataOverHttps](INFO): SBD MOMSN=15758627
2021-07-23T19:31:58.176Z,1627068718.176 [Default:CheckIn:Read_Iridium] Stopped
2021-07-23T19:31:58.176Z,1627068718.176 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-23T19:31:58.176Z,1627068718.176 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-23T19:31:59.085Z,1627068719.085 [NAL9602](ERROR): getFix uart error: serial timeout
2021-07-23T19:32:29.423Z,1627068749.423 [NAL9602](ERROR): parseGSV uart error: serial timeout
2021-07-23T19:32:33.116Z,1627068753.116 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T19:33:01.077Z,1627068781.077 [NAL9602](ERROR): getFix uart error: serial timeout
2021-07-23T19:33:13.297Z,1627068793.297 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T19:33:31.423Z,1627068811.423 [NAL9602](ERROR): parseGSV uart error: serial timeout
2021-07-23T19:33:32.230Z,1627068812.230 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-07-23T19:33:32.230Z,1627068812.230 [NAL9602] Data Fault, FailCount= 1
2021-07-23T19:33:32.231Z,1627068812.231 [NAL9602](ERROR): Data Fault
2021-07-23T19:33:32.634Z,1627068812.634 [NAL9602](INFO): Powering down
2021-07-23T19:33:39.906Z,1627068819.906 [Power24vConverter](INFO): Powering down.
2021-07-23T19:35:00.348Z,1627068900.348 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T19:35:18.933Z,1627068918.933 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T19:36:59.491Z,1627069019.491 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-23T19:36:59.491Z,1627069019.491 [Default:CheckIn:C.Wait] Stopped
2021-07-23T19:36:59.491Z,1627069019.491 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-23T19:36:59.491Z,1627069019.491 [Default:CheckIn:D] Running Loop=1
2021-07-23T19:36:59.893Z,1627069019.893 [Default:CheckIn:D] Stopped
2021-07-23T19:36:59.893Z,1627069019.893 [Default:CheckIn:E] Running Loop=1
2021-07-23T19:37:00.297Z,1627069020.297 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.101000 min
2021-07-23T19:37:00.297Z,1627069020.297 [Default:CheckIn:E] Stopped
2021-07-23T19:37:00.297Z,1627069020.297 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-23T19:37:00.297Z,1627069020.297 [Default:CheckIn] Stopped
2021-07-23T19:37:00.297Z,1627069020.297 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-23T19:37:00.297Z,1627069020.297 [Default:CheckIn](INFO): Running loop #2
2021-07-23T19:37:00.298Z,1627069020.298 [Default:CheckIn] Running Loop=2
2021-07-23T19:37:00.298Z,1627069020.298 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-23T19:37:00.298Z,1627069020.298 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-23T19:37:30.229Z,1627069050.229 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T19:38:24.456Z,1627069104.456 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T19:42:00.575Z,1627069320.575 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-23T19:37:00.3Z
2021-07-23T19:42:00.575Z,1627069320.575 [Default:CheckIn:Read_GPS] Stopped
2021-07-23T19:42:00.575Z,1627069320.575 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-23T19:42:08.740Z,1627069328.740 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20210723T192225/Express0008.lzma
2021-07-23T19:42:09.742Z,1627069329.742 [DataOverHttps](INFO): Moved sent file to Logs/20210723T192225/Express0008.lzma.bak
2021-07-23T19:42:09.743Z,1627069329.743 [DataOverHttps](INFO): SBD MOMSN=15758644
2021-07-23T19:42:12.272Z,1627069332.272 [Default:CheckIn:Read_Iridium] Stopped
2021-07-23T19:42:12.272Z,1627069332.272 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-23T19:42:12.272Z,1627069332.272 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-23T19:45:46.469Z,1627069546.469 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T19:46:35.755Z,1627069595.755 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T19:47:12.554Z,1627069632.554 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T19:47:12.895Z,1627069632.895 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-23T19:47:12.895Z,1627069632.895 [Default:CheckIn:C.Wait] Stopped
2021-07-23T19:47:12.895Z,1627069632.895 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-23T19:47:12.895Z,1627069632.895 [Default:CheckIn:D] Running Loop=1
2021-07-23T19:47:13.304Z,1627069633.304 [Default:CheckIn:D] Stopped
2021-07-23T19:47:13.304Z,1627069633.304 [Default:CheckIn:E] Running Loop=1
2021-07-23T19:47:13.693Z,1627069633.693 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.324520 min
2021-07-23T19:47:13.693Z,1627069633.693 [Default:CheckIn:E] Stopped
2021-07-23T19:47:13.693Z,1627069633.693 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-23T19:47:13.693Z,1627069633.693 [Default:CheckIn] Stopped
2021-07-23T19:47:13.693Z,1627069633.693 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-23T19:47:13.693Z,1627069633.693 [Default:CheckIn](INFO): Running loop #3
2021-07-23T19:47:13.694Z,1627069633.694 [Default:CheckIn] Running Loop=3
2021-07-23T19:47:13.694Z,1627069633.694 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-23T19:47:13.694Z,1627069633.694 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-23T19:48:06.284Z,1627069686.284 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T19:50:06.692Z,1627069806.692 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T19:52:13.894Z,1627069933.894 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-23T19:47:13.7Z
2021-07-23T19:52:13.894Z,1627069933.894 [Default:CheckIn:Read_GPS] Stopped
2021-07-23T19:52:13.894Z,1627069933.894 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-23T19:52:22.632Z,1627069942.632 [DataOverHttps](INFO): Sending 97 bytes from file Logs/20210723T192225/Express0011.lzma
2021-07-23T19:52:23.635Z,1627069943.635 [DataOverHttps](INFO): Moved sent file to Logs/20210723T192225/Express0011.lzma.bak
2021-07-23T19:52:23.635Z,1627069943.635 [DataOverHttps](INFO): SBD MOMSN=15758657
2021-07-23T19:52:26.037Z,1627069946.037 [Default:CheckIn:Read_Iridium] Stopped
2021-07-23T19:52:26.037Z,1627069946.037 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-23T19:52:26.038Z,1627069946.038 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-23T19:53:16.185Z,1627069996.185 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T19:53:29.114Z,1627070009.114 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T19:53:38.752Z,1627070018.752 [BPC1](INFO): Calculating totals. Valid battery stick count: 28. Valid reserve battery stick count: 3.
2021-07-23T19:53:38.756Z,1627070018.756 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle.
2021-07-23T19:57:26.680Z,1627070246.680 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-23T19:57:26.680Z,1627070246.680 [Default:CheckIn:C.Wait] Stopped
2021-07-23T19:57:26.680Z,1627070246.680 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-23T19:57:26.680Z,1627070246.680 [Default:CheckIn:D] Running Loop=1
2021-07-23T19:57:27.076Z,1627070247.076 [Default:CheckIn:D] Stopped
2021-07-23T19:57:27.077Z,1627070247.077 [Default:CheckIn:E] Running Loop=1
2021-07-23T19:57:27.481Z,1627070247.481 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.554065 min
2021-07-23T19:57:27.481Z,1627070247.481 [Default:CheckIn:E] Stopped
2021-07-23T19:57:27.481Z,1627070247.481 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-23T19:57:27.481Z,1627070247.481 [Default:CheckIn] Stopped
2021-07-23T19:57:27.481Z,1627070247.481 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-23T19:57:27.481Z,1627070247.481 [Default:CheckIn](INFO): Running loop #4
2021-07-23T19:57:27.482Z,1627070247.482 [Default:CheckIn] Running Loop=4
2021-07-23T19:57:27.482Z,1627070247.482 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-23T19:57:27.482Z,1627070247.482 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-23T20:02:27.701Z,1627070547.701 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-23T19:57:27.5Z
2021-07-23T20:02:27.701Z,1627070547.701 [Default:CheckIn:Read_GPS] Stopped
2021-07-23T20:02:27.701Z,1627070547.701 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-23T20:02:34.557Z,1627070554.557 [DataOverHttps](INFO): Sending 186 bytes from file Logs/20210723T192225/Courier0013.lzma
2021-07-23T20:02:35.558Z,1627070555.559 [DataOverHttps](INFO): Moved sent file to Logs/20210723T192225/Courier0013.lzma.bak
2021-07-23T20:02:35.559Z,1627070555.559 [DataOverHttps](INFO): SBD MOMSN=15758667
2021-07-23T20:02:51.288Z,1627070571.288 [DataOverHttps](INFO): Sending 97 bytes from file Logs/20210723T192225/Express0014.lzma
2021-07-23T20:02:52.291Z,1627070572.291 [DataOverHttps](INFO): Moved sent file to Logs/20210723T192225/Express0014.lzma.bak
2021-07-23T20:02:52.291Z,1627070572.291 [DataOverHttps](INFO): SBD MOMSN=15758669
2021-07-23T20:02:54.820Z,1627070574.820 [Default:CheckIn:Read_Iridium] Stopped
2021-07-23T20:02:54.820Z,1627070574.820 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-23T20:02:54.820Z,1627070574.820 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-23T20:07:55.396Z,1627070875.396 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-23T20:07:55.396Z,1627070875.396 [Default:CheckIn:C.Wait] Stopped
2021-07-23T20:07:55.396Z,1627070875.396 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-23T20:07:55.397Z,1627070875.397 [Default:CheckIn:D] Running Loop=1
2021-07-23T20:07:55.818Z,1627070875.818 [Default:CheckIn:D] Stopped
2021-07-23T20:07:55.818Z,1627070875.818 [Default:CheckIn:E] Running Loop=1
2021-07-23T20:07:56.217Z,1627070876.217 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 42.033089 min
2021-07-23T20:07:56.217Z,1627070876.217 [Default:CheckIn:E] Stopped
2021-07-23T20:07:56.217Z,1627070876.217 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-23T20:07:56.217Z,1627070876.217 [Default:CheckIn] Stopped
2021-07-23T20:07:56.217Z,1627070876.217 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-23T20:07:56.218Z,1627070876.218 [Default:CheckIn](INFO): Running loop #5
2021-07-23T20:07:56.218Z,1627070876.218 [Default:CheckIn] Running Loop=5
2021-07-23T20:07:56.218Z,1627070876.218 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-23T20:07:56.218Z,1627070876.218 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-23T20:12:56.469Z,1627071176.469 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-23T20:07:56.2Z
2021-07-23T20:12:56.469Z,1627071176.469 [Default:CheckIn:Read_GPS] Stopped
2021-07-23T20:12:56.469Z,1627071176.469 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-23T20:13:04.892Z,1627071184.892 [DataOverHttps](INFO): Sending 97 bytes from file Logs/20210723T192225/Express0017.lzma
2021-07-23T20:13:05.895Z,1627071185.895 [DataOverHttps](INFO): Moved sent file to Logs/20210723T192225/Express0017.lzma.bak
2021-07-23T20:13:05.895Z,1627071185.895 [DataOverHttps](INFO): SBD MOMSN=15758679
2021-07-23T20:13:08.176Z,1627071188.176 [Default:CheckIn:Read_Iridium] Stopped
2021-07-23T20:13:08.176Z,1627071188.176 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-23T20:13:08.176Z,1627071188.176 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-23T20:18:08.756Z,1627071488.756 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-23T20:18:08.756Z,1627071488.756 [Default:CheckIn:C.Wait] Stopped
2021-07-23T20:18:08.757Z,1627071488.757 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-23T20:18:08.757Z,1627071488.757 [Default:CheckIn:D] Running Loop=1
2021-07-23T20:18:09.169Z,1627071489.169 [Default:CheckIn:D] Stopped
2021-07-23T20:18:09.169Z,1627071489.169 [Default:CheckIn:E] Running Loop=1
2021-07-23T20:18:09.565Z,1627071489.565 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 52.255603 min
2021-07-23T20:18:09.565Z,1627071489.565 [Default:CheckIn:E] Stopped
2021-07-23T20:18:09.565Z,1627071489.565 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-23T20:18:09.565Z,1627071489.565 [Default:CheckIn] Stopped
2021-07-23T20:18:09.565Z,1627071489.565 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-23T20:18:09.565Z,1627071489.565 [Default:CheckIn](INFO): Running loop #6
2021-07-23T20:18:09.566Z,1627071489.566 [Default:CheckIn] Running Loop=6
2021-07-23T20:18:09.566Z,1627071489.566 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-23T20:18:09.566Z,1627071489.566 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-23T20:23:09.924Z,1627071789.924 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-23T20:18:09.6Z
2021-07-23T20:23:09.924Z,1627071789.924 [Default:CheckIn:Read_GPS] Stopped
2021-07-23T20:23:09.924Z,1627071789.924 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-23T20:23:18.756Z,1627071798.756 [DataOverHttps](INFO): Sending 97 bytes from file Logs/20210723T192225/Express0020.lzma
2021-07-23T20:23:19.775Z,1627071799.775 [DataOverHttps](INFO): Moved sent file to Logs/20210723T192225/Express0020.lzma.bak
2021-07-23T20:23:19.775Z,1627071799.775 [DataOverHttps](INFO): SBD MOMSN=15758688
2021-07-23T20:23:22.040Z,1627071802.040 [Default:CheckIn:Read_Iridium] Stopped
2021-07-23T20:23:22.040Z,1627071802.040 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-23T20:23:22.040Z,1627071802.040 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-23T20:28:22.640Z,1627072102.640 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-23T20:28:22.640Z,1627072102.640 [Default:CheckIn:C.Wait] Stopped
2021-07-23T20:28:22.641Z,1627072102.641 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-23T20:28:22.641Z,1627072102.641 [Default:CheckIn:D] Running Loop=1
2021-07-23T20:28:23.036Z,1627072103.036 [Default:CheckIn:D] Stopped
2021-07-23T20:28:23.037Z,1627072103.037 [Default:CheckIn:E] Running Loop=1
2021-07-23T20:28:23.441Z,1627072103.441 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 62.486731 min
2021-07-23T20:28:23.441Z,1627072103.441 [Default:CheckIn:E] Stopped
2021-07-23T20:28:23.441Z,1627072103.441 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-23T20:28:23.441Z,1627072103.441 [Default:CheckIn] Stopped
2021-07-23T20:28:23.441Z,1627072103.441 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-23T20:28:23.441Z,1627072103.441 [Default:CheckIn](INFO): Running loop #7
2021-07-23T20:28:23.442Z,1627072103.442 [Default:CheckIn] Running Loop=7
2021-07-23T20:28:23.442Z,1627072103.442 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-23T20:28:23.442Z,1627072103.442 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-23T20:33:23.741Z,1627072403.741 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-23T20:28:23.4Z
2021-07-23T20:33:23.741Z,1627072403.741 [Default:CheckIn:Read_GPS] Stopped
2021-07-23T20:33:23.741Z,1627072403.741 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-23T20:33:31.048Z,1627072411.048 [DataOverHttps](INFO): Sending 97 bytes from file Logs/20210723T192225/Express0023.lzma
2021-07-23T20:33:32.039Z,1627072412.039 [DataOverHttps](INFO): Moved sent file to Logs/20210723T192225/Express0023.lzma.bak
2021-07-23T20:33:32.039Z,1627072412.039 [DataOverHttps](INFO): SBD MOMSN=15758698
2021-07-23T20:33:34.244Z,1627072414.244 [Default:CheckIn:Read_Iridium] Stopped
2021-07-23T20:33:34.244Z,1627072414.244 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-23T20:33:34.244Z,1627072414.244 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-23T20:38:34.856Z,1627072714.856 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-23T20:38:34.856Z,1627072714.856 [Default:CheckIn:C.Wait] Stopped
2021-07-23T20:38:34.857Z,1627072714.857 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-23T20:38:34.857Z,1627072714.857 [Default:CheckIn:D] Running Loop=1
2021-07-23T20:38:35.260Z,1627072715.260 [Default:CheckIn:D] Stopped
2021-07-23T20:38:35.261Z,1627072715.261 [Default:CheckIn:E] Running Loop=1
2021-07-23T20:38:35.665Z,1627072715.665 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 72.690462 min
2021-07-23T20:38:35.665Z,1627072715.665 [Default:CheckIn:E] Stopped
2021-07-23T20:38:35.665Z,1627072715.665 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-23T20:38:35.665Z,1627072715.665 [Default:CheckIn] Stopped
2021-07-23T20:38:35.665Z,1627072715.665 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-23T20:38:35.665Z,1627072715.665 [Default:CheckIn](INFO): Running loop #8
2021-07-23T20:38:35.666Z,1627072715.666 [Default:CheckIn] Running Loop=8
2021-07-23T20:38:35.666Z,1627072715.666 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-23T20:38:35.666Z,1627072715.666 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-23T20:43:35.953Z,1627073015.953 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-23T20:38:35.7Z
2021-07-23T20:43:35.953Z,1627073015.953 [Default:CheckIn:Read_GPS] Stopped
2021-07-23T20:43:35.953Z,1627073015.953 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-23T20:43:44.400Z,1627073024.400 [DataOverHttps](INFO): Sending 98 bytes from file Logs/20210723T192225/Express0026.lzma
2021-07-23T20:43:45.403Z,1627073025.403 [DataOverHttps](INFO): Moved sent file to Logs/20210723T192225/Express0026.lzma.bak
2021-07-23T20:43:45.403Z,1627073025.403 [DataOverHttps](INFO): SBD MOMSN=15758709
2021-07-23T20:43:47.692Z,1627073027.692 [Default:CheckIn:Read_Iridium] Stopped
2021-07-23T20:43:47.693Z,1627073027.693 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-23T20:43:47.693Z,1627073027.693 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-23T20:48:48.292Z,1627073328.292 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-23T20:48:48.292Z,1627073328.292 [Default:CheckIn:C.Wait] Stopped
2021-07-23T20:48:48.292Z,1627073328.292 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-23T20:48:48.293Z,1627073328.293 [Default:CheckIn:D] Running Loop=1
2021-07-23T20:48:48.717Z,1627073328.717 [Default:CheckIn:D] Stopped
2021-07-23T20:48:48.717Z,1627073328.717 [Default:CheckIn:E] Running Loop=1
2021-07-23T20:48:49.114Z,1627073329.114 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 82.914738 min
2021-07-23T20:48:49.114Z,1627073329.114 [Default:CheckIn:E] Stopped
2021-07-23T20:48:49.114Z,1627073329.114 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-23T20:48:49.114Z,1627073329.114 [Default:CheckIn] Stopped
2021-07-23T20:48:49.114Z,1627073329.114 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-23T20:48:49.114Z,1627073329.114 [Default:CheckIn](INFO): Running loop #9
2021-07-23T20:48:49.115Z,1627073329.115 [Default:CheckIn] Running Loop=9
2021-07-23T20:48:49.115Z,1627073329.115 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-23T20:48:49.115Z,1627073329.115 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-23T20:53:49.301Z,1627073629.301 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-23T20:48:49.1Z
2021-07-23T20:53:49.301Z,1627073629.301 [Default:CheckIn:Read_GPS] Stopped
2021-07-23T20:53:49.301Z,1627073629.301 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-23T20:53:57.652Z,1627073637.652 [DataOverHttps](INFO): Sending 98 bytes from file Logs/20210723T192225/Express0029.lzma
2021-07-23T20:53:58.655Z,1627073638.655 [DataOverHttps](INFO): Moved sent file to Logs/20210723T192225/Express0029.lzma.bak
2021-07-23T20:53:58.655Z,1627073638.655 [DataOverHttps](INFO): SBD MOMSN=15758722
2021-07-23T20:54:01.016Z,1627073641.016 [Default:CheckIn:Read_Iridium] Stopped
2021-07-23T20:54:01.016Z,1627073641.016 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-23T20:54:01.016Z,1627073641.016 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-23T20:57:09.079Z,1627073829.079 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T20:59:01.643Z,1627073941.643 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-23T20:59:01.643Z,1627073941.643 [Default:CheckIn:C.Wait] Stopped
2021-07-23T20:59:01.643Z,1627073941.643 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-23T20:59:01.643Z,1627073941.643 [Default:CheckIn:D] Running Loop=1
2021-07-23T20:59:02.044Z,1627073942.044 [Default:CheckIn:D] Stopped
2021-07-23T20:59:02.053Z,1627073942.053 [Default:CheckIn:E] Running Loop=1
2021-07-23T20:59:02.449Z,1627073942.449 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 93.136865 min
2021-07-23T20:59:02.449Z,1627073942.449 [Default:CheckIn:E] Stopped
2021-07-23T20:59:02.449Z,1627073942.449 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-23T20:59:02.449Z,1627073942.449 [Default:CheckIn] Stopped
2021-07-23T20:59:02.449Z,1627073942.449 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-23T20:59:02.449Z,1627073942.449 [Default:CheckIn](INFO): Running loop #10
2021-07-23T20:59:02.450Z,1627073942.450 [Default:CheckIn] Running Loop=10
2021-07-23T20:59:02.450Z,1627073942.450 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-23T20:59:02.450Z,1627073942.450 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-23T21:01:53.851Z,1627074113.851 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T21:03:44.518Z,1627074224.518 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T21:04:02.657Z,1627074242.657 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-23T20:59:02.4Z
2021-07-23T21:04:02.657Z,1627074242.657 [Default:CheckIn:Read_GPS] Stopped
2021-07-23T21:04:02.657Z,1627074242.657 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-23T21:04:09.616Z,1627074249.616 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T21:04:11.416Z,1627074251.416 [DataOverHttps](INFO): Sending 97 bytes from file Logs/20210723T192225/Express0032.lzma
2021-07-23T21:04:12.419Z,1627074252.419 [DataOverHttps](INFO): Moved sent file to Logs/20210723T192225/Express0032.lzma.bak
2021-07-23T21:04:12.419Z,1627074252.419 [DataOverHttps](INFO): SBD MOMSN=15758733
2021-07-23T21:04:14.776Z,1627074254.776 [Default:CheckIn:Read_Iridium] Stopped
2021-07-23T21:04:14.776Z,1627074254.776 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-23T21:04:14.776Z,1627074254.776 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-23T21:06:45.540Z,1627074405.540 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T21:08:33.861Z,1627074513.861 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T21:09:15.440Z,1627074555.440 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-23T21:09:15.441Z,1627074555.441 [Default:CheckIn:C.Wait] Stopped
2021-07-23T21:09:15.441Z,1627074555.441 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-23T21:09:15.441Z,1627074555.441 [Default:CheckIn:D] Running Loop=1
2021-07-23T21:09:15.827Z,1627074555.827 [Default:CheckIn:D] Stopped
2021-07-23T21:09:15.827Z,1627074555.827 [Default:CheckIn:E] Running Loop=1
2021-07-23T21:09:16.213Z,1627074556.213 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 103.366577 min
2021-07-23T21:09:16.213Z,1627074556.213 [Default:CheckIn:E] Stopped
2021-07-23T21:09:16.213Z,1627074556.213 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-23T21:09:16.213Z,1627074556.213 [Default:CheckIn] Stopped
2021-07-23T21:09:16.213Z,1627074556.213 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-23T21:09:16.214Z,1627074556.214 [Default:CheckIn](INFO): Running loop #11
2021-07-23T21:09:16.214Z,1627074556.214 [Default:CheckIn] Running Loop=11
2021-07-23T21:09:16.214Z,1627074556.214 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-23T21:09:16.214Z,1627074556.214 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-23T21:12:08.065Z,1627074728.065 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T21:12:58.145Z,1627074778.145 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T21:13:23.171Z,1627074803.171 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T21:14:07.206Z,1627074847.206 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T21:14:16.495Z,1627074856.495 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-23T21:09:16.2Z
2021-07-23T21:14:16.495Z,1627074856.495 [Default:CheckIn:Read_GPS] Stopped
2021-07-23T21:14:16.496Z,1627074856.496 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-23T21:14:24.304Z,1627074864.304 [DataOverHttps](INFO): Sending 98 bytes from file Logs/20210723T192225/Express0035.lzma
2021-07-23T21:14:25.307Z,1627074865.307 [DataOverHttps](INFO): Moved sent file to Logs/20210723T192225/Express0035.lzma.bak
2021-07-23T21:14:25.307Z,1627074865.307 [DataOverHttps](INFO): SBD MOMSN=15758745
2021-07-23T21:14:27.804Z,1627074867.804 [Default:CheckIn:Read_Iridium] Stopped
2021-07-23T21:14:27.804Z,1627074867.804 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-23T21:14:27.804Z,1627074867.804 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-23T21:15:02.634Z,1627074902.634 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T21:18:26.222Z,1627075106.222 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T21:19:28.388Z,1627075168.388 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-23T21:19:28.388Z,1627075168.388 [Default:CheckIn:C.Wait] Stopped
2021-07-23T21:19:28.389Z,1627075168.389 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-23T21:19:28.389Z,1627075168.389 [Default:CheckIn:D] Running Loop=1
2021-07-23T21:19:28.800Z,1627075168.800 [Default:CheckIn:D] Stopped
2021-07-23T21:19:28.801Z,1627075168.801 [Default:CheckIn:E] Running Loop=1
2021-07-23T21:19:29.221Z,1627075169.221 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 113.582796 min
2021-07-23T21:19:29.221Z,1627075169.221 [Default:CheckIn:E] Stopped
2021-07-23T21:19:29.221Z,1627075169.221 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-23T21:19:29.221Z,1627075169.221 [Default:CheckIn] Stopped
2021-07-23T21:19:29.222Z,1627075169.222 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-23T21:19:29.222Z,1627075169.222 [Default:CheckIn](INFO): Running loop #12
2021-07-23T21:19:29.222Z,1627075169.222 [Default:CheckIn] Running Loop=12
2021-07-23T21:19:29.222Z,1627075169.222 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-23T21:19:29.222Z,1627075169.222 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-23T21:19:46.212Z,1627075186.212 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T21:20:53.342Z,1627075253.342 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T21:22:52.180Z,1627075372.180 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T21:23:03.894Z,1627075383.894 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T21:24:29.522Z,1627075469.522 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-23T21:19:29.2Z
2021-07-23T21:24:29.523Z,1627075469.523 [Default:CheckIn:Read_GPS] Stopped
2021-07-23T21:24:29.523Z,1627075469.523 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-23T21:24:38.072Z,1627075478.072 [DataOverHttps](INFO): Sending 98 bytes from file Logs/20210723T192225/Express0038.lzma
2021-07-23T21:24:39.075Z,1627075479.075 [DataOverHttps](INFO): Moved sent file to Logs/20210723T192225/Express0038.lzma.bak
2021-07-23T21:24:39.075Z,1627075479.075 [DataOverHttps](INFO): SBD MOMSN=15758754
2021-07-23T21:24:39.632Z,1627075479.632 [BPC1](INFO): Calculating totals. Valid battery stick count: 28. Valid reserve battery stick count: 3.
2021-07-23T21:24:39.635Z,1627075479.635 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle.
2021-07-23T21:24:41.256Z,1627075481.256 [Default:CheckIn:Read_Iridium] Stopped
2021-07-23T21:24:41.256Z,1627075481.256 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-23T21:24:41.256Z,1627075481.256 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-23T21:29:41.832Z,1627075781.832 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-23T21:29:41.832Z,1627075781.832 [Default:CheckIn:C.Wait] Stopped
2021-07-23T21:29:41.833Z,1627075781.833 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-23T21:29:41.833Z,1627075781.833 [Default:CheckIn:D] Running Loop=1
2021-07-23T21:29:42.237Z,1627075782.237 [Default:CheckIn:D] Stopped
2021-07-23T21:29:42.237Z,1627075782.237 [Default:CheckIn:E] Running Loop=1
2021-07-23T21:29:42.641Z,1627075782.641 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 123.806730 min
2021-07-23T21:29:42.641Z,1627075782.641 [Default:CheckIn:E] Stopped
2021-07-23T21:29:42.641Z,1627075782.641 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-23T21:29:42.641Z,1627075782.641 [Default:CheckIn] Stopped
2021-07-23T21:29:42.641Z,1627075782.641 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-23T21:29:42.641Z,1627075782.641 [Default:CheckIn](INFO): Running loop #13
2021-07-23T21:29:42.642Z,1627075782.642 [Default:CheckIn] Running Loop=13
2021-07-23T21:29:42.642Z,1627075782.642 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-23T21:29:42.642Z,1627075782.642 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-23T21:34:42.873Z,1627076082.873 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-23T21:29:42.6Z
2021-07-23T21:34:42.873Z,1627076082.873 [Default:CheckIn:Read_GPS] Stopped
2021-07-23T21:34:42.873Z,1627076082.873 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-23T21:34:49.860Z,1627076089.860 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20210723T192225/Courier0040.lzma
2021-07-23T21:34:50.863Z,1627076090.863 [DataOverHttps](INFO): Moved sent file to Logs/20210723T192225/Courier0040.lzma.bak
2021-07-23T21:34:50.863Z,1627076090.863 [DataOverHttps](INFO): SBD MOMSN=15758765
2021-07-23T21:35:06.612Z,1627076106.612 [DataOverHttps](INFO): Sending 98 bytes from file Logs/20210723T192225/Express0041.lzma
2021-07-23T21:35:07.615Z,1627076107.615 [DataOverHttps](INFO): Moved sent file to Logs/20210723T192225/Express0041.lzma.bak
2021-07-23T21:35:07.615Z,1627076107.615 [DataOverHttps](INFO): SBD MOMSN=15758767
2021-07-23T21:35:09.971Z,1627076109.971 [Default:CheckIn:Read_Iridium] Stopped
2021-07-23T21:35:09.971Z,1627076109.971 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-23T21:35:09.971Z,1627076109.971 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-23T21:40:10.548Z,1627076410.548 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-23T21:40:10.548Z,1627076410.548 [Default:CheckIn:C.Wait] Stopped
2021-07-23T21:40:10.549Z,1627076410.549 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-23T21:40:10.549Z,1627076410.549 [Default:CheckIn:D] Running Loop=1
2021-07-23T21:40:10.952Z,1627076410.952 [Default:CheckIn:D] Stopped
2021-07-23T21:40:10.953Z,1627076410.953 [Default:CheckIn:E] Running Loop=1
2021-07-23T21:40:11.369Z,1627076411.369 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 134.285327 min
2021-07-23T21:40:11.369Z,1627076411.369 [Default:CheckIn:E] Stopped
2021-07-23T21:40:11.369Z,1627076411.369 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-23T21:40:11.369Z,1627076411.369 [Default:CheckIn] Stopped
2021-07-23T21:40:11.369Z,1627076411.369 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-23T21:40:11.370Z,1627076411.370 [Default:CheckIn](INFO): Running loop #14
2021-07-23T21:40:11.370Z,1627076411.370 [Default:CheckIn] Running Loop=14
2021-07-23T21:40:11.370Z,1627076411.370 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-23T21:40:11.370Z,1627076411.370 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-23T21:45:11.547Z,1627076711.547 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-23T21:40:11.4Z
2021-07-23T21:45:11.547Z,1627076711.547 [Default:CheckIn:Read_GPS] Stopped
2021-07-23T21:45:11.547Z,1627076711.547 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-23T21:45:18.879Z,1627076718.879 [DataOverHttps](INFO): Sending 98 bytes from file Logs/20210723T192225/Express0044.lzma
2021-07-23T21:45:19.879Z,1627076719.879 [DataOverHttps](INFO): Moved sent file to Logs/20210723T192225/Express0044.lzma.bak
2021-07-23T21:45:19.879Z,1627076719.879 [DataOverHttps](INFO): SBD MOMSN=15758776
2021-07-23T21:45:22.064Z,1627076722.064 [Default:CheckIn:Read_Iridium] Stopped
2021-07-23T21:45:22.064Z,1627076722.064 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-23T21:45:22.064Z,1627076722.064 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-23T21:50:22.716Z,1627077022.716 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-23T21:50:22.717Z,1627077022.717 [Default:CheckIn:C.Wait] Stopped
2021-07-23T21:50:22.717Z,1627077022.717 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-23T21:50:22.717Z,1627077022.717 [Default:CheckIn:D] Running Loop=1
2021-07-23T21:50:23.117Z,1627077023.117 [Default:CheckIn:D] Stopped
2021-07-23T21:50:23.117Z,1627077023.117 [Default:CheckIn:E] Running Loop=1
2021-07-23T21:50:23.513Z,1627077023.513 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 144.488070 min
2021-07-23T21:50:23.513Z,1627077023.513 [Default:CheckIn:E] Stopped
2021-07-23T21:50:23.513Z,1627077023.513 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-23T21:50:23.513Z,1627077023.513 [Default:CheckIn] Stopped
2021-07-23T21:50:23.513Z,1627077023.513 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-23T21:50:23.514Z,1627077023.514 [Default:CheckIn](INFO): Running loop #15
2021-07-23T21:50:23.514Z,1627077023.514 [Default:CheckIn] Running Loop=15
2021-07-23T21:50:23.514Z,1627077023.514 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-23T21:50:23.514Z,1627077023.514 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-23T21:55:23.751Z,1627077323.751 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-23T21:50:23.5Z
2021-07-23T21:55:23.751Z,1627077323.751 [Default:CheckIn:Read_GPS] Stopped
2021-07-23T21:55:23.751Z,1627077323.751 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-23T21:55:31.940Z,1627077331.940 [DataOverHttps](INFO): Sending 98 bytes from file Logs/20210723T192225/Express0047.lzma
2021-07-23T21:55:32.943Z,1627077332.943 [DataOverHttps](INFO): Moved sent file to Logs/20210723T192225/Express0047.lzma.bak
2021-07-23T21:55:32.943Z,1627077332.943 [DataOverHttps](INFO): SBD MOMSN=15758781
2021-07-23T21:55:35.464Z,1627077335.464 [Default:CheckIn:Read_Iridium] Stopped
2021-07-23T21:55:35.464Z,1627077335.464 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-23T21:55:35.464Z,1627077335.464 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-23T22:00:36.068Z,1627077636.068 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-23T22:00:36.085Z,1627077636.085 [Default:CheckIn:C.Wait] Stopped
2021-07-23T22:00:36.085Z,1627077636.085 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-23T22:00:36.085Z,1627077636.085 [Default:CheckIn:D] Running Loop=1
2021-07-23T22:00:36.460Z,1627077636.460 [Default:CheckIn:D] Stopped
2021-07-23T22:00:36.460Z,1627077636.460 [Default:CheckIn:E] Running Loop=1
2021-07-23T22:00:36.849Z,1627077636.849 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 154.710465 min
2021-07-23T22:00:36.849Z,1627077636.849 [Default:CheckIn:E] Stopped
2021-07-23T22:00:36.849Z,1627077636.849 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-23T22:00:36.849Z,1627077636.849 [Default:CheckIn] Stopped
2021-07-23T22:00:36.849Z,1627077636.849 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-23T22:00:36.850Z,1627077636.850 [Default:CheckIn](INFO): Running loop #16
2021-07-23T22:00:36.850Z,1627077636.850 [Default:CheckIn] Running Loop=16
2021-07-23T22:00:36.850Z,1627077636.850 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-23T22:00:36.850Z,1627077636.850 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-23T22:05:37.081Z,1627077937.081 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-23T22:00:36.8Z
2021-07-23T22:05:37.081Z,1627077937.081 [Default:CheckIn:Read_GPS] Stopped
2021-07-23T22:05:37.081Z,1627077937.081 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-23T22:05:45.212Z,1627077945.212 [DataOverHttps](INFO): Sending 98 bytes from file Logs/20210723T192225/Express0050.lzma
2021-07-23T22:05:46.215Z,1627077946.215 [DataOverHttps](INFO): Moved sent file to Logs/20210723T192225/Express0050.lzma.bak
2021-07-23T22:05:46.215Z,1627077946.215 [DataOverHttps](INFO): SBD MOMSN=15758789
2021-07-23T22:05:48.460Z,1627077948.460 [Default:CheckIn:Read_Iridium] Stopped
2021-07-23T22:05:48.460Z,1627077948.460 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-23T22:05:48.460Z,1627077948.460 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-23T22:10:49.078Z,1627078249.078 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-23T22:10:49.078Z,1627078249.078 [Default:CheckIn:C.Wait] Stopped
2021-07-23T22:10:49.079Z,1627078249.079 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-23T22:10:49.079Z,1627078249.079 [Default:CheckIn:D] Running Loop=1
2021-07-23T22:10:49.480Z,1627078249.480 [Default:CheckIn:D] Stopped
2021-07-23T22:10:49.480Z,1627078249.480 [Default:CheckIn:E] Running Loop=1
2021-07-23T22:10:49.883Z,1627078249.883 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 164.927458 min
2021-07-23T22:10:49.884Z,1627078249.884 [Default:CheckIn:E] Stopped
2021-07-23T22:10:49.884Z,1627078249.884 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-23T22:10:49.884Z,1627078249.884 [Default:CheckIn] Stopped
2021-07-23T22:10:49.884Z,1627078249.884 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-23T22:10:49.884Z,1627078249.884 [Default:CheckIn](INFO): Running loop #17
2021-07-23T22:10:49.884Z,1627078249.884 [Default:CheckIn] Running Loop=17
2021-07-23T22:10:49.884Z,1627078249.884 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-23T22:10:49.884Z,1627078249.884 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-23T22:15:50.073Z,1627078550.073 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-23T22:10:49.9Z
2021-07-23T22:15:50.073Z,1627078550.073 [Default:CheckIn:Read_GPS] Stopped
2021-07-23T22:15:50.073Z,1627078550.073 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-23T22:15:58.280Z,1627078558.280 [DataOverHttps](INFO): Sending 98 bytes from file Logs/20210723T192225/Express0053.lzma
2021-07-23T22:15:59.283Z,1627078559.283 [DataOverHttps](INFO): Moved sent file to Logs/20210723T192225/Express0053.lzma.bak
2021-07-23T22:15:59.283Z,1627078559.283 [DataOverHttps](INFO): SBD MOMSN=15758798
2021-07-23T22:16:01.808Z,1627078561.808 [Default:CheckIn:Read_Iridium] Stopped
2021-07-23T22:16:01.808Z,1627078561.808 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-23T22:16:01.808Z,1627078561.808 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-23T22:21:02.444Z,1627078862.444 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-23T22:21:02.444Z,1627078862.444 [Default:CheckIn:C.Wait] Stopped
2021-07-23T22:21:02.444Z,1627078862.444 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-23T22:21:02.444Z,1627078862.444 [Default:CheckIn:D] Running Loop=1
2021-07-23T22:21:02.865Z,1627078862.865 [Default:CheckIn:D] Stopped
2021-07-23T22:21:02.865Z,1627078862.865 [Default:CheckIn:E] Running Loop=1
2021-07-23T22:21:03.261Z,1627078863.261 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 175.150537 min
2021-07-23T22:21:03.261Z,1627078863.261 [Default:CheckIn:E] Stopped
2021-07-23T22:21:03.261Z,1627078863.261 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-23T22:21:03.261Z,1627078863.261 [Default:CheckIn] Stopped
2021-07-23T22:21:03.261Z,1627078863.261 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-23T22:21:03.262Z,1627078863.262 [Default:CheckIn](INFO): Running loop #18
2021-07-23T22:21:03.262Z,1627078863.262 [Default:CheckIn] Running Loop=18
2021-07-23T22:21:03.262Z,1627078863.262 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-23T22:21:03.262Z,1627078863.262 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-23T22:26:03.489Z,1627079163.489 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-23T22:21:03.3Z
2021-07-23T22:26:03.489Z,1627079163.489 [Default:CheckIn:Read_GPS] Stopped
2021-07-23T22:26:03.489Z,1627079163.489 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-23T22:26:11.912Z,1627079171.912 [DataOverHttps](INFO): Sending 98 bytes from file Logs/20210723T192225/Express0056.lzma
2021-07-23T22:26:12.915Z,1627079172.915 [DataOverHttps](INFO): Moved sent file to Logs/20210723T192225/Express0056.lzma.bak
2021-07-23T22:26:12.915Z,1627079172.915 [DataOverHttps](INFO): SBD MOMSN=15758808
2021-07-23T22:26:15.200Z,1627079175.200 [Default:CheckIn:Read_Iridium] Stopped
2021-07-23T22:26:15.200Z,1627079175.200 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-23T22:26:15.200Z,1627079175.200 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-23T22:26:47.616Z,1627079207.616 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T22:27:40.538Z,1627079260.538 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T22:29:24.783Z,1627079364.783 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T22:29:36.911Z,1627079376.911 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T22:29:48.610Z,1627079388.610 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T22:31:15.867Z,1627079475.867 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-23T22:31:15.868Z,1627079475.868 [Default:CheckIn:C.Wait] Stopped
2021-07-23T22:31:15.868Z,1627079475.868 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-23T22:31:15.868Z,1627079475.868 [Default:CheckIn:D] Running Loop=1
2021-07-23T22:31:16.260Z,1627079476.260 [Default:CheckIn:D] Stopped
2021-07-23T22:31:16.261Z,1627079476.261 [Default:CheckIn:E] Running Loop=1
2021-07-23T22:31:16.665Z,1627079476.665 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 185.373796 min
2021-07-23T22:31:16.665Z,1627079476.665 [Default:CheckIn:E] Stopped
2021-07-23T22:31:16.665Z,1627079476.665 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-23T22:31:16.665Z,1627079476.665 [Default:CheckIn] Stopped
2021-07-23T22:31:16.665Z,1627079476.665 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-23T22:31:16.666Z,1627079476.666 [Default:CheckIn](INFO): Running loop #19
2021-07-23T22:31:16.666Z,1627079476.666 [Default:CheckIn] Running Loop=19
2021-07-23T22:31:16.666Z,1627079476.666 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-23T22:31:16.666Z,1627079476.666 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-23T22:32:36.750Z,1627079556.750 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T22:33:03.010Z,1627079583.010 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T22:34:23.826Z,1627079663.826 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T22:36:16.901Z,1627079776.901 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-23T22:31:16.7Z
2021-07-23T22:36:16.901Z,1627079776.901 [Default:CheckIn:Read_GPS] Stopped
2021-07-23T22:36:16.901Z,1627079776.901 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-23T22:36:25.344Z,1627079785.344 [DataOverHttps](INFO): Sending 98 bytes from file Logs/20210723T192225/Express0059.lzma
2021-07-23T22:36:26.347Z,1627079786.347 [DataOverHttps](INFO): Moved sent file to Logs/20210723T192225/Express0059.lzma.bak
2021-07-23T22:36:26.347Z,1627079786.347 [DataOverHttps](INFO): SBD MOMSN=15758817
2021-07-23T22:36:28.676Z,1627079788.676 [Default:CheckIn:Read_Iridium] Stopped
2021-07-23T22:36:28.676Z,1627079788.676 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-23T22:36:28.676Z,1627079788.676 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-23T22:38:13.358Z,1627079893.358 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T22:39:24.423Z,1627079964.423 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file).
2021-07-23T22:41:29.279Z,1627080089.279 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-23T22:41:29.279Z,1627080089.279 [Default:CheckIn:C.Wait] Stopped
2021-07-23T22:41:29.280Z,1627080089.280 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-23T22:41:29.280Z,1627080089.280 [Default:CheckIn:D] Running Loop=1
2021-07-23T22:41:29.680Z,1627080089.680 [Default:CheckIn:D] Stopped
2021-07-23T22:41:29.681Z,1627080089.681 [Default:CheckIn:E] Running Loop=1
2021-07-23T22:41:30.085Z,1627080090.085 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 195.597461 min
2021-07-23T22:41:30.085Z,1627080090.085 [Default:CheckIn:E] Stopped
2021-07-23T22:41:30.085Z,1627080090.085 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-23T22:41:30.085Z,1627080090.085 [Default:CheckIn] Stopped
2021-07-23T22:41:30.085Z,1627080090.085 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-23T22:41:30.085Z,1627080090.085 [Default:CheckIn](INFO): Running loop #20
2021-07-23T22:41:30.086Z,1627080090.086 [Default:CheckIn] Running Loop=20
2021-07-23T22:41:30.086Z,1627080090.086 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-23T22:41:30.086Z,1627080090.086 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-23T22:42:33.514Z,1627080153.514 [BPC1](ERROR): BPC1A failed to parse battery stick message.
2021-07-23T22:43:13.566Z,1627080193.566 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T22:43:26.900Z,1627080206.900 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T22:46:30.265Z,1627080390.265 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-23T22:41:30.1Z
2021-07-23T22:46:30.265Z,1627080390.265 [Default:CheckIn:Read_GPS] Stopped
2021-07-23T22:46:30.265Z,1627080390.265 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-23T22:46:38.428Z,1627080398.428 [DataOverHttps](INFO): Sending 98 bytes from file Logs/20210723T192225/Express0062.lzma
2021-07-23T22:46:39.431Z,1627080399.431 [DataOverHttps](INFO): Moved sent file to Logs/20210723T192225/Express0062.lzma.bak
2021-07-23T22:46:39.431Z,1627080399.431 [DataOverHttps](INFO): SBD MOMSN=15758827
2021-07-23T22:46:42.000Z,1627080402.000 [Default:CheckIn:Read_Iridium] Stopped
2021-07-23T22:46:42.001Z,1627080402.001 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-23T22:46:42.001Z,1627080402.001 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-23T22:47:32.546Z,1627080452.546 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T22:51:42.624Z,1627080702.624 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-23T22:51:42.624Z,1627080702.624 [Default:CheckIn:C.Wait] Stopped
2021-07-23T22:51:42.625Z,1627080702.625 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-23T22:51:42.625Z,1627080702.625 [Default:CheckIn:D] Running Loop=1
2021-07-23T22:51:43.016Z,1627080703.016 [Default:CheckIn:D] Stopped
2021-07-23T22:51:43.017Z,1627080703.017 [Default:CheckIn:E] Running Loop=1
2021-07-23T22:51:43.424Z,1627080703.424 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 205.819727 min
2021-07-23T22:51:43.424Z,1627080703.424 [Default:CheckIn:E] Stopped
2021-07-23T22:51:43.425Z,1627080703.425 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-23T22:51:43.425Z,1627080703.425 [Default:CheckIn] Stopped
2021-07-23T22:51:43.425Z,1627080703.425 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-23T22:51:43.425Z,1627080703.425 [Default:CheckIn](INFO): Running loop #21
2021-07-23T22:51:43.425Z,1627080703.425 [Default:CheckIn] Running Loop=21
2021-07-23T22:51:43.425Z,1627080703.425 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-23T22:51:43.425Z,1627080703.425 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-23T22:51:57.250Z,1627080717.250 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T22:55:35.396Z,1627080935.396 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T22:55:40.591Z,1627080940.591 [BPC1](INFO): Calculating totals. Valid battery stick count: 28. Valid reserve battery stick count: 3.
2021-07-23T22:55:40.594Z,1627080940.594 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle.
2021-07-23T22:56:43.672Z,1627081003.672 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-23T22:51:43.4Z
2021-07-23T22:56:43.672Z,1627081003.672 [Default:CheckIn:Read_GPS] Stopped
2021-07-23T22:56:43.672Z,1627081003.672 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-23T22:56:51.052Z,1627081011.052 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20210723T192225/Courier0064.lzma
2021-07-23T22:56:52.055Z,1627081012.055 [DataOverHttps](INFO): Moved sent file to Logs/20210723T192225/Courier0064.lzma.bak
2021-07-23T22:56:52.055Z,1627081012.055 [DataOverHttps](INFO): SBD MOMSN=15758838
2021-07-23T22:57:08.828Z,1627081028.828 [DataOverHttps](INFO): Sending 98 bytes from file Logs/20210723T192225/Express0065.lzma
2021-07-23T22:57:09.831Z,1627081029.831 [DataOverHttps](INFO): Moved sent file to Logs/20210723T192225/Express0065.lzma.bak
2021-07-23T22:57:09.831Z,1627081029.831 [DataOverHttps](INFO): SBD MOMSN=15758840
2021-07-23T22:57:12.367Z,1627081032.367 [Default:CheckIn:Read_Iridium] Stopped
2021-07-23T22:57:12.367Z,1627081032.367 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-23T22:57:12.367Z,1627081032.367 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-23T23:02:13.044Z,1627081333.044 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-23T23:02:13.044Z,1627081333.044 [Default:CheckIn:C.Wait] Stopped
2021-07-23T23:02:13.045Z,1627081333.045 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-23T23:02:13.045Z,1627081333.045 [Default:CheckIn:D] Running Loop=1
2021-07-23T23:02:13.451Z,1627081333.451 [Default:CheckIn:D] Stopped
2021-07-23T23:02:13.451Z,1627081333.451 [Default:CheckIn:E] Running Loop=1
2021-07-23T23:02:13.853Z,1627081333.853 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 216.326969 min
2021-07-23T23:02:13.853Z,1627081333.853 [Default:CheckIn:E] Stopped
2021-07-23T23:02:13.853Z,1627081333.853 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-23T23:02:13.853Z,1627081333.853 [Default:CheckIn] Stopped
2021-07-23T23:02:13.853Z,1627081333.853 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-23T23:02:13.853Z,1627081333.853 [Default:CheckIn](INFO): Running loop #22
2021-07-23T23:02:13.854Z,1627081333.854 [Default:CheckIn] Running Loop=22
2021-07-23T23:02:13.854Z,1627081333.854 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-23T23:02:13.854Z,1627081333.854 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-23T23:07:14.025Z,1627081634.025 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-23T23:02:13.9Z
2021-07-23T23:07:14.025Z,1627081634.025 [Default:CheckIn:Read_GPS] Stopped
2021-07-23T23:07:14.025Z,1627081634.025 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-23T23:07:22.524Z,1627081642.524 [DataOverHttps](INFO): Sending 98 bytes from file Logs/20210723T192225/Express0068.lzma
2021-07-23T23:07:23.527Z,1627081643.527 [DataOverHttps](INFO): Moved sent file to Logs/20210723T192225/Express0068.lzma.bak
2021-07-23T23:07:23.527Z,1627081643.527 [DataOverHttps](INFO): SBD MOMSN=15758852
2021-07-23T23:07:25.775Z,1627081645.775 [Default:CheckIn:Read_Iridium] Stopped
2021-07-23T23:07:25.775Z,1627081645.775 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-23T23:07:25.775Z,1627081645.775 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-23T23:12:26.368Z,1627081946.368 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-23T23:12:26.368Z,1627081946.368 [Default:CheckIn:C.Wait] Stopped
2021-07-23T23:12:26.369Z,1627081946.369 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-23T23:12:26.369Z,1627081946.369 [Default:CheckIn:D] Running Loop=1
2021-07-23T23:12:26.779Z,1627081946.779 [Default:CheckIn:D] Stopped
2021-07-23T23:12:26.780Z,1627081946.780 [Default:CheckIn:E] Running Loop=1
2021-07-23T23:12:27.185Z,1627081947.185 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 226.549121 min
2021-07-23T23:12:27.185Z,1627081947.185 [Default:CheckIn:E] Stopped
2021-07-23T23:12:27.185Z,1627081947.185 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-23T23:12:27.185Z,1627081947.185 [Default:CheckIn] Stopped
2021-07-23T23:12:27.185Z,1627081947.185 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-23T23:12:27.186Z,1627081947.186 [Default:CheckIn](INFO): Running loop #23
2021-07-23T23:12:27.186Z,1627081947.186 [Default:CheckIn] Running Loop=23
2021-07-23T23:12:27.186Z,1627081947.186 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-23T23:12:27.186Z,1627081947.186 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-23T23:17:27.373Z,1627082247.373 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-23T23:12:27.2Z
2021-07-23T23:17:27.373Z,1627082247.373 [Default:CheckIn:Read_GPS] Stopped
2021-07-23T23:17:27.373Z,1627082247.373 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-23T23:17:35.984Z,1627082255.984 [DataOverHttps](INFO): Sending 98 bytes from file Logs/20210723T192225/Express0071.lzma
2021-07-23T23:17:36.987Z,1627082256.987 [DataOverHttps](INFO): Moved sent file to Logs/20210723T192225/Express0071.lzma.bak
2021-07-23T23:17:36.987Z,1627082256.987 [DataOverHttps](INFO): SBD MOMSN=15758861
2021-07-23T23:17:39.523Z,1627082259.523 [Default:CheckIn:Read_Iridium] Stopped
2021-07-23T23:17:39.523Z,1627082259.523 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-23T23:17:39.523Z,1627082259.523 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-23T23:22:40.109Z,1627082560.109 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-23T23:22:40.109Z,1627082560.109 [Default:CheckIn:C.Wait] Stopped
2021-07-23T23:22:40.110Z,1627082560.110 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-23T23:22:40.110Z,1627082560.110 [Default:CheckIn:D] Running Loop=1
2021-07-23T23:22:40.525Z,1627082560.525 [Default:CheckIn:D] Stopped
2021-07-23T23:22:40.526Z,1627082560.526 [Default:CheckIn:E] Running Loop=1
2021-07-23T23:22:40.909Z,1627082560.909 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 236.778223 min
2021-07-23T23:22:40.909Z,1627082560.909 [Default:CheckIn:E] Stopped
2021-07-23T23:22:40.909Z,1627082560.909 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-23T23:22:40.909Z,1627082560.909 [Default:CheckIn] Stopped
2021-07-23T23:22:40.909Z,1627082560.909 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-23T23:22:40.909Z,1627082560.909 [Default:CheckIn](INFO): Running loop #24
2021-07-23T23:22:40.910Z,1627082560.910 [Default:CheckIn] Running Loop=24
2021-07-23T23:22:40.910Z,1627082560.910 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-23T23:22:40.910Z,1627082560.910 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-23T23:27:41.097Z,1627082861.097 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-23T23:22:40.9Z
2021-07-23T23:27:41.097Z,1627082861.097 [Default:CheckIn:Read_GPS] Stopped
2021-07-23T23:27:41.097Z,1627082861.097 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-23T23:27:50.024Z,1627082870.024 [DataOverHttps](INFO): Sending 97 bytes from file Logs/20210723T192225/Express0074.lzma
2021-07-23T23:27:51.027Z,1627082871.027 [DataOverHttps](INFO): Moved sent file to Logs/20210723T192225/Express0074.lzma.bak
2021-07-23T23:27:51.027Z,1627082871.027 [DataOverHttps](INFO): SBD MOMSN=15758872
2021-07-23T23:27:53.208Z,1627082873.208 [Default:CheckIn:Read_Iridium] Stopped
2021-07-23T23:27:53.208Z,1627082873.208 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-23T23:27:53.208Z,1627082873.208 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-23T23:32:53.852Z,1627083173.852 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-23T23:32:53.852Z,1627083173.852 [Default:CheckIn:C.Wait] Stopped
2021-07-23T23:32:53.853Z,1627083173.853 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-23T23:32:53.853Z,1627083173.853 [Default:CheckIn:D] Running Loop=1
2021-07-23T23:32:54.284Z,1627083174.284 [Default:CheckIn:D] Stopped
2021-07-23T23:32:54.284Z,1627083174.284 [Default:CheckIn:E] Running Loop=1
2021-07-23T23:32:54.661Z,1627083174.661 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 247.007520 min
2021-07-23T23:32:54.661Z,1627083174.661 [Default:CheckIn:E] Stopped
2021-07-23T23:32:54.661Z,1627083174.661 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-23T23:32:54.661Z,1627083174.661 [Default:CheckIn] Stopped
2021-07-23T23:32:54.662Z,1627083174.662 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-23T23:32:54.662Z,1627083174.662 [Default:CheckIn](INFO): Running loop #25
2021-07-23T23:32:54.662Z,1627083174.662 [Default:CheckIn] Running Loop=25
2021-07-23T23:32:54.662Z,1627083174.662 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-23T23:32:54.662Z,1627083174.662 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-23T23:37:54.873Z,1627083474.873 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-23T23:32:54.7Z
2021-07-23T23:37:54.873Z,1627083474.873 [Default:CheckIn:Read_GPS] Stopped
2021-07-23T23:37:54.873Z,1627083474.873 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-23T23:38:03.532Z,1627083483.532 [DataOverHttps](INFO): Sending 98 bytes from file Logs/20210723T192225/Express0077.lzma
2021-07-23T23:38:04.535Z,1627083484.535 [DataOverHttps](INFO): Moved sent file to Logs/20210723T192225/Express0077.lzma.bak
2021-07-23T23:38:04.535Z,1627083484.535 [DataOverHttps](INFO): SBD MOMSN=15758881
2021-07-23T23:38:07.008Z,1627083487.008 [Default:CheckIn:Read_Iridium] Stopped
2021-07-23T23:38:07.008Z,1627083487.008 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-23T23:38:07.008Z,1627083487.008 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-23T23:43:07.638Z,1627083787.638 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-23T23:43:07.638Z,1627083787.638 [Default:CheckIn:C.Wait] Stopped
2021-07-23T23:43:07.638Z,1627083787.638 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-23T23:43:07.638Z,1627083787.638 [Default:CheckIn:D] Running Loop=1
2021-07-23T23:43:08.033Z,1627083788.033 [Default:CheckIn:D] Stopped
2021-07-23T23:43:08.033Z,1627083788.033 [Default:CheckIn:E] Running Loop=1
2021-07-23T23:43:08.437Z,1627083788.437 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 257.236670 min
2021-07-23T23:43:08.437Z,1627083788.437 [Default:CheckIn:E] Stopped
2021-07-23T23:43:08.437Z,1627083788.437 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-23T23:43:08.437Z,1627083788.437 [Default:CheckIn] Stopped
2021-07-23T23:43:08.437Z,1627083788.437 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-23T23:43:08.437Z,1627083788.437 [Default:CheckIn](INFO): Running loop #26
2021-07-23T23:43:08.438Z,1627083788.438 [Default:CheckIn] Running Loop=26
2021-07-23T23:43:08.438Z,1627083788.438 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-23T23:43:08.438Z,1627083788.438 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-23T23:48:08.609Z,1627084088.609 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-23T23:43:08.4Z
2021-07-23T23:48:08.609Z,1627084088.609 [Default:CheckIn:Read_GPS] Stopped
2021-07-23T23:48:08.609Z,1627084088.609 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-23T23:48:17.360Z,1627084097.360 [DataOverHttps](INFO): Sending 98 bytes from file Logs/20210723T192225/Express0080.lzma
2021-07-23T23:48:18.363Z,1627084098.363 [DataOverHttps](INFO): Moved sent file to Logs/20210723T192225/Express0080.lzma.bak
2021-07-23T23:48:18.363Z,1627084098.363 [DataOverHttps](INFO): SBD MOMSN=15758891
2021-07-23T23:48:20.748Z,1627084100.748 [Default:CheckIn:Read_Iridium] Stopped
2021-07-23T23:48:20.748Z,1627084100.748 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-23T23:48:20.748Z,1627084100.748 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-23T23:53:21.344Z,1627084401.344 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-23T23:53:21.344Z,1627084401.344 [Default:CheckIn:C.Wait] Stopped
2021-07-23T23:53:21.344Z,1627084401.344 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-23T23:53:21.344Z,1627084401.344 [Default:CheckIn:D] Running Loop=1
2021-07-23T23:53:21.773Z,1627084401.773 [Default:CheckIn:D] Stopped
2021-07-23T23:53:21.773Z,1627084401.773 [Default:CheckIn:E] Running Loop=1
2021-07-23T23:53:22.144Z,1627084402.144 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 267.465674 min
2021-07-23T23:53:22.144Z,1627084402.144 [Default:CheckIn:E] Stopped
2021-07-23T23:53:22.144Z,1627084402.144 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-23T23:53:22.144Z,1627084402.144 [Default:CheckIn] Stopped
2021-07-23T23:53:22.144Z,1627084402.144 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-23T23:53:22.144Z,1627084402.144 [Default:CheckIn](INFO): Running loop #27
2021-07-23T23:53:22.144Z,1627084402.144 [Default:CheckIn] Running Loop=27
2021-07-23T23:53:22.144Z,1627084402.144 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-23T23:53:22.145Z,1627084402.145 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-23T23:58:22.361Z,1627084702.361 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-23T23:53:22.1Z
2021-07-23T23:58:22.361Z,1627084702.361 [Default:CheckIn:Read_GPS] Stopped
2021-07-23T23:58:22.361Z,1627084702.361 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-23T23:58:25.673Z,1627084705.673 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-23T23:58:30.520Z,1627084710.520 [DataOverHttps](INFO): Sending 98 bytes from file Logs/20210723T192225/Express0083.lzma
2021-07-23T23:58:31.523Z,1627084711.523 [DataOverHttps](INFO): Moved sent file to Logs/20210723T192225/Express0083.lzma.bak
2021-07-23T23:58:31.523Z,1627084711.523 [DataOverHttps](INFO): SBD MOMSN=15758902
2021-07-23T23:58:34.100Z,1627084714.100 [Default:CheckIn:Read_Iridium] Stopped
2021-07-23T23:58:34.100Z,1627084714.100 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-23T23:58:34.112Z,1627084714.112 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-23T23:59:40.382Z,1627084780.382 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-24T00:01:02.032Z,1627084862.032 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-24T00:01:41.636Z,1627084901.636 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-24T00:03:34.652Z,1627085014.652 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-24T00:03:34.652Z,1627085014.652 [Default:CheckIn:C.Wait] Stopped
2021-07-24T00:03:34.652Z,1627085014.652 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-24T00:03:34.653Z,1627085014.653 [Default:CheckIn:D] Running Loop=1
2021-07-24T00:03:35.067Z,1627085015.067 [Default:CheckIn:D] Stopped
2021-07-24T00:03:35.067Z,1627085015.067 [Default:CheckIn:E] Running Loop=1
2021-07-24T00:03:35.461Z,1627085015.461 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 277.687240 min
2021-07-24T00:03:35.461Z,1627085015.461 [Default:CheckIn:E] Stopped
2021-07-24T00:03:35.461Z,1627085015.461 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-24T00:03:35.461Z,1627085015.461 [Default:CheckIn] Stopped
2021-07-24T00:03:35.461Z,1627085015.461 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-24T00:03:35.461Z,1627085015.461 [Default:CheckIn](INFO): Running loop #28
2021-07-24T00:03:35.462Z,1627085015.462 [Default:CheckIn] Running Loop=28
2021-07-24T00:03:35.462Z,1627085015.462 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-24T00:03:35.462Z,1627085015.462 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-24T00:04:24.797Z,1627085064.797 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-24T00:04:37.725Z,1627085077.725 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-24T00:07:11.638Z,1627085231.638 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-24T00:07:23.354Z,1627085243.354 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-24T00:08:00.142Z,1627085280.142 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-24T00:08:35.633Z,1627085315.633 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-24T00:03:35.5Z
2021-07-24T00:08:35.633Z,1627085315.633 [Default:CheckIn:Read_GPS] Stopped
2021-07-24T00:08:35.633Z,1627085315.633 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-24T00:08:43.792Z,1627085323.792 [DataOverHttps](INFO): Sending 98 bytes from file Logs/20210723T192225/Express0086.lzma
2021-07-24T00:08:44.795Z,1627085324.795 [DataOverHttps](INFO): Moved sent file to Logs/20210723T192225/Express0086.lzma.bak
2021-07-24T00:08:44.795Z,1627085324.795 [DataOverHttps](INFO): SBD MOMSN=15758914
2021-07-24T00:08:47.348Z,1627085327.348 [Default:CheckIn:Read_Iridium] Stopped
2021-07-24T00:08:47.348Z,1627085327.348 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-24T00:08:47.348Z,1627085327.348 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-24T00:08:53.900Z,1627085333.900 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-24T00:10:54.704Z,1627085454.704 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-24T00:11:07.217Z,1627085467.217 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-24T00:13:09.626Z,1627085589.626 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-24T00:13:47.956Z,1627085627.956 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-24T00:13:47.956Z,1627085627.956 [Default:CheckIn:C.Wait] Stopped
2021-07-24T00:13:47.957Z,1627085627.957 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-24T00:13:47.957Z,1627085627.957 [Default:CheckIn:D] Running Loop=1
2021-07-24T00:13:48.363Z,1627085628.363 [Default:CheckIn:D] Stopped
2021-07-24T00:13:48.363Z,1627085628.363 [Default:CheckIn:E] Running Loop=1
2021-07-24T00:13:48.782Z,1627085628.782 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 287.908854 min
2021-07-24T00:13:48.782Z,1627085628.782 [Default:CheckIn:E] Stopped
2021-07-24T00:13:48.782Z,1627085628.782 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-24T00:13:48.782Z,1627085628.782 [Default:CheckIn] Stopped
2021-07-24T00:13:48.782Z,1627085628.782 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-24T00:13:48.782Z,1627085628.782 [Default:CheckIn](INFO): Running loop #29
2021-07-24T00:13:48.782Z,1627085628.782 [Default:CheckIn] Running Loop=29
2021-07-24T00:13:48.783Z,1627085628.783 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-24T00:13:48.783Z,1627085628.783 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-24T00:16:51.410Z,1627085811.410 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-24T00:17:40.331Z,1627085860.331 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-24T00:18:49.009Z,1627085929.009 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-24T00:13:48.8Z
2021-07-24T00:18:49.010Z,1627085929.010 [Default:CheckIn:Read_GPS] Stopped
2021-07-24T00:18:49.010Z,1627085929.010 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-24T00:18:57.068Z,1627085937.068 [DataOverHttps](INFO): Sending 98 bytes from file Logs/20210723T192225/Express0089.lzma
2021-07-24T00:18:58.071Z,1627085938.071 [DataOverHttps](INFO): Moved sent file to Logs/20210723T192225/Express0089.lzma.bak
2021-07-24T00:18:58.071Z,1627085938.071 [DataOverHttps](INFO): SBD MOMSN=15758923
2021-07-24T00:19:00.248Z,1627085940.248 [Default:CheckIn:Read_Iridium] Stopped
2021-07-24T00:19:00.248Z,1627085940.248 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-24T00:19:00.248Z,1627085940.248 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-24T00:19:01.540Z,1627085941.540 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-24T00:24:00.862Z,1627086240.862 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-24T00:24:00.862Z,1627086240.862 [Default:CheckIn:C.Wait] Stopped
2021-07-24T00:24:00.862Z,1627086240.862 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-24T00:24:00.862Z,1627086240.862 [Default:CheckIn:D] Running Loop=1
2021-07-24T00:24:01.267Z,1627086241.267 [Default:CheckIn:D] Stopped
2021-07-24T00:24:01.267Z,1627086241.267 [Default:CheckIn:E] Running Loop=1
2021-07-24T00:24:01.697Z,1627086241.697 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 298.123893 min
2021-07-24T00:24:01.697Z,1627086241.697 [Default:CheckIn:E] Stopped
2021-07-24T00:24:01.698Z,1627086241.698 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-24T00:24:01.698Z,1627086241.698 [Default:CheckIn] Stopped
2021-07-24T00:24:01.698Z,1627086241.698 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-24T00:24:01.698Z,1627086241.698 [Default:CheckIn](INFO): Running loop #30
2021-07-24T00:24:01.698Z,1627086241.698 [Default:CheckIn] Running Loop=30
2021-07-24T00:24:01.698Z,1627086241.698 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-24T00:24:01.698Z,1627086241.698 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-24T00:24:13.466Z,1627086253.466 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-24T00:26:34.030Z,1627086394.030 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-07-24T00:26:41.656Z,1627086401.656 [BPC1](INFO): Calculating totals. Valid battery stick count: 28. Valid reserve battery stick count: 3.
2021-07-24T00:26:41.659Z,1627086401.659 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle.
2021-07-24T00:29:01.853Z,1627086541.853 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-24T00:24:01.7Z
2021-07-24T00:29:01.853Z,1627086541.853 [Default:CheckIn:Read_GPS] Stopped
2021-07-24T00:29:01.853Z,1627086541.853 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-24T00:29:07.826Z,1627086547.826 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20210723T192225/Courier0091.lzma
2021-07-24T00:29:08.819Z,1627086548.819 [DataOverHttps](INFO): Moved sent file to Logs/20210723T192225/Courier0091.lzma.bak
2021-07-24T00:29:08.819Z,1627086548.819 [DataOverHttps](INFO): SBD MOMSN=15758933
2021-07-24T00:29:25.600Z,1627086565.600 [DataOverHttps](INFO): Sending 98 bytes from file Logs/20210723T192225/Express0092.lzma
2021-07-24T00:29:26.603Z,1627086566.603 [DataOverHttps](INFO): Moved sent file to Logs/20210723T192225/Express0092.lzma.bak
2021-07-24T00:29:26.603Z,1627086566.603 [DataOverHttps](INFO): SBD MOMSN=15758935
2021-07-24T00:29:28.920Z,1627086568.920 [Default:CheckIn:Read_Iridium] Stopped
2021-07-24T00:29:28.920Z,1627086568.920 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-24T00:29:28.920Z,1627086568.920 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-24T00:30:40.906Z,1627086640.906 [CommandLine](IMPORTANT): got command quit
2021-07-24T00:30:41.913Z,1627086641.913 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2021-07-24T00:30:41.913Z,1627086641.913 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-07-24T00:30:41.945Z,1627086641.945 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2021-07-24T00:30:41.945Z,1627086641.945 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-07-24T00:30:41.946Z,1627086641.946 [CommandLine](INFO): Join timeout helper Thread ID is 9713
2021-07-24T00:30:41.946Z,1627086641.946 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2021-07-24T00:30:41.946Z,1627086641.946 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-07-24T00:30:41.946Z,1627086641.946 [NavChartDb](INFO): Join timeout helper Thread ID is 9714
2021-07-24T00:30:42.293Z,1627086642.293 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2021-07-24T00:30:42.293Z,1627086642.293 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-07-24T00:30:42.305Z,1627086642.305 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2021-07-24T00:30:42.305Z,1627086642.305 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-07-24T00:30:42.305Z,1627086642.305 [Radio_Surface](INFO): Join timeout helper Thread ID is 9717
2021-07-24T00:30:42.369Z,1627086642.369 [Radio_Surface](INFO): Powering down
2021-07-24T00:30:42.370Z,1627086642.370 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2021-07-24T00:30:42.370Z,1627086642.370 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-07-24T00:30:42.385Z,1627086642.385 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2021-07-24T00:30:42.385Z,1627086642.385 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-07-24T00:30:42.385Z,1627086642.385 [Onboard](INFO): Join timeout helper Thread ID is 9718
2021-07-24T00:30:43.073Z,1627086643.073 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2021-07-24T00:30:43.653Z,1627086643.653 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2021-07-24T00:30:43.653Z,1627086643.653 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-07-24T00:30:43.657Z,1627086643.657 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2021-07-24T00:30:43.657Z,1627086643.657 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-07-24T00:30:43.657Z,1627086643.657 [DataOverHttps](INFO): Join timeout helper Thread ID is 9727
2021-07-24T00:30:44.077Z,1627086644.077 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2021-07-24T00:30:44.078Z,1627086644.078 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-07-24T00:30:44.098Z,1627086644.098 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2021-07-24T00:30:44.098Z,1627086644.098 [logger ThreadHandler](INFO): Thread cancelled.
2021-07-24T00:30:44.098Z,1627086644.098 [logger](INFO): Join timeout helper Thread ID is 9730
2021-07-24T00:30:44.129Z,1627086644.129 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2021-07-24T00:30:44.129Z,1627086644.129 [logger ThreadHandler](INFO): Thread cancelled.
2021-07-24T00:30:44.149Z,1627086644.149 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2021-07-24T00:30:44.150Z,1627086644.150 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-07-24T00:30:44.150Z,1627086644.150 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2021-07-24T00:30:44.150Z,1627086644.150 [controlThread ThreadHandler](INFO): Thread cancelled.
2021-07-24T00:30:44.150Z,1627086644.150 [controlThread](INFO): Join timeout helper Thread ID is 9731
2021-07-24T00:30:44.489Z,1627086644.489 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2021-07-24T00:30:44.489Z,1627086644.489 [controlThread](DEBUG): Uninitializing ControlThread
2021-07-24T00:30:44.491Z,1627086644.491 [NAL9602](INFO): Powering down
2021-07-24T00:30:44.493Z,1627086644.493 [DAT](INFO): Powering down
2021-07-24T00:30:44.494Z,1627086644.494 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2021-07-24T00:30:44.494Z,1627086644.494 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2021-07-24T00:30:44.495Z,1627086644.495 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2021-07-24T00:30:44.495Z,1627086644.495 [MissionManager](INFO): Uninitializing Mission Default
2021-07-24T00:30:44.495Z,1627086644.495 [Default] Stopped
2021-07-24T00:30:44.496Z,1627086644.496 [Default](DEBUG): Aggregate::uninitialize Default
2021-07-24T00:30:44.496Z,1627086644.496 [Default:B.GoToSurface] Stopped
2021-07-24T00:30:44.496Z,1627086644.496 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-07-24T00:30:44.496Z,1627086644.496 [Default:CheckIn] Stopped
2021-07-24T00:30:44.496Z,1627086644.496 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-24T00:30:44.496Z,1627086644.496 [Default:CheckIn:C.Wait] Stopped
2021-07-24T00:30:44.496Z,1627086644.496 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-24T00:30:44.499Z,1627086644.499 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2021-07-24T00:30:44.500Z,1627086644.500 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2021-07-24T00:30:44.500Z,1627086644.500 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2021-07-24T00:30:44.500Z,1627086644.500 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2021-07-24T00:30:44.500Z,1627086644.500 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2021-07-24T00:30:44.501Z,1627086644.501 [BuoyancyServo](INFO): Powering down
2021-07-24T00:30:44.513Z,1627086644.513 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2021-07-24T00:30:44.513Z,1627086644.513 [ElevatorServo](INFO): Powering down
2021-07-24T00:30:44.514Z,1627086644.514 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2021-07-24T00:30:44.514Z,1627086644.514 [RudderServo](INFO): Powering down
2021-07-24T00:30:44.515Z,1627086644.515 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2021-07-24T00:30:44.515Z,1627086644.515 [ThrusterServo](INFO): Powering down
2021-07-24T00:30:44.516Z,1627086644.516 [SBIT](DEBUG): Uninitialize SBIT Component.
2021-07-24T00:30:44.516Z,1627086644.516 [IBIT](DEBUG): Uninitialize IBIT Component.
2021-07-24T00:30:44.517Z,1627086644.517 [CBIT](DEBUG): Uninitialize CBIT Component.
2021-07-24T00:30:44.517Z,1627086644.517 [CBIT](DEBUG): Powering off loads.
2021-07-24T00:30:44.529Z,1627086644.529 [CBIT](DEBUG): Disabling WDT.
2021-07-24T00:30:44.541Z,1627086644.541 [CBIT](DEBUG): Opening all GF detection circuits.
2021-07-24T00:30:44.542Z,1627086644.542 [controlThread ThreadHandler](INFO): Thread cancelled.
2021-07-24T00:30:44.666Z,1627086644.666 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-07-24T00:30:44.669Z,1627086644.669 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-07-24T00:30:44.675Z,1627086644.675 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-07-24T00:30:44.754Z,1627086644.754 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-07-24T00:30:44.815Z,1627086644.815 [logger ThreadHandler](INFO): Thread cancelled.