2023-04-14T16:42:23.840Z,1681490543.840 [Supervisor](DEBUG): Initializing supervisor.
2023-04-14T16:42:23.845Z,1681490543.845 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2023-04-14T16:42:23.845Z,1681490543.845 [SyncHandler](INFO): Protected caller Thread ID is 835
2023-04-14T16:42:23.846Z,1681490543.846 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2023-04-14T16:42:23.847Z,1681490543.847 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2023-04-14T16:42:23.847Z,1681490543.847 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 836
2023-04-14T16:42:23.851Z,1681490543.851 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2023-04-14T16:42:23.869Z,1681490543.869 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2023-04-14T16:42:23.870Z,1681490543.870 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2023-04-14T16:42:23.870Z,1681490543.870 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 837
2023-04-14T16:42:23.875Z,1681490543.875 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2023-04-14T16:42:23.876Z,1681490543.876 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2023-04-14T16:42:23.876Z,1681490543.876 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 838
2023-04-14T16:42:23.878Z,1681490543.878 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2023-04-14T16:42:23.879Z,1681490543.879 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2023-04-14T16:42:23.879Z,1681490543.879 [logger ThreadHandler](INFO): Protected caller Thread ID is 839
2023-04-14T16:42:23.883Z,1681490543.883 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2023-04-14T16:42:23.883Z,1681490543.883 [Supervisor](INFO): Looking for Config files in directory: Config/
2023-04-14T16:42:23.888Z,1681490543.888 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2023-04-14T16:42:24.105Z,1681490544.105 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2023-04-14T16:42:24.105Z,1681490544.105 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2023-04-14T16:42:24.212Z,1681490544.212 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2023-04-14T16:42:24.214Z,1681490544.214 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2023-04-14T16:42:24.310Z,1681490544.310 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2023-04-14T16:42:24.311Z,1681490544.311 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2023-04-14T16:42:24.786Z,1681490544.786 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2023-04-14T16:42:24.788Z,1681490544.788 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2023-04-14T16:42:25.136Z,1681490545.136 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2023-04-14T16:42:25.138Z,1681490545.138 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2023-04-14T16:42:25.478Z,1681490545.478 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2023-04-14T16:42:25.480Z,1681490545.480 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2023-04-14T16:42:25.669Z,1681490545.669 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2023-04-14T16:42:25.670Z,1681490545.670 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2023-04-14T16:42:25.750Z,1681490545.750 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2023-04-14T16:42:25.831Z,1681490545.831 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2023-04-14T16:42:26.230Z,1681490546.230 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2023-04-14T16:42:26.232Z,1681490546.232 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2023-04-14T16:42:26.520Z,1681490546.520 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2023-04-14T16:42:26.521Z,1681490546.521 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2023-04-14T16:42:27.030Z,1681490547.030 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2023-04-14T16:42:27.031Z,1681490547.031 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2023-04-14T16:42:27.249Z,1681490547.249 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2023-04-14T16:42:27.250Z,1681490547.250 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2023-04-14T16:42:28.219Z,1681490548.219 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2023-04-14T16:42:28.220Z,1681490548.220 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2023-04-14T16:42:28.359Z,1681490548.359 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2023-04-14T16:42:28.360Z,1681490548.360 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2023-04-14T16:42:29.142Z,1681490549.142 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2023-04-14T16:42:29.144Z,1681490549.144 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-galene/
2023-04-14T16:42:29.147Z,1681490549.147 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/secure.cfg
2023-04-14T16:42:29.231Z,1681490549.231 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/vehicle.cfg
2023-04-14T16:42:29.415Z,1681490549.415 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Battery.cfg
2023-04-14T16:42:29.681Z,1681490549.681 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2023-04-14T16:42:29.681Z,1681490549.681 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Science.cfg
2023-04-14T16:42:29.804Z,1681490549.804 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Control.cfg
2023-04-14T16:42:29.905Z,1681490549.905 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/logger.cfg
2023-04-14T16:42:29.998Z,1681490549.998 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Servo.cfg
2023-04-14T16:42:30.105Z,1681490550.105 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Navigation.cfg
2023-04-14T16:42:30.199Z,1681490550.199 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Simulator.cfg
2023-04-14T16:42:30.285Z,1681490550.285 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/BIT.cfg
2023-04-14T16:42:30.387Z,1681490550.387 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Sensor.cfg
2023-04-14T16:42:30.546Z,1681490550.546 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2023-04-14T16:42:30.566Z,1681490550.566 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2023-04-14T16:42:30.651Z,1681490550.651 [DepthRateCalculator] Loaded
2023-04-14T16:42:30.651Z,1681490550.651 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2023-04-14T16:42:30.657Z,1681490550.657 [PitchRateCalculator] Loaded
2023-04-14T16:42:30.657Z,1681490550.657 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2023-04-14T16:42:30.667Z,1681490550.667 [SpeedCalculator] Loaded
2023-04-14T16:42:30.667Z,1681490550.667 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2023-04-14T16:42:30.683Z,1681490550.683 [VerticalHomogeneityIndexCalculator] Loaded
2023-04-14T16:42:30.683Z,1681490550.683 [ComponentRegistry](DEBUG): SyncComponent "VerticalHomogeneityIndexCalculator" handled in the control thread.
2023-04-14T16:42:30.688Z,1681490550.688 [YawRateCalculator] Loaded
2023-04-14T16:42:30.688Z,1681490550.688 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2023-04-14T16:42:30.710Z,1681490550.710 [ElevatorOffsetCalculator] Loaded
2023-04-14T16:42:30.711Z,1681490550.711 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2023-04-14T16:42:30.711Z,1681490550.711 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2023-04-14T16:42:30.713Z,1681490550.713 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2023-04-14T16:42:30.756Z,1681490550.756 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2023-04-14T16:42:30.756Z,1681490550.756 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2023-04-14T16:42:30.772Z,1681490550.772 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2023-04-14T16:42:30.772Z,1681490550.772 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2023-04-14T16:42:31.528Z,1681490551.528 [AHRS_M2] Loaded
2023-04-14T16:42:31.529Z,1681490551.529 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2023-04-14T16:42:31.777Z,1681490551.777 [BackseatComponent] Loaded
2023-04-14T16:42:31.778Z,1681490551.778 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2023-04-14T16:42:31.779Z,1681490551.779 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408474E0
2023-04-14T16:42:31.779Z,1681490551.779 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 921
2023-04-14T16:42:31.782Z,1681490551.782 [LcmUniversalReporter] Loaded
2023-04-14T16:42:31.782Z,1681490551.782 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2023-04-14T16:42:32.852Z,1681490552.852 [BPC1] Loaded
2023-04-14T16:42:32.852Z,1681490552.852 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2023-04-14T16:42:33.000Z,1681490553.000 [DataOverHttps] Loaded
2023-04-14T16:42:33.000Z,1681490553.000 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2023-04-14T16:42:33.001Z,1681490553.001 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408774E0
2023-04-14T16:42:33.002Z,1681490553.002 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 922
2023-04-14T16:42:33.022Z,1681490553.022 [Depth_Keller] Loaded
2023-04-14T16:42:33.023Z,1681490553.023 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2023-04-14T16:42:33.028Z,1681490553.028 [DropWeight] Loaded
2023-04-14T16:42:33.028Z,1681490553.028 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2023-04-14T16:42:33.091Z,1681490553.091 [NAL9602] Loaded
2023-04-14T16:42:33.091Z,1681490553.091 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2023-04-14T16:42:33.120Z,1681490553.120 [Onboard] Loaded
2023-04-14T16:42:33.121Z,1681490553.121 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2023-04-14T16:42:33.122Z,1681490553.122 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408A74E0
2023-04-14T16:42:33.122Z,1681490553.122 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 923
2023-04-14T16:42:33.128Z,1681490553.128 [PowerOnly](INFO): Adding load control power supply at /dev/loadC3
2023-04-14T16:42:33.139Z,1681490553.139 [PowerOnly] Loaded
2023-04-14T16:42:33.139Z,1681490553.139 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2023-04-14T16:42:33.151Z,1681490553.151 [Power24vConverter] Loaded
2023-04-14T16:42:33.151Z,1681490553.151 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2023-04-14T16:42:33.166Z,1681490553.166 [Radio_Surface] Loaded
2023-04-14T16:42:33.166Z,1681490553.166 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2023-04-14T16:42:33.167Z,1681490553.167 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408D74E0
2023-04-14T16:42:33.168Z,1681490553.168 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 924
2023-04-14T16:42:33.169Z,1681490553.169 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2023-04-14T16:42:33.169Z,1681490553.169 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2023-04-14T16:42:33.306Z,1681490553.306 [DeadReckonUsingMultipleVelocitySources] Loaded
2023-04-14T16:42:33.306Z,1681490553.306 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2023-04-14T16:42:33.349Z,1681490553.349 [DeadReckonUsingSpeedCalculator] Loaded
2023-04-14T16:42:33.349Z,1681490553.349 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2023-04-14T16:42:33.363Z,1681490553.363 [NavChart] Loaded
2023-04-14T16:42:33.363Z,1681490553.363 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2023-04-14T16:42:33.369Z,1681490553.369 [UniversalFixResidualReporter] Loaded
2023-04-14T16:42:33.369Z,1681490553.369 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2023-04-14T16:42:33.370Z,1681490553.370 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2023-04-14T16:42:33.372Z,1681490553.372 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2023-04-14T16:42:33.539Z,1681490553.539 [SBIT](DEBUG): Construct Startup Built In Test.
2023-04-14T16:42:33.554Z,1681490553.554 [SBIT] Loaded
2023-04-14T16:42:33.554Z,1681490553.554 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2023-04-14T16:42:33.557Z,1681490553.557 [IBIT](DEBUG): Construct Initiated Built In Test.
2023-04-14T16:42:33.570Z,1681490553.570 [IBIT] Loaded
2023-04-14T16:42:33.570Z,1681490553.570 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2023-04-14T16:42:33.576Z,1681490553.576 [CBIT](DEBUG): Construct Continuous Built In Test.
2023-04-14T16:42:33.682Z,1681490553.682 [CBIT] Loaded
2023-04-14T16:42:33.682Z,1681490553.682 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2023-04-14T16:42:33.682Z,1681490553.682 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2023-04-14T16:42:33.683Z,1681490553.683 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2023-04-14T16:42:33.899Z,1681490553.899 [CTD_Seabird] Loaded
2023-04-14T16:42:33.899Z,1681490553.899 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2023-04-14T16:42:33.900Z,1681490553.900 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409DB4E0
2023-04-14T16:42:33.901Z,1681490553.901 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 925
2023-04-14T16:42:33.921Z,1681490553.921 [PAR_Licor] Loaded
2023-04-14T16:42:33.921Z,1681490553.921 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2023-04-14T16:42:33.953Z,1681490553.953 [WetLabsBB2FL] Loaded
2023-04-14T16:42:33.953Z,1681490553.953 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2023-04-14T16:42:33.954Z,1681490553.954 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A0B4E0
2023-04-14T16:42:33.955Z,1681490553.955 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 926
2023-04-14T16:42:33.956Z,1681490553.956 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2023-04-14T16:42:33.956Z,1681490553.956 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2023-04-14T16:42:34.118Z,1681490554.118 [BuoyancyServo] Loaded
2023-04-14T16:42:34.119Z,1681490554.119 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2023-04-14T16:42:34.141Z,1681490554.141 [ElevatorServo] Loaded
2023-04-14T16:42:34.141Z,1681490554.141 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2023-04-14T16:42:34.162Z,1681490554.162 [MassServo] Loaded
2023-04-14T16:42:34.162Z,1681490554.162 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2023-04-14T16:42:34.184Z,1681490554.184 [RudderServo] Loaded
2023-04-14T16:42:34.184Z,1681490554.184 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2023-04-14T16:42:34.200Z,1681490554.200 [ThrusterHE] Loaded
2023-04-14T16:42:34.200Z,1681490554.200 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2023-04-14T16:42:34.200Z,1681490554.200 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2023-04-14T16:42:34.201Z,1681490554.201 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2023-04-14T16:42:34.268Z,1681490554.268 [VerticalControl](DEBUG): Construct VerticalControl.
2023-04-14T16:42:34.321Z,1681490554.321 [VerticalControl] Loaded
2023-04-14T16:42:34.321Z,1681490554.321 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2023-04-14T16:42:34.324Z,1681490554.324 [HorizontalControl](DEBUG): Construct HorizontalControl.
2023-04-14T16:42:34.362Z,1681490554.362 [HorizontalControl] Loaded
2023-04-14T16:42:34.363Z,1681490554.363 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2023-04-14T16:42:34.365Z,1681490554.365 [SpeedControl](DEBUG): Construct SpeedControl.
2023-04-14T16:42:34.367Z,1681490554.367 [SpeedControl] Loaded
2023-04-14T16:42:34.367Z,1681490554.367 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2023-04-14T16:42:34.370Z,1681490554.370 [LoopControl](DEBUG): Construct LoopControl.
2023-04-14T16:42:34.371Z,1681490554.371 [LoopControl] Loaded
2023-04-14T16:42:34.371Z,1681490554.371 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2023-04-14T16:42:34.371Z,1681490554.371 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2023-04-14T16:42:34.372Z,1681490554.372 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2023-04-14T16:42:34.496Z,1681490554.496 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2023-04-14T16:42:34.497Z,1681490554.497 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2023-04-14T16:42:34.683Z,1681490554.683 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2023-04-14T16:42:34.684Z,1681490554.684 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2023-04-14T16:42:35.040Z,1681490555.040 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2023-04-14T16:42:35.040Z,1681490555.040 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2023-04-14T16:42:35.139Z,1681490555.139 [StratificationFrontDetector](INFO): thresholdVTHI set to: 0.399988 degC
2023-04-14T16:42:35.139Z,1681490555.139 [StratificationFrontDetector](DEBUG): (re)initializing
2023-04-14T16:42:35.139Z,1681490555.139 [StratificationFrontDetector] Loaded
2023-04-14T16:42:35.139Z,1681490555.139 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2023-04-14T16:42:35.140Z,1681490555.140 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2023-04-14T16:42:35.146Z,1681490555.146 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2023-04-14T16:42:35.149Z,1681490555.149 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2023-04-14T16:42:35.160Z,1681490555.160 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2023-04-14T16:42:35.161Z,1681490555.161 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BAE4E0
2023-04-14T16:42:35.162Z,1681490555.162 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 927
2023-04-14T16:42:35.166Z,1681490555.166 [Supervisor](INFO): Main Thread ID is 830
2023-04-14T16:42:35.166Z,1681490555.166 [Supervisor](DEBUG): Running supervisor.
2023-04-14T16:42:35.167Z,1681490555.167 [CommandExec ThreadHandler](INFO): Handler Thread ID is 928
2023-04-14T16:42:35.167Z,1681490555.167 [CommandExec](INFO): Initializing the command executive.
2023-04-14T16:42:35.169Z,1681490555.169 [CommandLine ThreadHandler](INFO): Handler Thread ID is 929
2023-04-14T16:42:35.171Z,1681490555.171 [controlThread ThreadHandler](INFO): Handler Thread ID is 930
2023-04-14T16:42:35.171Z,1681490555.171 [controlThread](DEBUG): Initializing ControlThread
2023-04-14T16:42:35.172Z,1681490555.172 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2023-04-14T16:42:35.173Z,1681490555.173 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2023-04-14T16:42:35.173Z,1681490555.173 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2023-04-14T16:42:35.173Z,1681490555.173 [VerticalHomogeneityIndexCalculator](DEBUG): (re)initializing
2023-04-14T16:42:35.174Z,1681490555.174 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2023-04-14T16:42:35.175Z,1681490555.175 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2023-04-14T16:42:35.180Z,1681490555.180 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-04-14T16:42:35.180Z,1681490555.180 [NavChart](DEBUG): Initialize NavChart Navigation.
2023-04-14T16:42:35.180Z,1681490555.180 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2023-04-14T16:42:35.181Z,1681490555.181 [SBIT](INFO): Initialize SBIT Component.
2023-04-14T16:42:35.181Z,1681490555.181 [SBIT](IMPORTANT): git: 2023-04-13
2023-04-14T16:42:35.181Z,1681490555.181 [SBIT](INFO): git hash: 58f49511cc08420abb0c5b69b0871de949886db6
2023-04-14T16:42:35.182Z,1681490555.182 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2023-04-14T16:42:35.183Z,1681490555.183 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2023-04-14T16:42:35.184Z,1681490555.184 [SBIT](INFO): Beginning SBIT in 65.000000 seconds.
2023-04-14T16:42:35.184Z,1681490555.184 [IBIT](INFO): Initialize IBIT Component.
2023-04-14T16:42:35.185Z,1681490555.185 [CBIT](DEBUG): Initialize CBIT Component.
2023-04-14T16:42:35.186Z,1681490555.186 [logger ThreadHandler](INFO): Handler Thread ID is 931
2023-04-14T16:42:35.197Z,1681490555.197 [CBIT](DEBUG): Initialized mux pins.
2023-04-14T16:42:35.197Z,1681490555.197 [CBIT](DEBUG): Initializing the watchdog timer.
2023-04-14T16:42:35.206Z,1681490555.206 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 932
2023-04-14T16:42:35.217Z,1681490555.217 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 933
2023-04-14T16:42:35.218Z,1681490555.218 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2023-04-14T16:42:35.221Z,1681490555.221 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2023-04-14T16:42:35.222Z,1681490555.222 [CBIT](DEBUG): Initializing heartbeat.
2023-04-14T16:42:35.229Z,1681490555.229 [Onboard ThreadHandler](INFO): Handler Thread ID is 934
2023-04-14T16:42:35.247Z,1681490555.247 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 935
2023-04-14T16:42:35.270Z,1681490555.270 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 936
2023-04-14T16:42:35.271Z,1681490555.271 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2023-04-14T16:42:35.275Z,1681490555.275 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 938
2023-04-14T16:42:35.278Z,1681490555.278 [WetLabsBB2FL](INFO): Powering up
2023-04-14T16:42:35.279Z,1681490555.279 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 940
2023-04-14T16:42:35.284Z,1681490555.284 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2023-04-14T16:42:35.284Z,1681490555.284 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2023-04-14T16:42:35.284Z,1681490555.284 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2023-04-14T16:42:35.285Z,1681490555.285 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2023-04-14T16:42:35.285Z,1681490555.285 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2023-04-14T16:42:35.285Z,1681490555.285 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2023-04-14T16:42:35.286Z,1681490555.286 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2023-04-14T16:42:35.286Z,1681490555.286 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2023-04-14T16:42:35.293Z,1681490555.293 [CBIT](DEBUG): Deactivating GF circuits.
2023-04-14T16:42:35.293Z,1681490555.293 [CBIT](DEBUG): Deactivating emergency mode.
2023-04-14T16:42:35.333Z,1681490555.333 [CBIT](DEBUG): Backplane powered.
2023-04-14T16:42:35.338Z,1681490555.338 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2023-04-14T16:42:35.340Z,1681490555.340 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2023-04-14T16:42:35.341Z,1681490555.341 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2023-04-14T16:42:35.342Z,1681490555.342 [LoopControl](DEBUG): Initialize LoopControlComponent.
2023-04-14T16:42:35.343Z,1681490555.343 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2023-04-14T16:42:35.379Z,1681490555.379 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2023-04-14T16:42:35.408Z,1681490555.408 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

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

    <Aggregate Id="StartupSatComms">

        <Sequence/>

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

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

    </Aggregate>

</Mission>


2023-04-14T16:42:35.409Z,1681490555.409 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2023-04-14T16:42:35.467Z,1681490555.467 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2023-04-14T16:42:35.468Z,1681490555.468 [Default:A.Wait](DEBUG): Construct Wait.
2023-04-14T16:42:35.475Z,1681490555.475 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-04-14T16:42:35.506Z,1681490555.506 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2023-04-14T16:42:35.508Z,1681490555.508 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2023-04-14T16:42:35.530Z,1681490555.530 [Default:E.Execute](DEBUG): Construct Execute.
2023-04-14T16:42:35.533Z,1681490555.533 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

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

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

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

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

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

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

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

    </Aggregate>

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

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

</Mission>


2023-04-14T16:42:35.550Z,1681490555.550 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,PowerOnly,Power24vConverter,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,VerticalHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2023-04-14T16:42:35.556Z,1681490555.556 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-04-14T16:42:35.653Z,1681490555.653 [Radio_Surface](INFO): Powering up
2023-04-14T16:42:35.680Z,1681490555.680 [Power24vConverter](INFO): Powering up.
2023-04-14T16:42:35.712Z,1681490555.712 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2023-04-14T16:42:35.725Z,1681490555.725 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2023-04-14T16:42:35.726Z,1681490555.726 [ElevatorServo](DEBUG): Initializing EZServoServo.
2023-04-14T16:42:35.733Z,1681490555.733 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2023-04-14T16:42:35.734Z,1681490555.734 [MassServo](DEBUG): Initializing EZServoServo.
2023-04-14T16:42:35.741Z,1681490555.741 [MassServo](DEBUG): Initializing MassServo.
2023-04-14T16:42:35.742Z,1681490555.742 [RudderServo](DEBUG): Initializing EZServoServo.
2023-04-14T16:42:35.749Z,1681490555.749 [RudderServo](DEBUG): Initializing RudderServo.
2023-04-14T16:42:35.750Z,1681490555.750 [ThrusterHE](DEBUG): Initializing EZServoServo.
2023-04-14T16:42:35.757Z,1681490555.757 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2023-04-14T16:42:37.889Z,1681490557.889 [WetLabsBB2FL](INFO): Powering down
2023-04-14T16:42:41.442Z,1681490561.442 [ThrusterHE](ERROR): Zero Speed Commanded.
2023-04-14T16:43:03.443Z,1681490583.443 [NAL9602](INFO): Powering up NAL9602
2023-04-14T16:43:14.351Z,1681490594.351 [NAL9602](INFO): NAL9602 initialized
2023-04-14T16:43:40.625Z,1681490620.625 [SBIT](IMPORTANT): Beginning Startup BIT
2023-04-14T16:43:40.629Z,1681490620.629 [CBIT](IMPORTANT): Beginning ground fault scan
2023-04-14T16:43:41.814Z,1681490621.814 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:43:51.590Z,1681490631.590 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.148288
CHAN A1 (24V): 0.216465
CHAN A2 (12V): 0.073432
CHAN A3 (5V): 0.015524
CHAN B0 (3.3V): 0.009125
CHAN B1 (3.15aV): 0.008765
CHAN B2 (3.15bV): 0.009247
CHAN B3 (GND): -0.005245
OPEN: 0.007537
Full Scale: +/- 1 mA
2023-04-14T16:43:53.934Z,1681490633.934 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:44:06.459Z,1681490646.459 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:44:18.578Z,1681490658.578 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:44:31.101Z,1681490671.101 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:44:34.762Z,1681490674.762 [SBIT](IMPORTANT): SBIT PASSED
2023-04-14T16:44:34.763Z,1681490674.763 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-04-14T16:44:34.764Z,1681490674.764 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool;

2023-04-14T16:44:34.764Z,1681490674.764 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=2 minute;

2023-04-14T16:44:34.766Z,1681490674.766 [SBIT](IMPORTANT): Express linearApproximation VerticalHomogeneityIndexCalculator.vertical_salinity_homogeneity_index 0.050000 practical_salinity_unit;

2023-04-14T16:44:34.766Z,1681490674.766 [SBIT](IMPORTANT): Express linearApproximation VerticalHomogeneityIndexCalculator.vertical_temperature_homogeneity_index 0.050000 celsius;

2023-04-14T16:44:34.766Z,1681490674.766 [SBIT](IMPORTANT): Express linearApproximation _.ayeris_disk_space 100.000000 gigabyte;

2023-04-14T16:44:34.766Z,1681490674.766 [SBIT](IMPORTANT): Express linearApproximation _.ayeris_particle_counts 300.000000 count_per_second;

2023-04-14T16:44:34.767Z,1681490674.767 [SBIT](IMPORTANT): Express linearApproximation _.ayeris_particle_shape 10.000000 count_per_second;

2023-04-14T16:44:34.767Z,1681490674.767 [SBIT](IMPORTANT): Express linearApproximation _.ayeris_particle_slope 0.200000 count_per_millimeter;

2023-04-14T16:44:34.767Z,1681490674.767 [SBIT](IMPORTANT): Express linearApproximation height_above_sea_floor 5.000000 meter;

2023-04-14T16:44:34.767Z,1681490674.767 [SBIT](IMPORTANT): StratificationFrontDetector.loadAtStartup=1 bool;

2023-04-14T16:44:34.767Z,1681490674.767 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=404.421079 cubic_centimeter;

2023-04-14T16:44:34.767Z,1681490674.767 [SBIT](IMPORTANT): VerticalControl.massDefault=11.496592 millimeter;

2023-04-14T16:44:34.767Z,1681490674.767 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.depth3=20 meter;

2023-04-14T16:44:34.767Z,1681490674.767 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.depth4=30 meter;

2023-04-14T16:44:34.768Z,1681490674.768 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.loadAtStartup=1 bool;

2023-04-14T16:44:34.768Z,1681490674.768 [SBIT](IMPORTANT): Waterlinked.loadAtStartup=0 bool;

2023-04-14T16:44:35.167Z,1681490675.167 [MissionManager](IMPORTANT): Started mission Startup
2023-04-14T16:44:35.168Z,1681490675.168 [Startup] Running Loop=1
2023-04-14T16:44:35.168Z,1681490675.168 [Startup](DEBUG): Aggregate::initialize Startup
2023-04-14T16:44:35.168Z,1681490675.168 [Startup:A.GoToSurface] Running Loop=1
2023-04-14T16:44:35.168Z,1681490675.168 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-04-14T16:44:35.168Z,1681490675.168 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-04-14T16:44:35.169Z,1681490675.169 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-04-14T16:44:35.169Z,1681490675.169 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-04-14T16:44:35.170Z,1681490675.170 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-04-14T16:44:35.170Z,1681490675.170 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-04-14T16:44:35.171Z,1681490675.171 [Startup:StartupSatComms] Running Loop=1
2023-04-14T16:44:35.172Z,1681490675.172 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2023-04-14T16:44:35.172Z,1681490675.172 [Startup:StartupSatComms:A] Running Loop=1
2023-04-14T16:44:35.564Z,1681490675.564 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2023-04-14T16:44:43.626Z,1681490683.626 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:44:55.746Z,1681490695.746 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:45:08.269Z,1681490708.269 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:45:20.793Z,1681490720.793 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:45:32.913Z,1681490732.913 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:45:35.355Z,1681490735.355 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2023-04-14T16:45:35.355Z,1681490735.355 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-04-14T16:45:35.356Z,1681490735.356 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2023-04-14T16:45:35.356Z,1681490735.356 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-04-14T16:45:35.358Z,1681490735.358 [Startup:StartupSatComms:A](INFO): Timed out from 2023-04-14T16:44:35.2Z
2023-04-14T16:45:35.358Z,1681490735.358 [Startup:StartupSatComms:A] Stopped
2023-04-14T16:45:35.358Z,1681490735.358 [Startup:StartupSatComms:B] Running Loop=1
2023-04-14T16:45:35.410Z,1681490735.410 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-04-14T16:45:35.410Z,1681490735.410 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-04-14T16:45:35.760Z,1681490735.760 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-04-14T16:45:35.769Z,1681490735.769 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-04-14T16:45:35.770Z,1681490735.770 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2023-04-14T16:45:35.770Z,1681490735.770 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-04-14T16:45:35.770Z,1681490735.770 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2023-04-14T16:45:36.166Z,1681490736.166 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-04-14T16:45:45.449Z,1681490745.449 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:45:57.969Z,1681490757.969 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:46:00.439Z,1681490760.439 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004414
2023-04-14T16:46:07.638Z,1681490767.638 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20230414T155541/Courier0016.lzma
2023-04-14T16:46:08.639Z,1681490768.639 [DataOverHttps](INFO): Moved sent file to Logs/20230414T155541/Courier0016.lzma.bak
2023-04-14T16:46:08.639Z,1681490768.639 [DataOverHttps](INFO): SBD MOMSN=18221097
2023-04-14T16:46:10.486Z,1681490770.486 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:46:22.607Z,1681490782.607 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:46:24.108Z,1681490784.108 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20230414T164223/Courier0000.lzma
2023-04-14T16:46:25.111Z,1681490785.111 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Courier0000.lzma.bak
2023-04-14T16:46:25.111Z,1681490785.111 [DataOverHttps](INFO): SBD MOMSN=18221143
2023-04-14T16:46:34.726Z,1681490794.726 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:46:35.552Z,1681490795.552 [Startup:StartupSatComms:B](INFO): Timed out from 2023-04-14T16:45:35.4Z
2023-04-14T16:46:35.552Z,1681490795.552 [Startup:StartupSatComms:B] Stopped
2023-04-14T16:46:35.552Z,1681490795.552 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2023-04-14T16:46:35.552Z,1681490795.552 [Startup:StartupSatComms] Stopped
2023-04-14T16:46:35.552Z,1681490795.552 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2023-04-14T16:46:35.553Z,1681490795.553 [Startup](INFO): Completed Startup
2023-04-14T16:46:35.553Z,1681490795.553 [MissionManager](INFO): Startup is completed.
2023-04-14T16:46:35.553Z,1681490795.553 [MissionManager](INFO): Uninitializing Mission Startup
2023-04-14T16:46:35.554Z,1681490795.554 [Startup] Stopped
2023-04-14T16:46:35.554Z,1681490795.554 [Startup](DEBUG): Aggregate::uninitialize Startup
2023-04-14T16:46:35.554Z,1681490795.554 [Startup:A.GoToSurface] Stopped
2023-04-14T16:46:35.554Z,1681490795.554 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-04-14T16:46:35.967Z,1681490795.967 [MissionManager](IMPORTANT): Started mission Default
2023-04-14T16:46:35.967Z,1681490795.967 [Default] Running Loop=1
2023-04-14T16:46:35.967Z,1681490795.967 [Default](DEBUG): Aggregate::initialize Default
2023-04-14T16:46:35.967Z,1681490795.967 [Default:B.GoToSurface] Running Loop=1
2023-04-14T16:46:35.968Z,1681490795.968 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-04-14T16:46:35.968Z,1681490795.968 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-04-14T16:46:35.968Z,1681490795.968 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-04-14T16:46:35.968Z,1681490795.968 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-04-14T16:46:35.969Z,1681490795.969 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-04-14T16:46:35.969Z,1681490795.969 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-04-14T16:46:35.970Z,1681490795.970 [Default:A.Wait] Running Loop=1
2023-04-14T16:46:35.970Z,1681490795.970 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-04-14T16:46:40.659Z,1681490800.659 [DataOverHttps](INFO): Sending 878 bytes from file Logs/20230414T155541/Express0017.lzma
2023-04-14T16:46:41.659Z,1681490801.659 [DataOverHttps](INFO): Moved sent file to Logs/20230414T155541/Express0017.lzma.bak
2023-04-14T16:46:41.659Z,1681490801.659 [DataOverHttps](INFO): SBD MOMSN=18221149
2023-04-14T16:46:47.662Z,1681490807.662 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:46:49.292Z,1681490809.292 [Default:A.Wait](INFO): Done Waiting.
2023-04-14T16:46:49.292Z,1681490809.292 [Default:A.Wait] Stopped
2023-04-14T16:46:49.292Z,1681490809.292 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-04-14T16:46:49.700Z,1681490809.700 [Default:CheckIn] Running Loop=1
2023-04-14T16:46:49.700Z,1681490809.700 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-14T16:46:49.700Z,1681490809.700 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-14T16:46:50.096Z,1681490810.096 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-04-14T16:46:59.773Z,1681490819.773 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:47:11.894Z,1681490831.894 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:47:24.417Z,1681490844.417 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:47:32.504Z,1681490852.504 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-31 in onboard configuration file).
2023-04-14T16:47:36.942Z,1681490856.942 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:47:49.066Z,1681490869.066 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:48:01.183Z,1681490881.183 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:48:14.109Z,1681490894.109 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:48:17.755Z,1681490897.755 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-04-14T16:48:26.645Z,1681490906.645 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:48:36.374Z,1681490916.374 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2023-04-14T16:48:36.374Z,1681490916.374 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-04-14T16:48:36.375Z,1681490916.375 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2
2023-04-14T16:48:36.375Z,1681490916.375 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-04-14T16:48:36.386Z,1681490916.386 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-04-14T16:48:36.386Z,1681490916.386 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-04-14T16:48:36.789Z,1681490916.789 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-04-14T16:48:36.789Z,1681490916.789 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2023-04-14T16:48:36.789Z,1681490916.789 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-04-14T16:48:36.790Z,1681490916.790 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2
2023-04-14T16:48:37.150Z,1681490917.150 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-04-14T16:48:38.349Z,1681490918.349 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:48:44.009Z,1681490924.009 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7).
2023-04-14T16:48:55.318Z,1681490935.318 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7).
2023-04-14T16:49:06.230Z,1681490946.230 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7).
2023-04-14T16:49:17.537Z,1681490957.537 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7).
2023-04-14T16:49:28.849Z,1681490968.849 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7).
2023-04-14T16:49:40.162Z,1681490980.162 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7).
2023-04-14T16:49:51.073Z,1681490991.073 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7).
2023-04-14T16:50:02.382Z,1681491002.382 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7).
2023-04-14T16:50:13.694Z,1681491013.694 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7).
2023-04-14T16:50:24.617Z,1681491024.617 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7).
2023-04-14T16:50:35.510Z,1681491035.510 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7).
2023-04-14T16:50:46.821Z,1681491046.821 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7).
2023-04-14T16:50:58.134Z,1681491058.134 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7).
2023-04-14T16:51:09.445Z,1681491069.445 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:51:21.974Z,1681491081.974 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:51:34.898Z,1681491094.898 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:51:37.350Z,1681491097.350 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2023-04-14T16:51:37.350Z,1681491097.350 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-04-14T16:51:37.351Z,1681491097.351 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 3
2023-04-14T16:51:37.351Z,1681491097.351 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-04-14T16:51:37.398Z,1681491097.398 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-04-14T16:51:37.398Z,1681491097.398 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-04-14T16:51:37.770Z,1681491097.770 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-04-14T16:51:37.771Z,1681491097.771 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2023-04-14T16:51:37.771Z,1681491097.771 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-04-14T16:51:37.771Z,1681491097.771 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 3
2023-04-14T16:51:38.144Z,1681491098.144 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-04-14T16:51:47.421Z,1681491107.421 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:51:49.866Z,1681491109.866 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-04-14T16:46:49.7Z
2023-04-14T16:51:49.866Z,1681491109.866 [Default:CheckIn:Read_GPS] Stopped
2023-04-14T16:51:49.867Z,1681491109.867 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-14T16:51:50.272Z,1681491110.272 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-04-14T16:51:56.756Z,1681491116.756 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230414T164223/Courier0004.lzma
2023-04-14T16:51:57.759Z,1681491117.759 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Courier0004.lzma.bak
2023-04-14T16:51:57.759Z,1681491117.759 [DataOverHttps](INFO): SBD MOMSN=18221229
2023-04-14T16:51:59.541Z,1681491119.541 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:52:12.065Z,1681491132.065 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:52:13.222Z,1681491133.222 [DataOverHttps](INFO): Sending 985 bytes from file Logs/20230414T164223/Express0001.lzma
2023-04-14T16:52:21.494Z,1681491141.494 [DataOverHttps](INFO): Sending 985 bytes from file Logs/20230414T164223/Express0001.lzma
2023-04-14T16:52:22.495Z,1681491142.495 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Express0001.lzma.bak
2023-04-14T16:52:22.495Z,1681491142.495 [DataOverHttps](INFO): SBD MOMSN=18221231
2023-04-14T16:52:24.186Z,1681491144.186 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:52:36.810Z,1681491156.810 [Power24vConverter](INFO): Powering down.
2023-04-14T16:52:37.114Z,1681491157.114 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:52:38.089Z,1681491158.089 [DataOverHttps](INFO): Sending 187 bytes from file Logs/20230414T164223/Express0005.lzma
2023-04-14T16:52:39.091Z,1681491159.091 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Express0005.lzma.bak
2023-04-14T16:52:39.091Z,1681491159.091 [DataOverHttps](INFO): SBD MOMSN=18221262
2023-04-14T16:52:40.363Z,1681491160.363 [Default:CheckIn:Read_Iridium] Stopped
2023-04-14T16:52:40.363Z,1681491160.363 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-14T16:52:40.363Z,1681491160.363 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-14T16:52:49.637Z,1681491169.637 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:53:02.161Z,1681491182.161 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:53:14.686Z,1681491194.686 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:53:17.923Z,1681491197.923 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-04-14T16:53:17.923Z,1681491197.923 [NAL9602] Data Fault, FailCount= 1
2023-04-14T16:53:17.923Z,1681491197.923 [NAL9602](ERROR): Data Fault
2023-04-14T16:53:17.982Z,1681491197.982 [CBIT](ERROR): Data Fault in component: NAL9602
2023-04-14T16:53:18.326Z,1681491198.326 [NAL9602](INFO): Powering down
2023-04-14T16:53:19.174Z,1681491199.174 [CBIT](INFO): Clearing failed state for component NAL9602
2023-04-14T16:53:19.174Z,1681491199.174 [NAL9602] No Fault, FailCount= 1
2023-04-14T16:53:26.817Z,1681491206.817 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:53:39.330Z,1681491219.330 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:53:48.630Z,1681491228.630 [NAL9602](INFO): Powering up NAL9602
2023-04-14T16:53:51.450Z,1681491231.450 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:53:59.543Z,1681491239.543 [NAL9602](INFO): NAL9602 initialized
2023-04-14T16:54:03.570Z,1681491243.570 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:54:15.285Z,1681491255.285 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:54:27.405Z,1681491267.405 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:54:38.334Z,1681491278.334 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2023-04-14T16:54:38.334Z,1681491278.334 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-04-14T16:54:38.336Z,1681491278.336 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 4
2023-04-14T16:54:38.336Z,1681491278.336 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-04-14T16:54:38.347Z,1681491278.347 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-04-14T16:54:38.347Z,1681491278.347 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-04-14T16:54:38.750Z,1681491278.750 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-04-14T16:54:38.750Z,1681491278.750 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2023-04-14T16:54:38.751Z,1681491278.751 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-04-14T16:54:38.751Z,1681491278.751 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 4
2023-04-14T16:54:39.206Z,1681491279.206 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-04-14T16:54:39.525Z,1681491279.525 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:54:52.054Z,1681491292.054 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:55:04.573Z,1681491304.573 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:55:17.097Z,1681491317.097 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:55:29.622Z,1681491329.622 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:55:41.755Z,1681491341.755 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:55:54.680Z,1681491354.680 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:56:06.791Z,1681491366.791 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:56:19.314Z,1681491379.314 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:56:31.434Z,1681491391.434 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:56:43.958Z,1681491403.958 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:56:56.083Z,1681491416.083 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:57:08.601Z,1681491428.601 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:57:20.721Z,1681491440.721 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:57:33.246Z,1681491453.246 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:57:39.338Z,1681491459.338 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2023-04-14T16:57:39.339Z,1681491459.339 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-04-14T16:57:39.340Z,1681491459.340 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 5
2023-04-14T16:57:39.340Z,1681491459.340 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-04-14T16:57:39.402Z,1681491459.402 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-04-14T16:57:39.402Z,1681491459.402 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-04-14T16:57:39.763Z,1681491459.763 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-04-14T16:57:39.763Z,1681491459.763 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2023-04-14T16:57:39.764Z,1681491459.764 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-04-14T16:57:39.764Z,1681491459.764 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 5
2023-04-14T16:57:40.148Z,1681491460.148 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-04-14T16:57:40.936Z,1681491460.936 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-14T16:57:40.936Z,1681491460.936 [Default:CheckIn:C.Wait] Stopped
2023-04-14T16:57:40.936Z,1681491460.936 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-14T16:57:40.936Z,1681491460.936 [Default:CheckIn:D] Running Loop=1
2023-04-14T16:57:41.351Z,1681491461.351 [Default:CheckIn:D] Stopped
2023-04-14T16:57:41.351Z,1681491461.351 [Default:CheckIn:E] Running Loop=1
2023-04-14T16:57:41.748Z,1681491461.748 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.089721 min 
2023-04-14T16:57:41.748Z,1681491461.748 [Default:CheckIn:E] Stopped
2023-04-14T16:57:41.748Z,1681491461.748 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-14T16:57:41.748Z,1681491461.748 [Default:CheckIn] Stopped
2023-04-14T16:57:41.748Z,1681491461.748 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-14T16:57:41.748Z,1681491461.748 [Default:CheckIn](INFO): Running loop #2
2023-04-14T16:57:41.748Z,1681491461.748 [Default:CheckIn] Running Loop=2
2023-04-14T16:57:41.748Z,1681491461.748 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-14T16:57:41.749Z,1681491461.749 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-14T16:57:46.175Z,1681491466.175 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:57:58.702Z,1681491478.702 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:58:11.238Z,1681491491.238 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T16:58:22.602Z,1681491502.602 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7).
2023-04-14T16:58:33.850Z,1681491513.850 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7).
2023-04-14T16:58:45.162Z,1681491525.162 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7).
2023-04-14T16:58:56.473Z,1681491536.473 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7).
2023-04-14T16:59:07.797Z,1681491547.797 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7).
2023-04-14T16:59:19.155Z,1681491559.155 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7).
2023-04-14T16:59:30.409Z,1681491570.409 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7).
2023-04-14T16:59:41.318Z,1681491581.318 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7).
2023-04-14T16:59:42.148Z,1681491582.148 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165941.00,A,3648.17903,N,12147.20820,W,0.194,0.00,140423,,,A*72
2023-04-14T16:59:42.151Z,1681491582.151 [NAL9602](INFO): GPS fix at 20230414T165941: (36.802984, -121.786803)
2023-04-14T16:59:42.182Z,1681491582.182 [Default:CheckIn:Read_GPS] Stopped
2023-04-14T16:59:42.182Z,1681491582.182 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-14T16:59:49.569Z,1681491589.569 [DataOverHttps](INFO): Sending 224 bytes from file Logs/20230414T164223/Courier0007.lzma
2023-04-14T16:59:50.571Z,1681491590.571 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Courier0007.lzma.bak
2023-04-14T16:59:50.571Z,1681491590.571 [DataOverHttps](INFO): SBD MOMSN=18221301
2023-04-14T16:59:52.275Z,1681491592.275 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7).
2023-04-14T17:00:03.587Z,1681491603.587 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7).
2023-04-14T17:00:06.369Z,1681491606.369 [DataOverHttps](INFO): Sending 306 bytes from file Logs/20230414T164223/Express0008.lzma
2023-04-14T17:00:07.371Z,1681491607.371 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Express0008.lzma.bak
2023-04-14T17:00:07.371Z,1681491607.371 [DataOverHttps](INFO): SBD MOMSN=18221304
2023-04-14T17:00:08.470Z,1681491608.470 [Default:CheckIn:Read_Iridium] Stopped
2023-04-14T17:00:08.470Z,1681491608.470 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-14T17:00:08.470Z,1681491608.470 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-14T17:00:14.535Z,1681491614.535 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-14T17:00:14.899Z,1681491614.899 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7).
2023-04-14T17:00:26.212Z,1681491626.212 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7).
2023-04-14T17:00:37.525Z,1681491637.525 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7).
2023-04-14T17:00:43.639Z,1681491643.639 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T17:00:56.192Z,1681491656.192 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T17:01:09.094Z,1681491669.094 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T17:01:21.158Z,1681491681.158 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T17:01:33.276Z,1681491693.276 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T17:01:45.395Z,1681491705.395 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T17:01:58.323Z,1681491718.323 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T17:02:10.847Z,1681491730.847 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T17:02:23.373Z,1681491743.373 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T17:02:36.299Z,1681491756.299 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T17:02:48.419Z,1681491768.419 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T17:03:00.943Z,1681491780.943 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T17:03:13.174Z,1681491793.174 [DataOverHttps](IMPORTANT): SBD MTMSN=20230414T170312
2023-04-14T17:03:13.469Z,1681491793.469 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T17:03:20.461Z,1681491800.461 [DataOverHttps](INFO): Received command: ibit
2023-04-14T17:03:20.526Z,1681491800.526 [CommandExec](IMPORTANT): got command ibit
2023-04-14T17:03:20.771Z,1681491800.771 [IBIT](IMPORTANT): Beginning Initiated BIT
2023-04-14T17:03:20.771Z,1681491800.771 [IBIT](IMPORTANT): Beginning control surface checks.
2023-04-14T17:03:20.775Z,1681491800.775 [CBIT](IMPORTANT): Beginning ground fault scan
2023-04-14T17:03:22.364Z,1681491802.364 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170322.00,A,3648.16867,N,12147.26396,W,3.849,101.21,140423,,,A*72
2023-04-14T17:03:22.375Z,1681491802.375 [NAL9602](INFO): GPS fix at 20230414T170322: (36.802811, -121.787733)
2023-04-14T17:03:23.666Z,1681491803.666 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2023-04-14T17:03:26.418Z,1681491806.418 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T17:03:31.727Z,1681491811.727 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.164160
CHAN A1 (24V) N/A reporting off
CHAN A2 (12V): 0.078320
CHAN A3 (5V): 0.016458
CHAN B0 (3.3V): 0.008262
CHAN B1 (3.15aV): 0.007888
CHAN B2 (3.15bV): 0.007299
CHAN B3 (GND): -0.004021
OPEN: 0.007009
Full Scale: +/- 1 mA
2023-04-14T17:03:38.537Z,1681491818.537 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T17:03:38.551Z,1681491818.551 [NAL9602](INFO): SBD MO Status=0, MOMSN=11433, MT Status=0, MTMSN=0
2023-04-14T17:03:38.551Z,1681491818.551 [NAL9602](INFO): No messages in MT queue
2023-04-14T17:03:39.752Z,1681491819.752 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170339.00,A,3648.15900,N,12147.25172,W,4.024,197.95,140423,,,A*74
2023-04-14T17:03:39.755Z,1681491819.755 [NAL9602](INFO): GPS fix at 20230414T170339: (36.802650, -121.787529)
2023-04-14T17:03:42.175Z,1681491822.175 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170342.00,A,3648.15659,N,12147.25315,W,3.227,205.09,140423,,,A*73
2023-04-14T17:03:42.188Z,1681491822.188 [NAL9602](INFO): GPS fix at 20230414T170342: (36.802610, -121.787553)
2023-04-14T17:03:45.416Z,1681491825.416 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170345.00,A,3648.15406,N,12147.25436,W,3.402,200.36,140423,,,A*72
2023-04-14T17:03:45.418Z,1681491825.418 [NAL9602](INFO): GPS fix at 20230414T170345: (36.802568, -121.787573)
2023-04-14T17:03:48.240Z,1681491828.240 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170348.00,A,3648.15190,N,12147.25535,W,2.721,199.76,140423,,,A*73
2023-04-14T17:03:48.242Z,1681491828.242 [NAL9602](INFO): GPS fix at 20230414T170348: (36.802532, -121.787589)
2023-04-14T17:03:50.669Z,1681491830.669 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-14T17:03:51.488Z,1681491831.488 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170351.00,A,3648.14990,N,12147.25540,W,2.274,180.75,140423,,,A*7E
2023-04-14T17:03:51.490Z,1681491831.490 [NAL9602](INFO): GPS fix at 20230414T170351: (36.802498, -121.787590)
2023-04-14T17:03:54.296Z,1681491834.296 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170354.00,A,3648.14822,N,12147.25427,W,2.099,139.22,140423,,,A*72
2023-04-14T17:03:54.300Z,1681491834.300 [NAL9602](INFO): GPS fix at 20230414T170354: (36.802470, -121.787571)
2023-04-14T17:03:57.532Z,1681491837.532 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170357.00,A,3648.14660,N,12147.25146,W,2.857,126.40,140423,,,A*7B
2023-04-14T17:03:57.534Z,1681491837.534 [NAL9602](INFO): GPS fix at 20230414T170357: (36.802443, -121.787524)
2023-04-14T17:04:00.355Z,1681491840.355 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170400.00,A,3648.14536,N,12147.24815,W,3.091,116.49,140423,,,A*79
2023-04-14T17:04:00.357Z,1681491840.357 [NAL9602](INFO): GPS fix at 20230414T170400: (36.802423, -121.787469)
2023-04-14T17:04:03.184Z,1681491843.184 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170403.00,A,3648.14333,N,12147.24450,W,4.510,118.16,140423,,,A*7B
2023-04-14T17:04:03.187Z,1681491843.187 [NAL9602](INFO): GPS fix at 20230414T170403: (36.802389, -121.787408)
2023-04-14T17:04:06.415Z,1681491846.415 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170406.00,A,3648.14161,N,12147.24093,W,2.974,114.46,140423,,,A*71
2023-04-14T17:04:06.417Z,1681491846.417 [NAL9602](INFO): GPS fix at 20230414T170406: (36.802360, -121.787349)
2023-04-14T17:04:06.862Z,1681491846.862 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 3
Latitude: 36.802361 Longitude: -121.787346
2023-04-14T17:04:07.257Z,1681491847.257 [IBIT](FAULT): Warning: Battery Data not active. Expected only when running primaries. Threshold checking not active.
2023-04-14T17:04:07.644Z,1681491847.644 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2023-04-14T17:04:07.644Z,1681491847.644 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2023-04-14T17:04:07.645Z,1681491847.645 [IBIT](IMPORTANT): Pressure:9.265732 PSI
2023-04-14T17:04:07.645Z,1681491847.645 [IBIT](IMPORTANT): Humidity:18.483702 %
2023-04-14T17:04:08.053Z,1681491848.053 [IBIT](IMPORTANT): Vehicle Pitch:4.644915 degrees
2023-04-14T17:04:08.053Z,1681491848.053 [IBIT](IMPORTANT): Vehicle  Roll:-1.770688 degrees
2023-04-14T17:04:08.054Z,1681491848.054 [IBIT](IMPORTANT): Vehicle  Heading:65.102272 degrees
2023-04-14T17:04:08.457Z,1681491848.457 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2023-04-14T17:04:08.457Z,1681491848.457 [IBIT](IMPORTANT): buoyancyNeutral: 404.421082 cc
2023-04-14T17:04:08.458Z,1681491848.458 [IBIT](IMPORTANT): massDefault: 1.149659 cm
2023-04-14T17:04:08.458Z,1681491848.458 [IBIT](IMPORTANT): stopDepth: 290.000000 m
2023-04-14T17:04:08.458Z,1681491848.458 [IBIT](IMPORTANT): abortDepth: 300.000000 m
2023-04-14T17:04:08.458Z,1681491848.458 [IBIT](IMPORTANT): IBIT PASSED
2023-04-14T17:04:38.738Z,1681491878.738 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-14T17:05:09.045Z,1681491909.045 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-14T17:05:09.045Z,1681491909.045 [Default:CheckIn:C.Wait] Stopped
2023-04-14T17:05:09.045Z,1681491909.045 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-14T17:05:09.045Z,1681491909.045 [Default:CheckIn:D] Running Loop=1
2023-04-14T17:05:09.449Z,1681491909.449 [Default:CheckIn:D] Stopped
2023-04-14T17:05:09.450Z,1681491909.450 [Default:CheckIn:E] Running Loop=1
2023-04-14T17:05:09.864Z,1681491909.864 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 18.558034 min 
2023-04-14T17:05:09.864Z,1681491909.864 [Default:CheckIn:E] Stopped
2023-04-14T17:05:09.864Z,1681491909.864 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-14T17:05:09.864Z,1681491909.864 [Default:CheckIn] Stopped
2023-04-14T17:05:09.864Z,1681491909.864 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-14T17:05:09.865Z,1681491909.865 [Default:CheckIn](INFO): Running loop #3
2023-04-14T17:05:09.865Z,1681491909.865 [Default:CheckIn] Running Loop=3
2023-04-14T17:05:09.865Z,1681491909.865 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-14T17:05:09.865Z,1681491909.865 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-14T17:05:11.892Z,1681491911.892 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170511.00,A,3648.14440,N,12147.22977,W,1.263,51.80,140423,,,A*41
2023-04-14T17:05:11.894Z,1681491911.894 [NAL9602](INFO): GPS fix at 20230414T170511: (36.802407, -121.787163)
2023-04-14T17:05:11.907Z,1681491911.907 [Default:CheckIn:Read_GPS] Stopped
2023-04-14T17:05:11.907Z,1681491911.907 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-14T17:05:19.276Z,1681491919.276 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230414T164223/Courier0010.lzma
2023-04-14T17:05:20.279Z,1681491920.279 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Courier0010.lzma.bak
2023-04-14T17:05:20.279Z,1681491920.279 [DataOverHttps](INFO): SBD MOMSN=18221355
2023-04-14T17:05:38.995Z,1681491938.995 [DataOverHttps](INFO): Sending 830 bytes from file Logs/20230414T164223/Express0011.lzma
2023-04-14T17:05:39.995Z,1681491939.995 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Express0011.lzma.bak
2023-04-14T17:05:39.995Z,1681491939.995 [DataOverHttps](INFO): SBD MOMSN=18221358
2023-04-14T17:05:41.435Z,1681491941.435 [NAL9602](INFO): SBD MO Status=0, MOMSN=11434, MT Status=0, MTMSN=0
2023-04-14T17:05:41.435Z,1681491941.435 [NAL9602](INFO): No messages in MT queue
2023-04-14T17:05:55.984Z,1681491955.984 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20230414T164223/Express0014.lzma
2023-04-14T17:05:56.987Z,1681491956.987 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Express0014.lzma.bak
2023-04-14T17:05:56.987Z,1681491956.987 [DataOverHttps](INFO): SBD MOMSN=18221384
2023-04-14T17:05:58.001Z,1681491958.001 [Default:CheckIn:Read_Iridium] Stopped
2023-04-14T17:05:58.001Z,1681491958.001 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-14T17:05:58.001Z,1681491958.001 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-14T17:06:12.116Z,1681491972.116 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-14T17:10:19.425Z,1681492219.425 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2023-04-14T17:10:19.431Z,1681492219.431 [BPC1](INFO): Received data from all battery sticks.
2023-04-14T17:10:58.635Z,1681492258.635 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-14T17:10:58.636Z,1681492258.636 [Default:CheckIn:C.Wait] Stopped
2023-04-14T17:10:58.636Z,1681492258.636 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-14T17:10:58.636Z,1681492258.636 [Default:CheckIn:D] Running Loop=1
2023-04-14T17:10:59.027Z,1681492259.027 [Default:CheckIn:D] Stopped
2023-04-14T17:10:59.027Z,1681492259.027 [Default:CheckIn:E] Running Loop=1
2023-04-14T17:10:59.425Z,1681492259.425 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 24.384330 min 
2023-04-14T17:10:59.425Z,1681492259.425 [Default:CheckIn:E] Stopped
2023-04-14T17:10:59.425Z,1681492259.425 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-14T17:10:59.425Z,1681492259.425 [Default:CheckIn] Stopped
2023-04-14T17:10:59.425Z,1681492259.425 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-14T17:10:59.425Z,1681492259.425 [Default:CheckIn](INFO): Running loop #4
2023-04-14T17:10:59.425Z,1681492259.425 [Default:CheckIn] Running Loop=4
2023-04-14T17:10:59.425Z,1681492259.425 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-14T17:10:59.425Z,1681492259.425 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-14T17:11:01.440Z,1681492261.440 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171101.00,A,3648.15091,N,12147.22184,W,0.039,0.00,140423,,,D*7D
2023-04-14T17:11:01.442Z,1681492261.442 [NAL9602](INFO): GPS fix at 20230414T171101: (36.802515, -121.787031)
2023-04-14T17:11:01.454Z,1681492261.454 [Default:CheckIn:Read_GPS] Stopped
2023-04-14T17:11:01.454Z,1681492261.454 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-14T17:11:08.521Z,1681492268.521 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20230414T164223/Courier0016.lzma
2023-04-14T17:11:09.523Z,1681492269.523 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Courier0016.lzma.bak
2023-04-14T17:11:09.523Z,1681492269.523 [DataOverHttps](INFO): SBD MOMSN=18221429
2023-04-14T17:11:18.004Z,1681492278.004 [NAL9602](INFO): SBD MO Status=0, MOMSN=11435, MT Status=0, MTMSN=0
2023-04-14T17:11:18.004Z,1681492278.004 [NAL9602](INFO): No messages in MT queue
2023-04-14T17:11:25.180Z,1681492285.180 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20230414T164223/Express0017.lzma
2023-04-14T17:11:26.183Z,1681492286.183 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Express0017.lzma.bak
2023-04-14T17:11:26.183Z,1681492286.183 [DataOverHttps](INFO): SBD MOMSN=18221432
2023-04-14T17:11:27.300Z,1681492287.300 [Default:CheckIn:Read_Iridium] Stopped
2023-04-14T17:11:27.300Z,1681492287.300 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-14T17:11:27.300Z,1681492287.300 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-14T17:11:48.718Z,1681492308.718 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-14T17:16:27.914Z,1681492587.914 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-14T17:16:27.914Z,1681492587.914 [Default:CheckIn:C.Wait] Stopped
2023-04-14T17:16:27.914Z,1681492587.914 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-14T17:16:27.915Z,1681492587.915 [Default:CheckIn:D] Running Loop=1
2023-04-14T17:16:28.334Z,1681492588.334 [Default:CheckIn:D] Stopped
2023-04-14T17:16:28.334Z,1681492588.334 [Default:CheckIn:E] Running Loop=1
2023-04-14T17:16:28.726Z,1681492588.726 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 29.872770 min 
2023-04-14T17:16:28.726Z,1681492588.726 [Default:CheckIn:E] Stopped
2023-04-14T17:16:28.726Z,1681492588.726 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-14T17:16:28.726Z,1681492588.726 [Default:CheckIn] Stopped
2023-04-14T17:16:28.726Z,1681492588.726 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-14T17:16:28.726Z,1681492588.726 [Default:CheckIn](INFO): Running loop #5
2023-04-14T17:16:28.726Z,1681492588.726 [Default:CheckIn] Running Loop=5
2023-04-14T17:16:28.726Z,1681492588.726 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-14T17:16:28.726Z,1681492588.726 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-14T17:16:30.731Z,1681492590.731 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171630.00,A,3648.14938,N,12147.22128,W,0.058,0.00,140423,,,D*72
2023-04-14T17:16:30.733Z,1681492590.733 [NAL9602](INFO): GPS fix at 20230414T171630: (36.802490, -121.787021)
2023-04-14T17:16:30.746Z,1681492590.746 [Default:CheckIn:Read_GPS] Stopped
2023-04-14T17:16:30.746Z,1681492590.746 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-14T17:16:37.512Z,1681492597.512 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230414T164223/Courier0019.lzma
2023-04-14T17:16:38.515Z,1681492598.515 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Courier0019.lzma.bak
2023-04-14T17:16:38.515Z,1681492598.515 [DataOverHttps](INFO): SBD MOMSN=18221445
2023-04-14T17:16:52.972Z,1681492612.972 [NAL9602](INFO): SBD MO Status=0, MOMSN=11436, MT Status=0, MTMSN=0
2023-04-14T17:16:52.972Z,1681492612.972 [NAL9602](INFO): No messages in MT queue
2023-04-14T17:16:54.444Z,1681492614.444 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20230414T164223/Express0020.lzma
2023-04-14T17:16:55.447Z,1681492615.447 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Express0020.lzma.bak
2023-04-14T17:16:55.447Z,1681492615.447 [DataOverHttps](INFO): SBD MOMSN=18221448
2023-04-14T17:16:56.602Z,1681492616.602 [Default:CheckIn:Read_Iridium] Stopped
2023-04-14T17:16:56.602Z,1681492616.602 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-14T17:16:56.602Z,1681492616.602 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-14T17:17:23.653Z,1681492643.653 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-14T17:21:57.281Z,1681492917.281 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-14T17:21:57.281Z,1681492917.281 [Default:CheckIn:C.Wait] Stopped
2023-04-14T17:21:57.281Z,1681492917.281 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-14T17:21:57.281Z,1681492917.281 [Default:CheckIn:D] Running Loop=1
2023-04-14T17:21:57.657Z,1681492917.657 [Default:CheckIn:D] Stopped
2023-04-14T17:21:57.657Z,1681492917.657 [Default:CheckIn:E] Running Loop=1
2023-04-14T17:21:58.061Z,1681492918.061 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 35.361495 min 
2023-04-14T17:21:58.061Z,1681492918.061 [Default:CheckIn:E] Stopped
2023-04-14T17:21:58.061Z,1681492918.061 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-14T17:21:58.061Z,1681492918.061 [Default:CheckIn] Stopped
2023-04-14T17:21:58.062Z,1681492918.062 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-14T17:21:58.062Z,1681492918.062 [Default:CheckIn](INFO): Running loop #6
2023-04-14T17:21:58.062Z,1681492918.062 [Default:CheckIn] Running Loop=6
2023-04-14T17:21:58.062Z,1681492918.062 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-14T17:21:58.062Z,1681492918.062 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-14T17:22:00.080Z,1681492920.080 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172200.00,A,3648.15009,N,12147.22088,W,0.117,0.00,140423,,,D*7D
2023-04-14T17:22:00.082Z,1681492920.082 [NAL9602](INFO): GPS fix at 20230414T172200: (36.802501, -121.787015)
2023-04-14T17:22:00.094Z,1681492920.094 [Default:CheckIn:Read_GPS] Stopped
2023-04-14T17:22:00.094Z,1681492920.094 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-14T17:22:07.080Z,1681492927.080 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230414T164223/Courier0022.lzma
2023-04-14T17:22:08.083Z,1681492928.083 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Courier0022.lzma.bak
2023-04-14T17:22:08.083Z,1681492928.083 [DataOverHttps](INFO): SBD MOMSN=18221458
2023-04-14T17:22:22.304Z,1681492942.304 [NAL9602](INFO): SBD MO Status=2, MOMSN=11437, MT Status=2, MTMSN=0
2023-04-14T17:22:22.304Z,1681492942.304 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-04-14T17:22:23.851Z,1681492943.851 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230414T164223/Express0023.lzma
2023-04-14T17:22:24.851Z,1681492944.851 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Express0023.lzma.bak
2023-04-14T17:22:24.851Z,1681492944.851 [DataOverHttps](INFO): SBD MOMSN=18221461
2023-04-14T17:22:25.938Z,1681492945.938 [Default:CheckIn:Read_Iridium] Stopped
2023-04-14T17:22:25.938Z,1681492945.938 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-14T17:22:25.938Z,1681492945.938 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-14T17:23:03.104Z,1681492983.104 [NAL9602](INFO): SBD MO Status=0, MOMSN=11437, MT Status=0, MTMSN=0
2023-04-14T17:23:03.104Z,1681492983.104 [NAL9602](INFO): No messages in MT queue
2023-04-14T17:23:33.797Z,1681493013.797 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-14T17:27:26.518Z,1681493246.518 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-14T17:27:26.518Z,1681493246.518 [Default:CheckIn:C.Wait] Stopped
2023-04-14T17:27:26.518Z,1681493246.518 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-14T17:27:26.518Z,1681493246.518 [Default:CheckIn:D] Running Loop=1
2023-04-14T17:27:26.922Z,1681493246.922 [Default:CheckIn:D] Stopped
2023-04-14T17:27:26.922Z,1681493246.922 [Default:CheckIn:E] Running Loop=1
2023-04-14T17:27:27.342Z,1681493247.342 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 40.849247 min 
2023-04-14T17:27:27.342Z,1681493247.342 [Default:CheckIn:E] Stopped
2023-04-14T17:27:27.342Z,1681493247.342 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-14T17:27:27.342Z,1681493247.342 [Default:CheckIn] Stopped
2023-04-14T17:27:27.342Z,1681493247.342 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-14T17:27:27.343Z,1681493247.343 [Default:CheckIn](INFO): Running loop #7
2023-04-14T17:27:27.343Z,1681493247.343 [Default:CheckIn] Running Loop=7
2023-04-14T17:27:27.343Z,1681493247.343 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-14T17:27:27.343Z,1681493247.343 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-14T17:27:29.336Z,1681493249.336 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172729.00,A,3648.37006,N,12147.11136,W,4.257,352.89,140423,,,D*7E
2023-04-14T17:27:29.338Z,1681493249.338 [NAL9602](INFO): GPS fix at 20230414T172729: (36.806168, -121.785189)
2023-04-14T17:27:29.379Z,1681493249.379 [Default:CheckIn:Read_GPS] Stopped
2023-04-14T17:27:29.379Z,1681493249.379 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-14T17:27:39.248Z,1681493259.248 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230414T164223/Courier0025.lzma
2023-04-14T17:27:40.251Z,1681493260.251 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Courier0025.lzma.bak
2023-04-14T17:27:40.251Z,1681493260.251 [DataOverHttps](INFO): SBD MOMSN=18221475
2023-04-14T17:27:42.748Z,1681493262.748 [NAL9602](INFO): SBD MO Status=0, MOMSN=11438, MT Status=0, MTMSN=0
2023-04-14T17:27:42.748Z,1681493262.748 [NAL9602](INFO): No messages in MT queue
2023-04-14T17:27:56.073Z,1681493276.073 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230414T164223/Express0026.lzma
2023-04-14T17:27:57.075Z,1681493277.075 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Express0026.lzma.bak
2023-04-14T17:27:57.075Z,1681493277.075 [DataOverHttps](INFO): SBD MOMSN=18221478
2023-04-14T17:27:58.118Z,1681493278.118 [Default:CheckIn:Read_Iridium] Stopped
2023-04-14T17:27:58.118Z,1681493278.118 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-14T17:27:58.118Z,1681493278.118 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-14T17:28:13.453Z,1681493293.453 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-14T17:32:58.730Z,1681493578.730 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-14T17:32:58.730Z,1681493578.730 [Default:CheckIn:C.Wait] Stopped
2023-04-14T17:32:58.730Z,1681493578.730 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-14T17:32:58.730Z,1681493578.730 [Default:CheckIn:D] Running Loop=1
2023-04-14T17:32:59.145Z,1681493579.145 [Default:CheckIn:D] Stopped
2023-04-14T17:32:59.145Z,1681493579.145 [Default:CheckIn:E] Running Loop=1
2023-04-14T17:32:59.536Z,1681493579.536 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 46.386292 min 
2023-04-14T17:32:59.536Z,1681493579.536 [Default:CheckIn:E] Stopped
2023-04-14T17:32:59.536Z,1681493579.536 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-14T17:32:59.536Z,1681493579.536 [Default:CheckIn] Stopped
2023-04-14T17:32:59.537Z,1681493579.537 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-14T17:32:59.537Z,1681493579.537 [Default:CheckIn](INFO): Running loop #8
2023-04-14T17:32:59.537Z,1681493579.537 [Default:CheckIn] Running Loop=8
2023-04-14T17:32:59.537Z,1681493579.537 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-14T17:32:59.537Z,1681493579.537 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-14T17:33:01.552Z,1681493581.552 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173301.00,A,3648.19254,N,12147.92715,W,15.356,247.58,140423,,,D*4D
2023-04-14T17:33:01.554Z,1681493581.554 [NAL9602](INFO): GPS fix at 20230414T173301: (36.803209, -121.798786)
2023-04-14T17:33:01.567Z,1681493581.567 [Default:CheckIn:Read_GPS] Stopped
2023-04-14T17:33:01.567Z,1681493581.567 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-14T17:33:08.756Z,1681493588.756 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230414T164223/Courier0028.lzma
2023-04-14T17:33:09.759Z,1681493589.759 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Courier0028.lzma.bak
2023-04-14T17:33:09.759Z,1681493589.759 [DataOverHttps](INFO): SBD MOMSN=18221497
2023-04-14T17:33:20.132Z,1681493600.132 [NAL9602](INFO): SBD MO Status=0, MOMSN=11439, MT Status=0, MTMSN=0
2023-04-14T17:33:20.132Z,1681493600.132 [NAL9602](INFO): No messages in MT queue
2023-04-14T17:33:25.405Z,1681493605.405 [DataOverHttps](INFO): Sending 138 bytes from file Logs/20230414T164223/Express0029.lzma
2023-04-14T17:33:26.407Z,1681493606.407 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Express0029.lzma.bak
2023-04-14T17:33:26.407Z,1681493606.407 [DataOverHttps](INFO): SBD MOMSN=18221501
2023-04-14T17:33:27.448Z,1681493607.448 [Default:CheckIn:Read_Iridium] Stopped
2023-04-14T17:33:27.448Z,1681493607.448 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-14T17:33:27.448Z,1681493607.448 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-14T17:33:50.858Z,1681493630.858 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-14T17:38:28.042Z,1681493908.042 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-14T17:38:28.042Z,1681493908.042 [Default:CheckIn:C.Wait] Stopped
2023-04-14T17:38:28.042Z,1681493908.042 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-14T17:38:28.042Z,1681493908.042 [Default:CheckIn:D] Running Loop=1
2023-04-14T17:38:28.457Z,1681493908.457 [Default:CheckIn:D] Stopped
2023-04-14T17:38:28.458Z,1681493908.458 [Default:CheckIn:E] Running Loop=1
2023-04-14T17:38:28.855Z,1681493908.855 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 51.874833 min 
2023-04-14T17:38:28.856Z,1681493908.856 [Default:CheckIn:E] Stopped
2023-04-14T17:38:28.856Z,1681493908.856 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-14T17:38:28.856Z,1681493908.856 [Default:CheckIn] Stopped
2023-04-14T17:38:28.856Z,1681493908.856 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-14T17:38:28.856Z,1681493908.856 [Default:CheckIn](INFO): Running loop #9
2023-04-14T17:38:28.856Z,1681493908.856 [Default:CheckIn] Running Loop=9
2023-04-14T17:38:28.856Z,1681493908.856 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-14T17:38:28.856Z,1681493908.856 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-14T17:38:30.859Z,1681493910.859 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173830.00,A,3647.59847,N,12149.43119,W,9.914,250.18,140423,,,D*7C
2023-04-14T17:38:30.861Z,1681493910.861 [NAL9602](INFO): GPS fix at 20230414T173830: (36.793308, -121.823853)
2023-04-14T17:38:30.873Z,1681493910.873 [Default:CheckIn:Read_GPS] Stopped
2023-04-14T17:38:30.873Z,1681493910.873 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-14T17:38:39.380Z,1681493919.380 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230414T164223/Courier0031.lzma
2023-04-14T17:38:40.383Z,1681493920.383 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Courier0031.lzma.bak
2023-04-14T17:38:40.383Z,1681493920.383 [DataOverHttps](INFO): SBD MOMSN=18221532
2023-04-14T17:38:54.705Z,1681493934.705 [NAL9602](INFO): SBD MO Status=0, MOMSN=11440, MT Status=0, MTMSN=0
2023-04-14T17:38:54.705Z,1681493934.705 [NAL9602](INFO): No messages in MT queue
2023-04-14T17:39:12.181Z,1681493952.181 [DataOverHttps](INFO): Sending 143 bytes from file Logs/20230414T164223/Express0032.lzma
2023-04-14T17:39:13.183Z,1681493953.183 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Express0032.lzma.bak
2023-04-14T17:39:13.183Z,1681493953.183 [DataOverHttps](INFO): SBD MOMSN=18221536
2023-04-14T17:39:14.500Z,1681493954.500 [Default:CheckIn:Read_Iridium] Stopped
2023-04-14T17:39:14.500Z,1681493954.500 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-14T17:39:14.500Z,1681493954.500 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-14T17:39:25.402Z,1681493965.402 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-14T17:43:54.801Z,1681494234.801 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.987263
2023-04-14T17:44:15.150Z,1681494255.150 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-14T17:44:15.150Z,1681494255.150 [Default:CheckIn:C.Wait] Stopped
2023-04-14T17:44:15.150Z,1681494255.150 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-14T17:44:15.150Z,1681494255.150 [Default:CheckIn:D] Running Loop=1
2023-04-14T17:44:15.554Z,1681494255.554 [Default:CheckIn:D] Stopped
2023-04-14T17:44:15.554Z,1681494255.554 [Default:CheckIn:E] Running Loop=1
2023-04-14T17:44:15.966Z,1681494255.966 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 57.659782 min 
2023-04-14T17:44:15.966Z,1681494255.966 [Default:CheckIn:E] Stopped
2023-04-14T17:44:15.966Z,1681494255.966 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-14T17:44:15.966Z,1681494255.966 [Default:CheckIn] Stopped
2023-04-14T17:44:15.966Z,1681494255.966 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-14T17:44:15.966Z,1681494255.966 [Default:CheckIn](INFO): Running loop #10
2023-04-14T17:44:15.967Z,1681494255.967 [Default:CheckIn] Running Loop=10
2023-04-14T17:44:15.967Z,1681494255.967 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-14T17:44:15.967Z,1681494255.967 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-14T17:44:17.976Z,1681494257.976 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174417.00,A,3647.60672,N,12149.36363,W,0.816,41.76,140423,,,D*4D
2023-04-14T17:44:17.979Z,1681494257.979 [NAL9602](INFO): GPS fix at 20230414T174417: (36.793445, -121.822727)
2023-04-14T17:44:17.991Z,1681494257.991 [Default:CheckIn:Read_GPS] Stopped
2023-04-14T17:44:17.991Z,1681494257.991 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-14T17:44:40.497Z,1681494280.497 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002898
2023-04-14T17:44:41.852Z,1681494281.852 [NAL9602](INFO): SBD MO Status=2, MOMSN=11441, MT Status=2, MTMSN=0
2023-04-14T17:44:41.852Z,1681494281.852 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-04-14T17:44:48.780Z,1681494288.780 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230414T164223/Courier0034.lzma
2023-04-14T17:44:49.783Z,1681494289.783 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Courier0034.lzma.bak
2023-04-14T17:44:49.783Z,1681494289.783 [DataOverHttps](INFO): SBD MOMSN=18221577
2023-04-14T17:45:08.428Z,1681494308.428 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230414T164223/Express0035.lzma
2023-04-14T17:45:09.431Z,1681494309.431 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Express0035.lzma.bak
2023-04-14T17:45:09.431Z,1681494309.431 [DataOverHttps](INFO): SBD MOMSN=18221587
2023-04-14T17:45:10.543Z,1681494310.543 [Default:CheckIn:Read_Iridium] Stopped
2023-04-14T17:45:10.544Z,1681494310.544 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-14T17:45:10.544Z,1681494310.544 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-14T17:45:12.546Z,1681494312.546 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-14T17:50:11.204Z,1681494611.204 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-14T17:50:11.205Z,1681494611.205 [Default:CheckIn:C.Wait] Stopped
2023-04-14T17:50:11.205Z,1681494611.205 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-14T17:50:11.205Z,1681494611.205 [Default:CheckIn:D] Running Loop=1
2023-04-14T17:50:11.620Z,1681494611.620 [Default:CheckIn:D] Stopped
2023-04-14T17:50:11.621Z,1681494611.621 [Default:CheckIn:E] Running Loop=1
2023-04-14T17:50:12.001Z,1681494612.001 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 63.594218 min 
2023-04-14T17:50:12.001Z,1681494612.001 [Default:CheckIn:E] Stopped
2023-04-14T17:50:12.001Z,1681494612.001 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-14T17:50:12.002Z,1681494612.002 [Default:CheckIn] Stopped
2023-04-14T17:50:12.002Z,1681494612.002 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-14T17:50:12.002Z,1681494612.002 [Default:CheckIn](INFO): Running loop #11
2023-04-14T17:50:12.002Z,1681494612.002 [Default:CheckIn] Running Loop=11
2023-04-14T17:50:12.002Z,1681494612.002 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-14T17:50:12.002Z,1681494612.002 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-14T17:50:14.008Z,1681494614.008 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175013.00,A,3647.65662,N,12149.36174,W,0.991,72.28,140423,,,D*49
2023-04-14T17:50:14.011Z,1681494614.011 [NAL9602](INFO): GPS fix at 20230414T175013: (36.794277, -121.822696)
2023-04-14T17:50:14.023Z,1681494614.023 [Default:CheckIn:Read_GPS] Stopped
2023-04-14T17:50:14.023Z,1681494614.023 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-14T17:50:20.920Z,1681494620.920 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230414T164223/Courier0037.lzma
2023-04-14T17:50:21.923Z,1681494621.923 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Courier0037.lzma.bak
2023-04-14T17:50:21.923Z,1681494621.923 [DataOverHttps](INFO): SBD MOMSN=18221636
2023-04-14T17:50:28.555Z,1681494628.555 [NAL9602](INFO): SBD MO Status=1, MOMSN=11441, MT Status=0, MTMSN=0
2023-04-14T17:50:28.556Z,1681494628.556 [NAL9602](INFO): No messages in MT queue
2023-04-14T17:50:59.252Z,1681494659.252 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-14T17:51:52.830Z,1681494712.830 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.503304
2023-04-14T17:52:10.419Z,1681494730.419 [NAL9602](INFO): SBD MO Status=1, MOMSN=11442, MT Status=0, MTMSN=0
2023-04-14T17:52:10.469Z,1681494730.469 [NAL9602](INFO): Sent 128 bytes from file Logs/20230414T164223/Express0038.lzma
2023-04-14T17:52:10.469Z,1681494730.469 [NAL9602](INFO): Packets left to send: 0
2023-04-14T17:52:29.812Z,1681494749.812 [NAL9602](INFO): SBD MO Status=0, MOMSN=11443, MT Status=0, MTMSN=0
2023-04-14T17:52:29.900Z,1681494749.900 [Default:CheckIn:Read_Iridium] Stopped
2023-04-14T17:52:29.900Z,1681494749.900 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-14T17:52:29.900Z,1681494749.900 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-14T17:52:59.461Z,1681494779.461 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-04-14T17:53:00.512Z,1681494780.512 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-14T17:53:34.601Z,1681494814.601 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-04-14T17:53:56.969Z,1681494836.969 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002918
2023-04-14T17:57:30.401Z,1681495050.401 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-14T17:57:30.401Z,1681495050.401 [Default:CheckIn:C.Wait] Stopped
2023-04-14T17:57:30.401Z,1681495050.401 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-14T17:57:30.401Z,1681495050.401 [Default:CheckIn:D] Running Loop=1
2023-04-14T17:57:30.805Z,1681495050.805 [Default:CheckIn:D] Stopped
2023-04-14T17:57:30.805Z,1681495050.805 [Default:CheckIn:E] Running Loop=1
2023-04-14T17:57:31.206Z,1681495051.206 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 70.913965 min 
2023-04-14T17:57:31.206Z,1681495051.206 [Default:CheckIn:E] Stopped
2023-04-14T17:57:31.206Z,1681495051.206 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-14T17:57:31.206Z,1681495051.206 [Default:CheckIn] Stopped
2023-04-14T17:57:31.206Z,1681495051.206 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-14T17:57:31.207Z,1681495051.207 [Default:CheckIn](INFO): Running loop #12
2023-04-14T17:57:31.207Z,1681495051.207 [Default:CheckIn] Running Loop=12
2023-04-14T17:57:31.207Z,1681495051.207 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-14T17:57:31.207Z,1681495051.207 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-14T17:57:33.216Z,1681495053.216 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175733.00,A,3647.00680,N,12149.64247,W,22.179,192.23,140423,,,D*4D
2023-04-14T17:57:33.218Z,1681495053.218 [NAL9602](INFO): GPS fix at 20230414T175733: (36.783447, -121.827375)
2023-04-14T17:57:33.266Z,1681495053.266 [Default:CheckIn:Read_GPS] Stopped
2023-04-14T17:57:33.267Z,1681495053.267 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-14T17:57:43.484Z,1681495063.484 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230414T164223/Courier0040.lzma
2023-04-14T17:57:44.487Z,1681495064.487 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Courier0040.lzma.bak
2023-04-14T17:57:44.487Z,1681495064.487 [DataOverHttps](INFO): SBD MOMSN=18221681
2023-04-14T17:57:57.517Z,1681495077.517 [NAL9602](INFO): SBD MO Status=0, MOMSN=11444, MT Status=0, MTMSN=0
2023-04-14T17:57:57.517Z,1681495077.517 [NAL9602](INFO): No messages in MT queue
2023-04-14T17:58:00.281Z,1681495080.281 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20230414T164223/Express0041.lzma
2023-04-14T17:58:01.283Z,1681495081.283 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Express0041.lzma.bak
2023-04-14T17:58:01.283Z,1681495081.283 [DataOverHttps](INFO): SBD MOMSN=18221684
2023-04-14T17:58:02.371Z,1681495082.371 [Default:CheckIn:Read_Iridium] Stopped
2023-04-14T17:58:02.372Z,1681495082.372 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-14T17:58:02.372Z,1681495082.372 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-14T17:58:28.216Z,1681495108.216 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-14T18:03:02.982Z,1681495382.982 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-14T18:03:02.982Z,1681495382.982 [Default:CheckIn:C.Wait] Stopped
2023-04-14T18:03:02.982Z,1681495382.982 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-14T18:03:02.983Z,1681495382.983 [Default:CheckIn:D] Running Loop=1
2023-04-14T18:03:03.398Z,1681495383.398 [Default:CheckIn:D] Stopped
2023-04-14T18:03:03.398Z,1681495383.398 [Default:CheckIn:E] Running Loop=1
2023-04-14T18:03:03.794Z,1681495383.794 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 76.457170 min 
2023-04-14T18:03:03.794Z,1681495383.794 [Default:CheckIn:E] Stopped
2023-04-14T18:03:03.794Z,1681495383.794 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-14T18:03:03.794Z,1681495383.794 [Default:CheckIn] Stopped
2023-04-14T18:03:03.794Z,1681495383.794 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-14T18:03:03.794Z,1681495383.794 [Default:CheckIn](INFO): Running loop #13
2023-04-14T18:03:03.794Z,1681495383.794 [Default:CheckIn] Running Loop=13
2023-04-14T18:03:03.795Z,1681495383.795 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-14T18:03:03.795Z,1681495383.795 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-14T18:03:05.804Z,1681495385.804 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180305.00,A,3645.17257,N,12150.37458,W,22.685,199.69,140423,,,A*4E
2023-04-14T18:03:05.806Z,1681495385.806 [NAL9602](INFO): GPS fix at 20230414T180305: (36.752876, -121.839576)
2023-04-14T18:03:05.819Z,1681495385.819 [Default:CheckIn:Read_GPS] Stopped
2023-04-14T18:03:05.819Z,1681495385.819 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-14T18:03:12.692Z,1681495392.692 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230414T164223/Courier0043.lzma
2023-04-14T18:03:13.695Z,1681495393.695 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Courier0043.lzma.bak
2023-04-14T18:03:13.695Z,1681495393.695 [DataOverHttps](INFO): SBD MOMSN=18221690
2023-04-14T18:03:29.232Z,1681495409.232 [NAL9602](INFO): SBD MO Status=2, MOMSN=11445, MT Status=2, MTMSN=0
2023-04-14T18:03:29.232Z,1681495409.232 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-04-14T18:03:41.065Z,1681495421.065 [DataOverHttps](INFO): Sending 143 bytes from file Logs/20230414T164223/Express0044.lzma
2023-04-14T18:03:42.067Z,1681495422.067 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Express0044.lzma.bak
2023-04-14T18:03:42.067Z,1681495422.067 [DataOverHttps](INFO): SBD MOMSN=18221693
2023-04-14T18:03:43.439Z,1681495423.439 [Default:CheckIn:Read_Iridium] Stopped
2023-04-14T18:03:43.439Z,1681495423.439 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-14T18:03:43.439Z,1681495423.439 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-14T18:03:45.836Z,1681495425.836 [NAL9602](INFO): SBD MO Status=0, MOMSN=11445, MT Status=0, MTMSN=0
2023-04-14T18:03:45.836Z,1681495425.836 [NAL9602](INFO): No messages in MT queue
2023-04-14T18:04:16.542Z,1681495456.542 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-14T18:08:44.044Z,1681495724.044 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-14T18:08:44.045Z,1681495724.045 [Default:CheckIn:C.Wait] Stopped
2023-04-14T18:08:44.045Z,1681495724.045 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-14T18:08:44.045Z,1681495724.045 [Default:CheckIn:D] Running Loop=1
2023-04-14T18:08:44.453Z,1681495724.453 [Default:CheckIn:D] Stopped
2023-04-14T18:08:44.453Z,1681495724.453 [Default:CheckIn:E] Running Loop=1
2023-04-14T18:08:44.855Z,1681495724.855 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 82.141431 min 
2023-04-14T18:08:44.855Z,1681495724.855 [Default:CheckIn:E] Stopped
2023-04-14T18:08:44.855Z,1681495724.855 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-14T18:08:44.855Z,1681495724.855 [Default:CheckIn] Stopped
2023-04-14T18:08:44.855Z,1681495724.855 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-14T18:08:44.855Z,1681495724.855 [Default:CheckIn](INFO): Running loop #14
2023-04-14T18:08:44.855Z,1681495724.855 [Default:CheckIn] Running Loop=14
2023-04-14T18:08:44.855Z,1681495724.855 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-14T18:08:44.855Z,1681495724.855 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-14T18:08:46.863Z,1681495726.863 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180846.00,A,3643.09621,N,12151.26086,W,18.933,216.06,140423,,,A*4E
2023-04-14T18:08:46.876Z,1681495726.876 [NAL9602](INFO): GPS fix at 20230414T180846: (36.718270, -121.854348)
2023-04-14T18:08:46.888Z,1681495726.888 [Default:CheckIn:Read_GPS] Stopped
2023-04-14T18:08:46.888Z,1681495726.888 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-14T18:08:54.004Z,1681495734.004 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230414T164223/Courier0046.lzma
2023-04-14T18:08:55.007Z,1681495735.007 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Courier0046.lzma.bak
2023-04-14T18:08:55.007Z,1681495735.007 [DataOverHttps](INFO): SBD MOMSN=18221727
2023-04-14T18:09:10.611Z,1681495750.611 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20230414T164223/Express0047.lzma
2023-04-14T18:09:11.611Z,1681495751.611 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Express0047.lzma.bak
2023-04-14T18:09:11.611Z,1681495751.611 [DataOverHttps](INFO): SBD MOMSN=18221730
2023-04-14T18:09:12.750Z,1681495752.750 [Default:CheckIn:Read_Iridium] Stopped
2023-04-14T18:09:12.750Z,1681495752.750 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-14T18:09:12.750Z,1681495752.750 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-14T18:09:13.526Z,1681495753.526 [NAL9602](INFO): SBD MO Status=0, MOMSN=11446, MT Status=0, MTMSN=0
2023-04-14T18:09:13.527Z,1681495753.527 [NAL9602](INFO): No messages in MT queue
2023-04-14T18:09:44.228Z,1681495784.228 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-14T18:14:13.304Z,1681496053.304 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-14T18:14:13.304Z,1681496053.304 [Default:CheckIn:C.Wait] Stopped
2023-04-14T18:14:13.304Z,1681496053.304 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-14T18:14:13.304Z,1681496053.304 [Default:CheckIn:D] Running Loop=1
2023-04-14T18:14:13.710Z,1681496053.710 [Default:CheckIn:D] Stopped
2023-04-14T18:14:13.710Z,1681496053.710 [Default:CheckIn:E] Running Loop=1
2023-04-14T18:14:14.122Z,1681496054.122 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 87.629045 min 
2023-04-14T18:14:14.122Z,1681496054.122 [Default:CheckIn:E] Stopped
2023-04-14T18:14:14.122Z,1681496054.122 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-14T18:14:14.122Z,1681496054.122 [Default:CheckIn] Stopped
2023-04-14T18:14:14.123Z,1681496054.123 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-14T18:14:14.123Z,1681496054.123 [Default:CheckIn](INFO): Running loop #15
2023-04-14T18:14:14.123Z,1681496054.123 [Default:CheckIn] Running Loop=15
2023-04-14T18:14:14.123Z,1681496054.123 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-14T18:14:14.123Z,1681496054.123 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-14T18:14:16.128Z,1681496056.128 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181416.00,A,3640.94698,N,12152.03798,W,27.447,197.10,140423,,,A*40
2023-04-14T18:14:16.130Z,1681496056.130 [NAL9602](INFO): GPS fix at 20230414T181416: (36.682450, -121.867300)
2023-04-14T18:14:16.143Z,1681496056.143 [Default:CheckIn:Read_GPS] Stopped
2023-04-14T18:14:16.143Z,1681496056.143 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-14T18:14:23.048Z,1681496063.048 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230414T164223/Courier0049.lzma
2023-04-14T18:14:24.051Z,1681496064.051 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Courier0049.lzma.bak
2023-04-14T18:14:24.051Z,1681496064.051 [DataOverHttps](INFO): SBD MOMSN=18221745
2023-04-14T18:14:30.668Z,1681496070.668 [NAL9602](INFO): SBD MO Status=0, MOMSN=11447, MT Status=0, MTMSN=0
2023-04-14T18:14:30.668Z,1681496070.668 [NAL9602](INFO): No messages in MT queue
2023-04-14T18:14:39.960Z,1681496079.960 [DataOverHttps](INFO): Sending 143 bytes from file Logs/20230414T164223/Express0050.lzma
2023-04-14T18:14:40.963Z,1681496080.963 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Express0050.lzma.bak
2023-04-14T18:14:40.963Z,1681496080.963 [DataOverHttps](INFO): SBD MOMSN=18221748
2023-04-14T18:14:42.114Z,1681496082.114 [Default:CheckIn:Read_Iridium] Stopped
2023-04-14T18:14:42.114Z,1681496082.114 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-14T18:14:42.114Z,1681496082.114 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-14T18:15:01.374Z,1681496101.374 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-14T18:17:49.034Z,1681496269.034 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2023-04-14T18:17:49.036Z,1681496269.036 [BPC1](INFO): Received data from all battery sticks.
2023-04-14T18:19:42.631Z,1681496382.631 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-14T18:19:42.631Z,1681496382.631 [Default:CheckIn:C.Wait] Stopped
2023-04-14T18:19:42.631Z,1681496382.631 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-14T18:19:42.632Z,1681496382.632 [Default:CheckIn:D] Running Loop=1
2023-04-14T18:19:43.027Z,1681496383.027 [Default:CheckIn:D] Stopped
2023-04-14T18:19:43.027Z,1681496383.027 [Default:CheckIn:E] Running Loop=1
2023-04-14T18:19:43.443Z,1681496383.443 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 93.117668 min 
2023-04-14T18:19:43.443Z,1681496383.443 [Default:CheckIn:E] Stopped
2023-04-14T18:19:43.443Z,1681496383.443 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-14T18:19:43.443Z,1681496383.443 [Default:CheckIn] Stopped
2023-04-14T18:19:43.443Z,1681496383.443 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-14T18:19:43.443Z,1681496383.443 [Default:CheckIn](INFO): Running loop #16
2023-04-14T18:19:43.443Z,1681496383.443 [Default:CheckIn] Running Loop=16
2023-04-14T18:19:43.444Z,1681496383.444 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-14T18:19:43.444Z,1681496383.444 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-14T18:19:45.448Z,1681496385.448 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181945.00,A,3638.87930,N,12152.81721,W,1.672,100.74,140423,,,D*7A
2023-04-14T18:19:45.450Z,1681496385.450 [NAL9602](INFO): GPS fix at 20230414T181945: (36.647988, -121.880287)
2023-04-14T18:19:45.462Z,1681496385.462 [Default:CheckIn:Read_GPS] Stopped
2023-04-14T18:19:45.462Z,1681496385.462 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-14T18:19:52.620Z,1681496392.620 [DataOverHttps](INFO): Sending 84 bytes from file Logs/20230414T164223/Courier0052.lzma
2023-04-14T18:19:53.623Z,1681496393.623 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Courier0052.lzma.bak
2023-04-14T18:19:53.623Z,1681496393.623 [DataOverHttps](INFO): SBD MOMSN=18221763
2023-04-14T18:19:57.560Z,1681496397.560 [NAL9602](INFO): SBD MO Status=0, MOMSN=11448, MT Status=0, MTMSN=0
2023-04-14T18:19:57.560Z,1681496397.560 [NAL9602](INFO): No messages in MT queue
2023-04-14T18:20:09.209Z,1681496409.209 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20230414T164223/Express0053.lzma
2023-04-14T18:20:10.211Z,1681496410.211 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Express0053.lzma.bak
2023-04-14T18:20:10.211Z,1681496410.211 [DataOverHttps](INFO): SBD MOMSN=18221767
2023-04-14T18:20:11.316Z,1681496411.316 [Default:CheckIn:Read_Iridium] Stopped
2023-04-14T18:20:11.316Z,1681496411.316 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-14T18:20:11.316Z,1681496411.316 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-14T18:20:28.261Z,1681496428.261 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-14T18:25:11.881Z,1681496711.881 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-14T18:25:11.881Z,1681496711.881 [Default:CheckIn:C.Wait] Stopped
2023-04-14T18:25:11.881Z,1681496711.881 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-14T18:25:11.881Z,1681496711.881 [Default:CheckIn:D] Running Loop=1
2023-04-14T18:25:12.290Z,1681496712.290 [Default:CheckIn:D] Stopped
2023-04-14T18:25:12.290Z,1681496712.290 [Default:CheckIn:E] Running Loop=1
2023-04-14T18:25:12.688Z,1681496712.688 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 98.605387 min 
2023-04-14T18:25:12.688Z,1681496712.688 [Default:CheckIn:E] Stopped
2023-04-14T18:25:12.688Z,1681496712.688 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-14T18:25:12.688Z,1681496712.688 [Default:CheckIn] Stopped
2023-04-14T18:25:12.688Z,1681496712.688 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-14T18:25:12.688Z,1681496712.688 [Default:CheckIn](INFO): Running loop #17
2023-04-14T18:25:12.688Z,1681496712.688 [Default:CheckIn] Running Loop=17
2023-04-14T18:25:12.689Z,1681496712.689 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-14T18:25:12.689Z,1681496712.689 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-14T18:25:14.700Z,1681496714.700 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182514.00,A,3638.87216,N,12152.75363,W,1.166,109.07,140423,,,D*78
2023-04-14T18:25:14.702Z,1681496714.702 [NAL9602](INFO): GPS fix at 20230414T182514: (36.647869, -121.879227)
2023-04-14T18:25:14.714Z,1681496714.714 [Default:CheckIn:Read_GPS] Stopped
2023-04-14T18:25:14.714Z,1681496714.714 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-14T18:25:22.320Z,1681496722.320 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230414T164223/Courier0055.lzma
2023-04-14T18:25:23.323Z,1681496723.323 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Courier0055.lzma.bak
2023-04-14T18:25:23.323Z,1681496723.323 [DataOverHttps](INFO): SBD MOMSN=18221782
2023-04-14T18:25:35.724Z,1681496735.724 [NAL9602](INFO): SBD MO Status=0, MOMSN=11449, MT Status=0, MTMSN=0
2023-04-14T18:25:35.724Z,1681496735.724 [NAL9602](INFO): No messages in MT queue
2023-04-14T18:25:41.460Z,1681496741.460 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230414T164223/Express0056.lzma
2023-04-14T18:25:42.466Z,1681496742.466 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Express0056.lzma.bak
2023-04-14T18:25:42.467Z,1681496742.467 [DataOverHttps](INFO): SBD MOMSN=18221785
2023-04-14T18:25:43.854Z,1681496743.854 [Default:CheckIn:Read_Iridium] Stopped
2023-04-14T18:25:43.854Z,1681496743.854 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-14T18:25:43.855Z,1681496743.855 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-14T18:26:06.456Z,1681496766.456 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-14T18:30:44.469Z,1681497044.469 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-14T18:30:44.469Z,1681497044.469 [Default:CheckIn:C.Wait] Stopped
2023-04-14T18:30:44.469Z,1681497044.469 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-14T18:30:44.469Z,1681497044.469 [Default:CheckIn:D] Running Loop=1
2023-04-14T18:30:44.868Z,1681497044.868 [Default:CheckIn:D] Stopped
2023-04-14T18:30:44.868Z,1681497044.868 [Default:CheckIn:E] Running Loop=1
2023-04-14T18:30:45.274Z,1681497045.274 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 104.148340 min 
2023-04-14T18:30:45.275Z,1681497045.275 [Default:CheckIn:E] Stopped
2023-04-14T18:30:45.275Z,1681497045.275 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-14T18:30:45.275Z,1681497045.275 [Default:CheckIn] Stopped
2023-04-14T18:30:45.275Z,1681497045.275 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-14T18:30:45.275Z,1681497045.275 [Default:CheckIn](INFO): Running loop #18
2023-04-14T18:30:45.275Z,1681497045.275 [Default:CheckIn] Running Loop=18
2023-04-14T18:30:45.275Z,1681497045.275 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-14T18:30:45.275Z,1681497045.275 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-14T18:30:47.284Z,1681497047.284 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183047.00,A,3638.86207,N,12152.69262,W,0.583,112.66,140423,,,D*75
2023-04-14T18:30:47.286Z,1681497047.286 [NAL9602](INFO): GPS fix at 20230414T183047: (36.647701, -121.878210)
2023-04-14T18:30:47.316Z,1681497047.316 [Default:CheckIn:Read_GPS] Stopped
2023-04-14T18:30:47.316Z,1681497047.316 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-14T18:30:54.240Z,1681497054.240 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230414T164223/Courier0058.lzma
2023-04-14T18:30:55.243Z,1681497055.243 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Courier0058.lzma.bak
2023-04-14T18:30:55.243Z,1681497055.243 [DataOverHttps](INFO): SBD MOMSN=18221822
2023-04-14T18:31:05.063Z,1681497065.063 [NAL9602](INFO): SBD MO Status=0, MOMSN=11450, MT Status=0, MTMSN=0
2023-04-14T18:31:05.064Z,1681497065.064 [NAL9602](INFO): No messages in MT queue
2023-04-14T18:31:10.849Z,1681497070.849 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230414T164223/Express0059.lzma
2023-04-14T18:31:11.851Z,1681497071.851 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Express0059.lzma.bak
2023-04-14T18:31:11.851Z,1681497071.851 [DataOverHttps](INFO): SBD MOMSN=18221827
2023-04-14T18:31:13.163Z,1681497073.163 [Default:CheckIn:Read_Iridium] Stopped
2023-04-14T18:31:13.163Z,1681497073.163 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-14T18:31:13.163Z,1681497073.163 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-14T18:31:35.762Z,1681497095.762 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-14T18:36:13.765Z,1681497373.765 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-14T18:36:13.765Z,1681497373.765 [Default:CheckIn:C.Wait] Stopped
2023-04-14T18:36:13.765Z,1681497373.765 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-14T18:36:13.765Z,1681497373.765 [Default:CheckIn:D] Running Loop=1
2023-04-14T18:36:14.180Z,1681497374.180 [Default:CheckIn:D] Stopped
2023-04-14T18:36:14.180Z,1681497374.180 [Default:CheckIn:E] Running Loop=1
2023-04-14T18:36:14.590Z,1681497374.590 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 109.636873 min 
2023-04-14T18:36:14.590Z,1681497374.590 [Default:CheckIn:E] Stopped
2023-04-14T18:36:14.590Z,1681497374.590 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-14T18:36:14.591Z,1681497374.591 [Default:CheckIn] Stopped
2023-04-14T18:36:14.591Z,1681497374.591 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-14T18:36:14.591Z,1681497374.591 [Default:CheckIn](INFO): Running loop #19
2023-04-14T18:36:14.591Z,1681497374.591 [Default:CheckIn] Running Loop=19
2023-04-14T18:36:14.591Z,1681497374.591 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-14T18:36:14.591Z,1681497374.591 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-14T18:36:16.588Z,1681497376.588 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183616.00,A,3638.85170,N,12152.62897,W,0.719,98.56,140423,,,D*4D
2023-04-14T18:36:16.590Z,1681497376.590 [NAL9602](INFO): GPS fix at 20230414T183616: (36.647528, -121.877150)
2023-04-14T18:36:16.620Z,1681497376.620 [Default:CheckIn:Read_GPS] Stopped
2023-04-14T18:36:16.620Z,1681497376.620 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-14T18:36:23.524Z,1681497383.524 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230414T164223/Courier0061.lzma
2023-04-14T18:36:24.527Z,1681497384.527 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Courier0061.lzma.bak
2023-04-14T18:36:24.527Z,1681497384.527 [DataOverHttps](INFO): SBD MOMSN=18221834
2023-04-14T18:36:33.956Z,1681497393.956 [NAL9602](INFO): SBD MO Status=0, MOMSN=11451, MT Status=0, MTMSN=0
2023-04-14T18:36:33.957Z,1681497393.957 [NAL9602](INFO): No messages in MT queue
2023-04-14T18:36:40.304Z,1681497400.304 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230414T164223/Express0062.lzma
2023-04-14T18:36:41.307Z,1681497401.307 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Express0062.lzma.bak
2023-04-14T18:36:41.307Z,1681497401.307 [DataOverHttps](INFO): SBD MOMSN=18221841
2023-04-14T18:36:42.450Z,1681497402.450 [Default:CheckIn:Read_Iridium] Stopped
2023-04-14T18:36:42.450Z,1681497402.450 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-14T18:36:42.450Z,1681497402.450 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-14T18:37:04.656Z,1681497424.656 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-14T18:41:43.040Z,1681497703.040 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-14T18:41:43.041Z,1681497703.041 [Default:CheckIn:C.Wait] Stopped
2023-04-14T18:41:43.041Z,1681497703.041 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-14T18:41:43.041Z,1681497703.041 [Default:CheckIn:D] Running Loop=1
2023-04-14T18:41:43.429Z,1681497703.429 [Default:CheckIn:D] Stopped
2023-04-14T18:41:43.429Z,1681497703.429 [Default:CheckIn:E] Running Loop=1
2023-04-14T18:41:43.834Z,1681497703.834 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 115.124357 min 
2023-04-14T18:41:43.834Z,1681497703.834 [Default:CheckIn:E] Stopped
2023-04-14T18:41:43.834Z,1681497703.834 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-14T18:41:43.834Z,1681497703.834 [Default:CheckIn] Stopped
2023-04-14T18:41:43.834Z,1681497703.834 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-14T18:41:43.835Z,1681497703.835 [Default:CheckIn](INFO): Running loop #20
2023-04-14T18:41:43.835Z,1681497703.835 [Default:CheckIn] Running Loop=20
2023-04-14T18:41:43.835Z,1681497703.835 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-14T18:41:43.835Z,1681497703.835 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-14T18:41:45.844Z,1681497705.844 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184145.00,A,3638.83910,N,12152.55145,W,1.011,104.01,140423,,,D*79
2023-04-14T18:41:45.847Z,1681497705.847 [NAL9602](INFO): GPS fix at 20230414T184145: (36.647318, -121.875857)
2023-04-14T18:41:45.859Z,1681497705.859 [Default:CheckIn:Read_GPS] Stopped
2023-04-14T18:41:45.859Z,1681497705.859 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-14T18:41:54.364Z,1681497714.364 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230414T164223/Courier0064.lzma
2023-04-14T18:41:57.375Z,1681497717.375 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Courier0064.lzma.bak
2023-04-14T18:41:57.375Z,1681497717.375 [DataOverHttps](INFO): SBD MOMSN=18221854
2023-04-14T18:42:01.600Z,1681497721.600 [NAL9602](INFO): SBD MO Status=0, MOMSN=11452, MT Status=0, MTMSN=0
2023-04-14T18:42:01.600Z,1681497721.600 [NAL9602](INFO): No messages in MT queue
2023-04-14T18:42:13.064Z,1681497733.064 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20230414T164223/Express0065.lzma
2023-04-14T18:42:14.067Z,1681497734.067 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Express0065.lzma.bak
2023-04-14T18:42:14.067Z,1681497734.067 [DataOverHttps](INFO): SBD MOMSN=18221860
2023-04-14T18:42:15.351Z,1681497735.351 [Default:CheckIn:Read_Iridium] Stopped
2023-04-14T18:42:15.351Z,1681497735.351 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-14T18:42:15.351Z,1681497735.351 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-14T18:42:32.306Z,1681497752.306 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-14T18:47:15.925Z,1681498035.925 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-14T18:47:15.925Z,1681498035.925 [Default:CheckIn:C.Wait] Stopped
2023-04-14T18:47:15.925Z,1681498035.925 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-14T18:47:15.925Z,1681498035.925 [Default:CheckIn:D] Running Loop=1
2023-04-14T18:47:16.327Z,1681498036.327 [Default:CheckIn:D] Stopped
2023-04-14T18:47:16.327Z,1681498036.327 [Default:CheckIn:E] Running Loop=1
2023-04-14T18:47:16.737Z,1681498036.737 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 120.672656 min 
2023-04-14T18:47:16.737Z,1681498036.737 [Default:CheckIn:E] Stopped
2023-04-14T18:47:16.737Z,1681498036.737 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-14T18:47:16.737Z,1681498036.737 [Default:CheckIn] Stopped
2023-04-14T18:47:16.737Z,1681498036.737 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-14T18:47:16.737Z,1681498036.737 [Default:CheckIn](INFO): Running loop #21
2023-04-14T18:47:16.737Z,1681498036.737 [Default:CheckIn] Running Loop=21
2023-04-14T18:47:16.738Z,1681498036.738 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-14T18:47:16.738Z,1681498036.738 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-14T18:47:18.744Z,1681498038.744 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184718.00,A,3638.86939,N,12152.60260,W,0.875,270.57,140423,,,D*73
2023-04-14T18:47:18.746Z,1681498038.746 [NAL9602](INFO): GPS fix at 20230414T184718: (36.647823, -121.876710)
2023-04-14T18:47:18.778Z,1681498038.778 [Default:CheckIn:Read_GPS] Stopped
2023-04-14T18:47:18.778Z,1681498038.778 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-14T18:47:25.752Z,1681498045.752 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230414T164223/Courier0067.lzma
2023-04-14T18:47:26.755Z,1681498046.755 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Courier0067.lzma.bak
2023-04-14T18:47:26.755Z,1681498046.755 [DataOverHttps](INFO): SBD MOMSN=18221870
2023-04-14T18:47:29.248Z,1681498049.248 [NAL9602](INFO): SBD MO Status=0, MOMSN=11453, MT Status=0, MTMSN=0
2023-04-14T18:47:29.248Z,1681498049.248 [NAL9602](INFO): No messages in MT queue
2023-04-14T18:47:56.885Z,1681498076.885 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230414T164223/Express0068.lzma
2023-04-14T18:47:57.887Z,1681498077.887 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Express0068.lzma.bak
2023-04-14T18:47:57.887Z,1681498077.887 [DataOverHttps](INFO): SBD MOMSN=18221876
2023-04-14T18:47:58.920Z,1681498078.920 [Default:CheckIn:Read_Iridium] Stopped
2023-04-14T18:47:58.920Z,1681498078.920 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-14T18:47:58.920Z,1681498078.920 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-14T18:47:59.690Z,1681498079.690 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-14T18:52:59.523Z,1681498379.523 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-14T18:52:59.523Z,1681498379.523 [Default:CheckIn:C.Wait] Stopped
2023-04-14T18:52:59.523Z,1681498379.523 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-14T18:52:59.523Z,1681498379.523 [Default:CheckIn:D] Running Loop=1
2023-04-14T18:52:59.916Z,1681498379.916 [Default:CheckIn:D] Stopped
2023-04-14T18:52:59.916Z,1681498379.916 [Default:CheckIn:E] Running Loop=1
2023-04-14T18:53:00.322Z,1681498380.322 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 126.399146 min 
2023-04-14T18:53:00.322Z,1681498380.322 [Default:CheckIn:E] Stopped
2023-04-14T18:53:00.322Z,1681498380.322 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-14T18:53:00.322Z,1681498380.322 [Default:CheckIn] Stopped
2023-04-14T18:53:00.323Z,1681498380.323 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-14T18:53:00.323Z,1681498380.323 [Default:CheckIn](INFO): Running loop #22
2023-04-14T18:53:00.323Z,1681498380.323 [Default:CheckIn] Running Loop=22
2023-04-14T18:53:00.323Z,1681498380.323 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-14T18:53:00.323Z,1681498380.323 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-14T18:53:02.333Z,1681498382.333 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185302.00,A,3638.86589,N,12152.55783,W,0.855,118.36,140423,,,D*7C
2023-04-14T18:53:02.335Z,1681498382.335 [NAL9602](INFO): GPS fix at 20230414T185302: (36.647765, -121.875964)
2023-04-14T18:53:02.348Z,1681498382.348 [Default:CheckIn:Read_GPS] Stopped
2023-04-14T18:53:02.348Z,1681498382.348 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-14T18:53:09.628Z,1681498389.628 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230414T164223/Courier0070.lzma
2023-04-14T18:53:10.631Z,1681498390.631 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Courier0070.lzma.bak
2023-04-14T18:53:10.631Z,1681498390.631 [DataOverHttps](INFO): SBD MOMSN=18221892
2023-04-14T18:53:26.300Z,1681498406.300 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230414T164223/Express0071.lzma
2023-04-14T18:53:28.307Z,1681498408.307 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Express0071.lzma.bak
2023-04-14T18:53:28.307Z,1681498408.307 [DataOverHttps](INFO): SBD MOMSN=18221903
2023-04-14T18:53:29.415Z,1681498409.415 [Default:CheckIn:Read_Iridium] Stopped
2023-04-14T18:53:29.415Z,1681498409.415 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-14T18:53:29.415Z,1681498409.415 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-14T18:53:30.616Z,1681498410.616 [NAL9602](INFO): SBD MO Status=2, MOMSN=11454, MT Status=2, MTMSN=0
2023-04-14T18:53:30.616Z,1681498410.616 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-04-14T18:53:43.988Z,1681498423.988 [NAL9602](INFO): SBD MO Status=0, MOMSN=11454, MT Status=0, MTMSN=0
2023-04-14T18:53:43.988Z,1681498423.988 [NAL9602](INFO): No messages in MT queue
2023-04-14T18:54:14.690Z,1681498454.690 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-14T18:58:30.035Z,1681498710.035 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-14T18:58:30.035Z,1681498710.035 [Default:CheckIn:C.Wait] Stopped
2023-04-14T18:58:30.035Z,1681498710.035 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-14T18:58:30.035Z,1681498710.035 [Default:CheckIn:D] Running Loop=1
2023-04-14T18:58:30.427Z,1681498710.427 [Default:CheckIn:D] Stopped
2023-04-14T18:58:30.427Z,1681498710.427 [Default:CheckIn:E] Running Loop=1
2023-04-14T18:58:30.833Z,1681498710.833 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 131.907666 min 
2023-04-14T18:58:30.833Z,1681498710.833 [Default:CheckIn:E] Stopped
2023-04-14T18:58:30.833Z,1681498710.833 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-14T18:58:30.833Z,1681498710.833 [Default:CheckIn] Stopped
2023-04-14T18:58:30.834Z,1681498710.834 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-14T18:58:30.834Z,1681498710.834 [Default:CheckIn](INFO): Running loop #23
2023-04-14T18:58:30.834Z,1681498710.834 [Default:CheckIn] Running Loop=23
2023-04-14T18:58:30.834Z,1681498710.834 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-14T18:58:30.834Z,1681498710.834 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-14T18:58:32.848Z,1681498712.848 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185832.00,A,3638.85444,N,12152.50470,W,0.700,98.86,140423,,,D*40
2023-04-14T18:58:32.850Z,1681498712.850 [NAL9602](INFO): GPS fix at 20230414T185832: (36.647574, -121.875078)
2023-04-14T18:58:32.863Z,1681498712.863 [Default:CheckIn:Read_GPS] Stopped
2023-04-14T18:58:32.863Z,1681498712.863 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-14T18:58:40.092Z,1681498720.092 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230414T164223/Courier0073.lzma
2023-04-14T18:58:41.095Z,1681498721.095 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Courier0073.lzma.bak
2023-04-14T18:58:41.095Z,1681498721.095 [DataOverHttps](INFO): SBD MOMSN=18221928
2023-04-14T18:58:45.372Z,1681498725.372 [NAL9602](INFO): SBD MO Status=0, MOMSN=11455, MT Status=0, MTMSN=0
2023-04-14T18:58:45.372Z,1681498725.372 [NAL9602](INFO): No messages in MT queue
2023-04-14T18:58:56.928Z,1681498736.928 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230414T164223/Express0074.lzma
2023-04-14T18:58:57.931Z,1681498737.931 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Express0074.lzma.bak
2023-04-14T18:58:57.931Z,1681498737.931 [DataOverHttps](INFO): SBD MOMSN=18221938
2023-04-14T18:58:59.122Z,1681498739.122 [Default:CheckIn:Read_Iridium] Stopped
2023-04-14T18:58:59.122Z,1681498739.122 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-14T18:58:59.122Z,1681498739.122 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-14T18:59:16.078Z,1681498756.078 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-14T19:03:59.745Z,1681499039.745 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-14T19:03:59.745Z,1681499039.745 [Default:CheckIn:C.Wait] Stopped
2023-04-14T19:03:59.745Z,1681499039.745 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-14T19:03:59.745Z,1681499039.745 [Default:CheckIn:D] Running Loop=1
2023-04-14T19:04:00.148Z,1681499040.148 [Default:CheckIn:D] Stopped
2023-04-14T19:04:00.148Z,1681499040.148 [Default:CheckIn:E] Running Loop=1
2023-04-14T19:04:00.555Z,1681499040.555 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 137.403011 min 
2023-04-14T19:04:00.555Z,1681499040.555 [Default:CheckIn:E] Stopped
2023-04-14T19:04:00.555Z,1681499040.555 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-14T19:04:00.555Z,1681499040.555 [Default:CheckIn] Stopped
2023-04-14T19:04:00.555Z,1681499040.555 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-14T19:04:00.555Z,1681499040.555 [Default:CheckIn](INFO): Running loop #24
2023-04-14T19:04:00.555Z,1681499040.555 [Default:CheckIn] Running Loop=24
2023-04-14T19:04:00.555Z,1681499040.555 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-14T19:04:00.555Z,1681499040.555 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-14T19:04:02.564Z,1681499042.564 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190402.00,A,3638.85017,N,12152.47170,W,0.505,77.75,140423,,,D*40
2023-04-14T19:04:02.566Z,1681499042.566 [NAL9602](INFO): GPS fix at 20230414T190402: (36.647503, -121.874528)
2023-04-14T19:04:02.596Z,1681499042.596 [Default:CheckIn:Read_GPS] Stopped
2023-04-14T19:04:02.596Z,1681499042.596 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-14T19:04:09.500Z,1681499049.500 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230414T164223/Courier0076.lzma
2023-04-14T19:04:10.503Z,1681499050.503 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Courier0076.lzma.bak
2023-04-14T19:04:10.503Z,1681499050.503 [DataOverHttps](INFO): SBD MOMSN=18221962
2023-04-14T19:04:26.256Z,1681499066.256 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230414T164223/Express0077.lzma
2023-04-14T19:04:27.259Z,1681499067.259 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Express0077.lzma.bak
2023-04-14T19:04:27.259Z,1681499067.259 [DataOverHttps](INFO): SBD MOMSN=18221968
2023-04-14T19:04:27.621Z,1681499067.621 [NAL9602](INFO): SBD MO Status=0, MOMSN=11456, MT Status=0, MTMSN=0
2023-04-14T19:04:27.621Z,1681499067.621 [NAL9602](INFO): No messages in MT queue
2023-04-14T19:04:28.429Z,1681499068.429 [Default:CheckIn:Read_Iridium] Stopped
2023-04-14T19:04:28.430Z,1681499068.430 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-14T19:04:28.430Z,1681499068.430 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-14T19:04:58.322Z,1681499098.322 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-14T19:09:29.008Z,1681499369.008 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-14T19:09:29.008Z,1681499369.008 [Default:CheckIn:C.Wait] Stopped
2023-04-14T19:09:29.008Z,1681499369.008 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-14T19:09:29.008Z,1681499369.008 [Default:CheckIn:D] Running Loop=1
2023-04-14T19:09:29.414Z,1681499369.414 [Default:CheckIn:D] Stopped
2023-04-14T19:09:29.414Z,1681499369.414 [Default:CheckIn:E] Running Loop=1
2023-04-14T19:09:29.829Z,1681499369.829 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 142.890771 min 
2023-04-14T19:09:29.829Z,1681499369.829 [Default:CheckIn:E] Stopped
2023-04-14T19:09:29.830Z,1681499369.830 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-14T19:09:29.830Z,1681499369.830 [Default:CheckIn] Stopped
2023-04-14T19:09:29.830Z,1681499369.830 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-14T19:09:29.830Z,1681499369.830 [Default:CheckIn](INFO): Running loop #25
2023-04-14T19:09:29.830Z,1681499369.830 [Default:CheckIn] Running Loop=25
2023-04-14T19:09:29.830Z,1681499369.830 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-14T19:09:29.830Z,1681499369.830 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-14T19:09:31.828Z,1681499371.828 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190931.00,A,3638.85290,N,12152.43177,W,0.214,41.18,140423,,,A*4F
2023-04-14T19:09:31.831Z,1681499371.831 [NAL9602](INFO): GPS fix at 20230414T190931: (36.647548, -121.873863)
2023-04-14T19:09:31.880Z,1681499371.880 [Default:CheckIn:Read_GPS] Stopped
2023-04-14T19:09:31.880Z,1681499371.880 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-14T19:09:43.124Z,1681499383.124 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230414T164223/Courier0079.lzma
2023-04-14T19:09:44.127Z,1681499384.127 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Courier0079.lzma.bak
2023-04-14T19:09:44.127Z,1681499384.127 [DataOverHttps](INFO): SBD MOMSN=18221980
2023-04-14T19:09:56.932Z,1681499396.931 [NAL9602](INFO): SBD MO Status=2, MOMSN=11457, MT Status=2, MTMSN=0
2023-04-14T19:09:56.932Z,1681499396.932 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-04-14T19:10:02.932Z,1681499402.932 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230414T164223/Express0080.lzma
2023-04-14T19:10:03.935Z,1681499403.935 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Express0080.lzma.bak
2023-04-14T19:10:03.935Z,1681499403.935 [DataOverHttps](INFO): SBD MOMSN=18221988
2023-04-14T19:10:05.032Z,1681499405.032 [Default:CheckIn:Read_Iridium] Stopped
2023-04-14T19:10:05.033Z,1681499405.033 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-14T19:10:05.033Z,1681499405.033 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-14T19:10:06.224Z,1681499406.224 [NAL9602](INFO): SBD MO Status=0, MOMSN=11457, MT Status=0, MTMSN=0
2023-04-14T19:10:06.224Z,1681499406.224 [NAL9602](INFO): No messages in MT queue
2023-04-14T19:10:36.927Z,1681499436.927 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-14T19:15:05.604Z,1681499705.604 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-14T19:15:05.604Z,1681499705.604 [Default:CheckIn:C.Wait] Stopped
2023-04-14T19:15:05.604Z,1681499705.604 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-14T19:15:05.604Z,1681499705.604 [Default:CheckIn:D] Running Loop=1
2023-04-14T19:15:06.018Z,1681499706.018 [Default:CheckIn:D] Stopped
2023-04-14T19:15:06.018Z,1681499706.018 [Default:CheckIn:E] Running Loop=1
2023-04-14T19:15:06.418Z,1681499706.418 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 148.500846 min 
2023-04-14T19:15:06.418Z,1681499706.418 [Default:CheckIn:E] Stopped
2023-04-14T19:15:06.418Z,1681499706.418 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-14T19:15:06.418Z,1681499706.418 [Default:CheckIn] Stopped
2023-04-14T19:15:06.418Z,1681499706.418 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-14T19:15:06.419Z,1681499706.419 [Default:CheckIn](INFO): Running loop #26
2023-04-14T19:15:06.419Z,1681499706.419 [Default:CheckIn] Running Loop=26
2023-04-14T19:15:06.419Z,1681499706.419 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-14T19:15:06.419Z,1681499706.419 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-14T19:15:08.424Z,1681499708.424 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191508.00,A,3638.97368,N,12152.85487,W,4.840,241.08,140423,,,A*71
2023-04-14T19:15:08.426Z,1681499708.426 [NAL9602](INFO): GPS fix at 20230414T191508: (36.649561, -121.880915)
2023-04-14T19:15:08.459Z,1681499708.459 [Default:CheckIn:Read_GPS] Stopped
2023-04-14T19:15:08.459Z,1681499708.459 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-14T19:15:16.516Z,1681499716.516 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230414T164223/Courier0082.lzma
2023-04-14T19:15:17.519Z,1681499717.519 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Courier0082.lzma.bak
2023-04-14T19:15:17.519Z,1681499717.519 [DataOverHttps](INFO): SBD MOMSN=18222002
2023-04-14T19:15:24.584Z,1681499724.584 [NAL9602](INFO): SBD MO Status=0, MOMSN=11458, MT Status=0, MTMSN=0
2023-04-14T19:15:24.584Z,1681499724.584 [NAL9602](INFO): No messages in MT queue
2023-04-14T19:15:34.033Z,1681499734.033 [DataOverHttps](INFO): Sending 138 bytes from file Logs/20230414T164223/Express0083.lzma
2023-04-14T19:15:35.035Z,1681499735.035 [DataOverHttps](INFO): Moved sent file to Logs/20230414T164223/Express0083.lzma.bak
2023-04-14T19:15:35.035Z,1681499735.035 [DataOverHttps](INFO): SBD MOMSN=18222008
2023-04-14T19:15:36.326Z,1681499736.326 [Default:CheckIn:Read_Iridium] Stopped
2023-04-14T19:15:36.326Z,1681499736.326 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-14T19:15:36.327Z,1681499736.327 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-14T19:15:55.288Z,1681499755.288 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-14T19:19:16.122Z,1681499956.122 [DataOverHttps](IMPORTANT): SBD MTMSN=20230414T191915
2023-04-14T19:19:23.445Z,1681499963.445 [DataOverHttps](INFO): Received command: restart logs