2023-07-31T17:09:24.246Z,1690823364.246 [Supervisor](DEBUG): Initializing supervisor.
2023-07-31T17:09:24.250Z,1690823364.250 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2023-07-31T17:09:24.250Z,1690823364.250 [SyncHandler](INFO): Protected caller Thread ID is 8784
2023-07-31T17:09:24.251Z,1690823364.251 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2023-07-31T17:09:24.252Z,1690823364.252 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2023-07-31T17:09:24.252Z,1690823364.252 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 8785
2023-07-31T17:09:24.256Z,1690823364.256 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2023-07-31T17:09:24.273Z,1690823364.273 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2023-07-31T17:09:24.274Z,1690823364.274 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2023-07-31T17:09:24.274Z,1690823364.274 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 8786
2023-07-31T17:09:24.278Z,1690823364.278 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2023-07-31T17:09:24.280Z,1690823364.280 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2023-07-31T17:09:24.280Z,1690823364.280 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 8787
2023-07-31T17:09:24.282Z,1690823364.282 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2023-07-31T17:09:24.283Z,1690823364.283 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2023-07-31T17:09:24.283Z,1690823364.283 [logger ThreadHandler](INFO): Protected caller Thread ID is 8788
2023-07-31T17:09:24.287Z,1690823364.287 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2023-07-31T17:09:24.287Z,1690823364.287 [Supervisor](INFO): Looking for Config files in directory: Config/
2023-07-31T17:09:24.289Z,1690823364.289 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2023-07-31T17:09:24.549Z,1690823364.549 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2023-07-31T17:09:24.549Z,1690823364.549 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2023-07-31T17:09:24.630Z,1690823364.630 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2023-07-31T17:09:25.082Z,1690823365.082 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2023-07-31T17:09:25.082Z,1690823365.082 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2023-07-31T17:09:25.391Z,1690823365.391 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2023-07-31T17:09:25.392Z,1690823365.392 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2023-07-31T17:09:25.488Z,1690823365.488 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2023-07-31T17:09:25.488Z,1690823365.488 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2023-07-31T17:09:25.863Z,1690823365.863 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2023-07-31T17:09:25.864Z,1690823365.864 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2023-07-31T17:09:26.069Z,1690823366.069 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2023-07-31T17:09:26.070Z,1690823366.070 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2023-07-31T17:09:26.573Z,1690823366.573 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2023-07-31T17:09:26.573Z,1690823366.573 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2023-07-31T17:09:26.706Z,1690823366.706 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2023-07-31T17:09:26.707Z,1690823366.707 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2023-07-31T17:09:26.839Z,1690823366.839 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2023-07-31T17:09:27.946Z,1690823367.946 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2023-07-31T17:09:27.947Z,1690823367.947 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2023-07-31T17:09:28.300Z,1690823368.300 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2023-07-31T17:09:28.300Z,1690823368.300 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2023-07-31T17:09:28.479Z,1690823368.479 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2023-07-31T17:09:28.480Z,1690823368.480 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2023-07-31T17:09:28.591Z,1690823368.591 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2023-07-31T17:09:28.591Z,1690823368.591 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2023-07-31T17:09:28.815Z,1690823368.815 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2023-07-31T17:09:28.815Z,1690823368.815 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2023-07-31T17:09:29.045Z,1690823369.045 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2023-07-31T17:09:29.047Z,1690823369.047 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2023-07-31T17:09:29.048Z,1690823369.048 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2023-07-31T17:09:29.138Z,1690823369.138 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2023-07-31T17:09:29.224Z,1690823369.224 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2023-07-31T17:09:29.323Z,1690823369.323 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2023-07-31T17:09:29.407Z,1690823369.407 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2023-07-31T17:09:29.509Z,1690823369.509 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2023-07-31T17:09:29.609Z,1690823369.609 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2023-07-31T17:09:29.720Z,1690823369.720 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2023-07-31T17:09:29.798Z,1690823369.798 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2023-07-31T17:09:29.945Z,1690823369.945 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2023-07-31T17:09:30.083Z,1690823370.083 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2023-07-31T17:09:30.193Z,1690823370.193 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2023-07-31T17:09:30.459Z,1690823370.459 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2023-07-31T17:09:30.461Z,1690823370.461 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/
2023-07-31T17:09:30.461Z,1690823370.461 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2023-07-31T17:09:30.471Z,1690823370.471 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2023-07-31T17:09:30.521Z,1690823370.521 [VerticalControl](DEBUG): Construct VerticalControl.
2023-07-31T17:09:30.579Z,1690823370.579 [VerticalControl] Loaded
2023-07-31T17:09:30.579Z,1690823370.579 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2023-07-31T17:09:30.582Z,1690823370.582 [HorizontalControl](DEBUG): Construct HorizontalControl.
2023-07-31T17:09:30.622Z,1690823370.622 [HorizontalControl] Loaded
2023-07-31T17:09:30.622Z,1690823370.622 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2023-07-31T17:09:30.624Z,1690823370.624 [SpeedControl](DEBUG): Construct SpeedControl.
2023-07-31T17:09:30.627Z,1690823370.627 [SpeedControl] Loaded
2023-07-31T17:09:30.627Z,1690823370.627 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2023-07-31T17:09:30.630Z,1690823370.630 [LoopControl](DEBUG): Construct LoopControl.
2023-07-31T17:09:30.630Z,1690823370.630 [LoopControl] Loaded
2023-07-31T17:09:30.631Z,1690823370.631 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2023-07-31T17:09:30.631Z,1690823370.631 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2023-07-31T17:09:30.632Z,1690823370.632 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2023-07-31T17:09:30.642Z,1690823370.642 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2023-07-31T17:09:30.642Z,1690823370.642 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2023-07-31T17:09:30.784Z,1690823370.784 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2023-07-31T17:09:30.784Z,1690823370.784 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2023-07-31T17:09:30.934Z,1690823370.934 [BuoyancyServo] Loaded
2023-07-31T17:09:30.935Z,1690823370.935 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2023-07-31T17:09:30.954Z,1690823370.954 [ElevatorServo] Loaded
2023-07-31T17:09:30.954Z,1690823370.954 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2023-07-31T17:09:30.973Z,1690823370.973 [MassServo] Loaded
2023-07-31T17:09:30.973Z,1690823370.973 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2023-07-31T17:09:30.991Z,1690823370.991 [RudderServo] Loaded
2023-07-31T17:09:30.991Z,1690823370.991 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2023-07-31T17:09:31.005Z,1690823371.005 [ThrusterHE] Loaded
2023-07-31T17:09:31.005Z,1690823371.005 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2023-07-31T17:09:31.006Z,1690823371.006 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2023-07-31T17:09:31.006Z,1690823371.006 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2023-07-31T17:09:31.116Z,1690823371.116 [DeadReckonUsingMultipleVelocitySources] Loaded
2023-07-31T17:09:31.116Z,1690823371.116 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2023-07-31T17:09:31.129Z,1690823371.129 [NavChart] Loaded
2023-07-31T17:09:31.129Z,1690823371.129 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2023-07-31T17:09:31.135Z,1690823371.135 [UniversalFixResidualReporter] Loaded
2023-07-31T17:09:31.135Z,1690823371.135 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2023-07-31T17:09:31.136Z,1690823371.136 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2023-07-31T17:09:31.136Z,1690823371.136 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2023-07-31T17:09:31.191Z,1690823371.191 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2023-07-31T17:09:31.192Z,1690823371.192 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2023-07-31T17:09:31.606Z,1690823371.606 [AHRS_M2] Loaded
2023-07-31T17:09:31.606Z,1690823371.606 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2023-07-31T17:09:32.416Z,1690823372.416 [BPC1] Loaded
2023-07-31T17:09:32.417Z,1690823372.417 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2023-07-31T17:09:32.490Z,1690823372.490 [DataOverHttps] Loaded
2023-07-31T17:09:32.490Z,1690823372.490 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2023-07-31T17:09:32.492Z,1690823372.492 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4090B4E0
2023-07-31T17:09:32.492Z,1690823372.492 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 8873
2023-07-31T17:09:32.513Z,1690823372.513 [Depth_Keller] Loaded
2023-07-31T17:09:32.513Z,1690823372.513 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2023-07-31T17:09:32.518Z,1690823372.518 [DropWeight] Loaded
2023-07-31T17:09:32.518Z,1690823372.518 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2023-07-31T17:09:32.579Z,1690823372.579 [NAL9602] Loaded
2023-07-31T17:09:32.579Z,1690823372.579 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2023-07-31T17:09:32.608Z,1690823372.608 [Onboard] Loaded
2023-07-31T17:09:32.609Z,1690823372.609 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2023-07-31T17:09:32.610Z,1690823372.610 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4093B4E0
2023-07-31T17:09:32.610Z,1690823372.610 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 8874
2023-07-31T17:09:32.623Z,1690823372.623 [Power24vConverter] Loaded
2023-07-31T17:09:32.624Z,1690823372.624 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2023-07-31T17:09:32.637Z,1690823372.637 [Radio_Surface] Loaded
2023-07-31T17:09:32.637Z,1690823372.637 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2023-07-31T17:09:32.638Z,1690823372.638 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4096B4E0
2023-07-31T17:09:32.638Z,1690823372.638 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 8875
2023-07-31T17:09:32.639Z,1690823372.639 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2023-07-31T17:09:32.640Z,1690823372.640 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2023-07-31T17:09:32.812Z,1690823372.812 [DepthRateCalculator] Loaded
2023-07-31T17:09:32.812Z,1690823372.812 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2023-07-31T17:09:32.817Z,1690823372.817 [PitchRateCalculator] Loaded
2023-07-31T17:09:32.817Z,1690823372.817 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2023-07-31T17:09:32.846Z,1690823372.846 [SpeedCalculator] Loaded
2023-07-31T17:09:32.846Z,1690823372.846 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2023-07-31T17:09:32.874Z,1690823372.874 [YawRateCalculator] Loaded
2023-07-31T17:09:32.874Z,1690823372.874 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2023-07-31T17:09:32.900Z,1690823372.900 [ElevatorOffsetCalculator] Loaded
2023-07-31T17:09:32.900Z,1690823372.900 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2023-07-31T17:09:32.900Z,1690823372.900 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2023-07-31T17:09:32.901Z,1690823372.901 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2023-07-31T17:09:33.252Z,1690823373.252 [CANONSampler] Loaded
2023-07-31T17:09:33.252Z,1690823373.252 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2023-07-31T17:09:33.340Z,1690823373.340 [CTD_Seabird] Loaded
2023-07-31T17:09:33.341Z,1690823373.341 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2023-07-31T17:09:33.342Z,1690823373.342 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A244E0
2023-07-31T17:09:33.342Z,1690823373.342 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 8876
2023-07-31T17:09:33.362Z,1690823373.362 [PAR_Licor] Loaded
2023-07-31T17:09:33.362Z,1690823373.362 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2023-07-31T17:09:33.439Z,1690823373.439 [WetLabsBB2FL] Loaded
2023-07-31T17:09:33.439Z,1690823373.439 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2023-07-31T17:09:33.440Z,1690823373.440 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A544E0
2023-07-31T17:09:33.441Z,1690823373.441 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 8877
2023-07-31T17:09:33.441Z,1690823373.441 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2023-07-31T17:09:33.442Z,1690823373.442 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2023-07-31T17:09:33.469Z,1690823373.469 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2023-07-31T17:09:33.469Z,1690823373.469 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2023-07-31T17:09:33.853Z,1690823373.853 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2023-07-31T17:09:33.854Z,1690823373.854 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2023-07-31T17:09:33.988Z,1690823373.988 [SBIT](DEBUG): Construct Startup Built In Test.
2023-07-31T17:09:33.996Z,1690823373.996 [SBIT] Loaded
2023-07-31T17:09:33.997Z,1690823373.997 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2023-07-31T17:09:33.000Z,1690823374.000 [IBIT](DEBUG): Construct Initiated Built In Test.
2023-07-31T17:09:34.012Z,1690823374.012 [IBIT] Loaded
2023-07-31T17:09:34.012Z,1690823374.012 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2023-07-31T17:09:34.018Z,1690823374.018 [CBIT](DEBUG): Construct Continuous Built In Test.
2023-07-31T17:09:34.121Z,1690823374.121 [CBIT] Loaded
2023-07-31T17:09:34.121Z,1690823374.121 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2023-07-31T17:09:34.122Z,1690823374.122 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2023-07-31T17:09:34.122Z,1690823374.122 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2023-07-31T17:09:34.218Z,1690823374.218 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2023-07-31T17:09:34.225Z,1690823374.225 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2023-07-31T17:09:34.227Z,1690823374.227 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2023-07-31T17:09:34.238Z,1690823374.238 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2023-07-31T17:09:34.239Z,1690823374.239 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B944E0
2023-07-31T17:09:34.240Z,1690823374.240 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 8878
2023-07-31T17:09:34.244Z,1690823374.244 [Supervisor](INFO): Main Thread ID is 8209
2023-07-31T17:09:34.244Z,1690823374.244 [Supervisor](DEBUG): Running supervisor.
2023-07-31T17:09:34.245Z,1690823374.245 [CommandExec ThreadHandler](INFO): Handler Thread ID is 8879
2023-07-31T17:09:34.245Z,1690823374.245 [CommandExec](INFO): Initializing the command executive.
2023-07-31T17:09:34.247Z,1690823374.247 [CommandLine ThreadHandler](INFO): Handler Thread ID is 8880
2023-07-31T17:09:34.250Z,1690823374.250 [controlThread ThreadHandler](INFO): Handler Thread ID is 8881
2023-07-31T17:09:34.250Z,1690823374.250 [controlThread](DEBUG): Initializing ControlThread
2023-07-31T17:09:34.251Z,1690823374.251 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2023-07-31T17:09:34.253Z,1690823374.253 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2023-07-31T17:09:34.254Z,1690823374.254 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2023-07-31T17:09:34.254Z,1690823374.254 [LoopControl](DEBUG): Initialize LoopControlComponent.
2023-07-31T17:09:34.256Z,1690823374.256 [NavChart](DEBUG): Initialize NavChart Navigation.
2023-07-31T17:09:34.256Z,1690823374.256 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2023-07-31T17:09:34.261Z,1690823374.261 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2023-07-31T17:09:34.261Z,1690823374.261 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2023-07-31T17:09:34.261Z,1690823374.261 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2023-07-31T17:09:34.262Z,1690823374.262 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2023-07-31T17:09:34.262Z,1690823374.262 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2023-07-31T17:09:34.267Z,1690823374.267 [SBIT](INFO): Initialize SBIT Component.
2023-07-31T17:09:34.268Z,1690823374.268 [SBIT](IMPORTANT): git: 2023-06-27_B
2023-07-31T17:09:34.268Z,1690823374.268 [SBIT](INFO): git hash: ff84f56c2b48606b9e34bb544c9bbe31deaa129e
2023-07-31T17:09:34.268Z,1690823374.268 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2023-07-31T17:09:34.269Z,1690823374.269 [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-07-31T17:09:34.271Z,1690823374.271 [SBIT](INFO): Beginning SBIT in 55.000000 seconds.
2023-07-31T17:09:34.271Z,1690823374.271 [IBIT](INFO): Initialize IBIT Component.
2023-07-31T17:09:34.272Z,1690823374.272 [CBIT](DEBUG): Initialize CBIT Component.
2023-07-31T17:09:34.273Z,1690823374.273 [logger ThreadHandler](INFO): Handler Thread ID is 8882
2023-07-31T17:09:34.283Z,1690823374.283 [CBIT](DEBUG): Initialized mux pins.
2023-07-31T17:09:34.284Z,1690823374.284 [CBIT](DEBUG): Initializing the watchdog timer.
2023-07-31T17:09:34.292Z,1690823374.292 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 8883
2023-07-31T17:09:34.293Z,1690823374.293 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2023-07-31T17:09:34.303Z,1690823374.303 [Onboard ThreadHandler](INFO): Handler Thread ID is 8884
2023-07-31T17:09:34.308Z,1690823374.308 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2023-07-31T17:09:34.308Z,1690823374.308 [CBIT](DEBUG): Initializing heartbeat.
2023-07-31T17:09:34.324Z,1690823374.324 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 8885
2023-07-31T17:09:34.336Z,1690823374.336 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 8886
2023-07-31T17:09:34.336Z,1690823374.336 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2023-07-31T17:09:34.341Z,1690823374.341 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 8888
2023-07-31T17:09:34.344Z,1690823374.344 [WetLabsBB2FL](INFO): Powering up
2023-07-31T17:09:34.345Z,1690823374.345 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 8890
2023-07-31T17:09:34.348Z,1690823374.348 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2023-07-31T17:09:34.349Z,1690823374.349 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2023-07-31T17:09:34.349Z,1690823374.349 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2023-07-31T17:09:34.349Z,1690823374.349 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2023-07-31T17:09:34.349Z,1690823374.349 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2023-07-31T17:09:34.349Z,1690823374.349 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2023-07-31T17:09:34.350Z,1690823374.350 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2023-07-31T17:09:34.350Z,1690823374.350 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2023-07-31T17:09:34.379Z,1690823374.379 [CBIT](DEBUG): Deactivating GF circuits.
2023-07-31T17:09:34.379Z,1690823374.379 [CBIT](DEBUG): Deactivating emergency mode.
2023-07-31T17:09:34.419Z,1690823374.419 [CBIT](DEBUG): Backplane powered.
2023-07-31T17:09:34.420Z,1690823374.420 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2023-07-31T17:09:34.433Z,1690823374.433 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2023-07-31T17:09:34.453Z,1690823374.453 [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-07-31T17:09:34.453Z,1690823374.453 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2023-07-31T17:09:34.532Z,1690823374.532 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2023-07-31T17:09:34.533Z,1690823374.533 [Default:A.Wait](DEBUG): Construct Wait.
2023-07-31T17:09:34.544Z,1690823374.544 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-07-31T17:09:34.588Z,1690823374.588 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2023-07-31T17:09:34.590Z,1690823374.590 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2023-07-31T17:09:34.612Z,1690823374.612 [Default:E.Execute](DEBUG): Construct Execute.
2023-07-31T17:09:34.616Z,1690823374.616 [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-07-31T17:09:34.639Z,1690823374.639 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2023-07-31T17:09:34.655Z,1690823374.655 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-07-31T17:09:34.727Z,1690823374.727 [Radio_Surface](INFO): Powering up
2023-07-31T17:09:34.730Z,1690823374.730 [Power24vConverter](INFO): Powering up.
2023-07-31T17:09:34.731Z,1690823374.731 [CANONSampler](INFO): Powering down
2023-07-31T17:09:34.788Z,1690823374.788 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2023-07-31T17:09:34.799Z,1690823374.799 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2023-07-31T17:09:34.800Z,1690823374.800 [ElevatorServo](DEBUG): Initializing EZServoServo.
2023-07-31T17:09:34.807Z,1690823374.807 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2023-07-31T17:09:34.808Z,1690823374.808 [MassServo](DEBUG): Initializing EZServoServo.
2023-07-31T17:09:34.815Z,1690823374.815 [MassServo](DEBUG): Initializing MassServo.
2023-07-31T17:09:34.816Z,1690823374.816 [RudderServo](DEBUG): Initializing EZServoServo.
2023-07-31T17:09:34.831Z,1690823374.831 [RudderServo](DEBUG): Initializing RudderServo.
2023-07-31T17:09:34.832Z,1690823374.832 [ThrusterHE](DEBUG): Initializing EZServoServo.
2023-07-31T17:09:34.839Z,1690823374.839 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2023-07-31T17:09:36.967Z,1690823376.967 [WetLabsBB2FL](INFO): Powering down
2023-07-31T17:09:40.536Z,1690823380.536 [ThrusterHE](ERROR): Zero Speed Commanded.
2023-07-31T17:10:02.933Z,1690823402.933 [NAL9602](INFO): Powering up NAL9602
2023-07-31T17:10:13.841Z,1690823413.841 [NAL9602](INFO): NAL9602 initialized
2023-07-31T17:10:30.018Z,1690823430.018 [SBIT](IMPORTANT): Beginning Startup BIT
2023-07-31T17:10:30.022Z,1690823430.022 [CBIT](IMPORTANT): Beginning ground fault scan
2023-07-31T17:10:38.491Z,1690823438.491 [NAL9602](INFO): SBD MO Status=0, MOMSN=44251, MT Status=0, MTMSN=0
2023-07-31T17:10:38.492Z,1690823438.492 [NAL9602](INFO): No messages in MT queue
2023-07-31T17:10:39.702Z,1690823439.702 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171038.00,A,3648.15073,N,12147.23051,W,1.652,338.32,310723,,,A*70
2023-07-31T17:10:39.706Z,1690823439.706 [NAL9602](INFO): GPS fix at 20230731T171038: (36.802512, -121.787175)
2023-07-31T17:10:40.947Z,1690823440.947 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2023-07-31T17:10:41.387Z,1690823441.387 [CBIT](IMPORTANT): Beginning ground fault scan
2023-07-31T17:10:52.300Z,1690823452.300 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.002503
CHAN A1 (24V): 0.000437
CHAN A2 (12V): -0.002174
CHAN A3 (5V): -0.001660
CHAN B0 (3.3V): -0.000355
CHAN B1 (3.15aV): -0.000223
CHAN B2 (3.15bV): -0.000578
CHAN B3 (GND): 0.000232
OPEN: -0.000462
Full Scale: +/- 1 mA
2023-07-31T17:11:12.424Z,1690823472.424 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-31T17:11:24.176Z,1690823484.176 [SBIT](IMPORTANT): SBIT PASSED
2023-07-31T17:11:24.177Z,1690823484.177 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-07-31T17:11:24.177Z,1690823484.177 [SBIT](IMPORTANT): AMEcho.loadAtStartup=0 bool;

2023-07-31T17:11:24.178Z,1690823484.178 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=20 count;

2023-07-31T17:11:24.178Z,1690823484.178 [SBIT](IMPORTANT): CANONSampler.loadAtStartup=1 bool;

2023-07-31T17:11:24.178Z,1690823484.178 [SBIT](IMPORTANT): CBIT.runElevOffsetCalc=1 bool;

2023-07-31T17:11:24.178Z,1690823484.178 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool;

2023-07-31T17:11:24.178Z,1690823484.178 [SBIT](IMPORTANT): RudderServo.offsetAngle=0 degree;

2023-07-31T17:11:24.178Z,1690823484.178 [SBIT](IMPORTANT): Sonardyne_Nano.loadAtStartup=0 bool;

2023-07-31T17:11:24.178Z,1690823484.178 [SBIT](IMPORTANT): ThrusterServo.currLimit=50 percent;

2023-07-31T17:11:24.178Z,1690823484.178 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=274.882962 cubic_centimeter;

2023-07-31T17:11:24.179Z,1690823484.179 [SBIT](IMPORTANT): VerticalControl.massDefault=-8.922045 millimeter;

2023-07-31T17:11:24.567Z,1690823484.567 [MissionManager](IMPORTANT): Started mission Startup
2023-07-31T17:11:24.568Z,1690823484.568 [Startup] Running Loop=1
2023-07-31T17:11:24.568Z,1690823484.568 [Startup](DEBUG): Aggregate::initialize Startup
2023-07-31T17:11:24.568Z,1690823484.568 [Startup:A.GoToSurface] Running Loop=1
2023-07-31T17:11:24.568Z,1690823484.568 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-07-31T17:11:24.569Z,1690823484.569 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-07-31T17:11:24.569Z,1690823484.569 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-07-31T17:11:24.569Z,1690823484.569 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-07-31T17:11:24.570Z,1690823484.570 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-07-31T17:11:24.570Z,1690823484.570 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-07-31T17:11:24.572Z,1690823484.572 [Startup:StartupSatComms] Running Loop=1
2023-07-31T17:11:24.572Z,1690823484.572 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2023-07-31T17:11:24.572Z,1690823484.572 [Startup:StartupSatComms:A] Running Loop=1
2023-07-31T17:11:24.975Z,1690823484.975 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2023-07-31T17:11:26.566Z,1690823486.566 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171125.00,A,3648.14256,N,12147.23084,W,0.078,337.32,310723,,,A*71
2023-07-31T17:11:26.569Z,1690823486.569 [NAL9602](INFO): GPS fix at 20230731T171125: (36.802376, -121.787181)
2023-07-31T17:11:26.592Z,1690823486.592 [Startup:StartupSatComms:A] Stopped
2023-07-31T17:11:26.592Z,1690823486.592 [Startup:StartupSatComms:B] Running Loop=1
2023-07-31T17:11:27.004Z,1690823487.004 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-07-31T17:11:49.270Z,1690823509.270 [NAL9602](INFO): SBD MO Status=1, MOMSN=44252, MT Status=0, MTMSN=0
2023-07-31T17:11:49.327Z,1690823509.327 [NAL9602](INFO): Sent 267 bytes from file Logs/20230731T170924/Courier0000.lzma
2023-07-31T17:11:49.327Z,1690823509.327 [NAL9602](INFO): Packets left to send: 0
2023-07-31T17:12:01.862Z,1690823521.862 [NAL9602](INFO): SBD MO Status=1, MOMSN=44253, MT Status=0, MTMSN=0
2023-07-31T17:12:01.911Z,1690823521.911 [NAL9602](INFO): Sent 332 bytes from file Logs/20230731T170924/Express0001.lzma
2023-07-31T17:12:01.911Z,1690823521.911 [NAL9602](INFO): Packets left to send: 2
2023-07-31T17:12:07.154Z,1690823527.154 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-07-31T17:12:14.021Z,1690823534.021 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-07-31T17:12:14.031Z,1690823534.031 [NAL9602](INFO): SBD MO Status=1, MOMSN=44254, MT Status=0, MTMSN=0
2023-07-31T17:12:14.083Z,1690823534.083 [NAL9602](INFO): Sent 332 bytes from file Logs/20230731T170924/Express0001.lzma
2023-07-31T17:12:14.084Z,1690823534.084 [NAL9602](INFO): Packets left to send: 1
2023-07-31T17:12:26.596Z,1690823546.596 [Startup:StartupSatComms:B](INFO): Timed out from 2023-07-31T17:11:26.6Z
2023-07-31T17:12:26.596Z,1690823546.596 [Startup:StartupSatComms:B] Stopped
2023-07-31T17:12:26.596Z,1690823546.596 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2023-07-31T17:12:26.596Z,1690823546.596 [Startup:StartupSatComms] Stopped
2023-07-31T17:12:26.596Z,1690823546.596 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2023-07-31T17:12:26.597Z,1690823546.597 [Startup](INFO): Completed Startup
2023-07-31T17:12:26.597Z,1690823546.597 [MissionManager](INFO): Startup is completed.
2023-07-31T17:12:26.597Z,1690823546.597 [MissionManager](INFO): Uninitializing Mission Startup
2023-07-31T17:12:26.597Z,1690823546.597 [Startup] Stopped
2023-07-31T17:12:26.597Z,1690823546.597 [Startup](DEBUG): Aggregate::uninitialize Startup
2023-07-31T17:12:26.597Z,1690823546.597 [Startup:A.GoToSurface] Stopped
2023-07-31T17:12:26.597Z,1690823546.597 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-07-31T17:12:27.015Z,1690823547.015 [MissionManager](IMPORTANT): Started mission Default
2023-07-31T17:12:27.016Z,1690823547.016 [Default] Running Loop=1
2023-07-31T17:12:27.016Z,1690823547.016 [Default](DEBUG): Aggregate::initialize Default
2023-07-31T17:12:27.016Z,1690823547.016 [Default:B.GoToSurface] Running Loop=1
2023-07-31T17:12:27.016Z,1690823547.016 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-07-31T17:12:27.016Z,1690823547.016 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-07-31T17:12:27.016Z,1690823547.016 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-07-31T17:12:27.017Z,1690823547.017 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-07-31T17:12:27.017Z,1690823547.017 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-07-31T17:12:27.017Z,1690823547.017 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-07-31T17:12:27.018Z,1690823547.018 [Default:A.Wait] Running Loop=1
2023-07-31T17:12:27.018Z,1690823547.018 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-07-31T17:12:29.005Z,1690823549.005 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-07-31T17:12:33.131Z,1690823553.131 [NAL9602](INFO): SBD MO Status=2, MOMSN=44255, MT Status=2, MTMSN=0
2023-07-31T17:12:33.131Z,1690823553.131 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-31T17:12:40.334Z,1690823560.334 [Default:A.Wait](INFO): Done Waiting.
2023-07-31T17:12:40.334Z,1690823560.334 [Default:A.Wait] Stopped
2023-07-31T17:12:40.334Z,1690823560.334 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-07-31T17:12:40.746Z,1690823560.746 [Default:CheckIn] Running Loop=1
2023-07-31T17:12:40.746Z,1690823560.746 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-31T17:12:40.747Z,1690823560.747 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-31T17:12:41.156Z,1690823561.156 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-07-31T17:12:42.339Z,1690823562.339 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-07-31T17:12:42.766Z,1690823562.766 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171242.00,A,3648.14119,N,12147.22890,W,0.058,337.32,310723,,,A*75
2023-07-31T17:12:42.768Z,1690823562.768 [NAL9602](INFO): GPS fix at 20230731T171242: (36.802353, -121.787148)
2023-07-31T17:12:42.780Z,1690823562.780 [Default:CheckIn:Read_GPS] Stopped
2023-07-31T17:12:42.780Z,1690823562.780 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-31T17:12:43.212Z,1690823563.212 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-07-31T17:12:55.737Z,1690823575.737 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-07-31T17:13:01.402Z,1690823581.402 [NAL9602](INFO): SBD MO Status=1, MOMSN=44255, MT Status=0, MTMSN=0
2023-07-31T17:13:01.447Z,1690823581.447 [NAL9602](INFO): Sent 73 bytes from file Logs/20230731T170924/Courier0004.lzma
2023-07-31T17:13:01.447Z,1690823581.447 [NAL9602](INFO): Packets left to send: 0
2023-07-31T17:13:09.174Z,1690823589.174 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-07-31T17:13:09.749Z,1690823589.749 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004508
2023-07-31T17:13:13.638Z,1690823593.638 [NAL9602](INFO): SBD MO Status=1, MOMSN=44256, MT Status=0, MTMSN=0
2023-07-31T17:13:13.699Z,1690823593.699 [NAL9602](INFO): Sent 198 bytes from file Logs/20230731T170924/Express0001.lzma
2023-07-31T17:13:13.700Z,1690823593.700 [NAL9602](INFO): Packets left to send: 0
2023-07-31T17:13:13.763Z,1690823593.763 [Default:CheckIn:Read_Iridium] Stopped
2023-07-31T17:13:13.763Z,1690823593.763 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-31T17:13:13.767Z,1690823593.767 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-31T17:13:17.245Z,1690823597.245 [DataOverHttps](IMPORTANT): Could not stat file Logs/20230731T170924/Express0001.lzma
2023-07-31T17:13:17.245Z,1690823597.245 [DataOverHttps](FAULT): Could not open file Logs/20230731T170924/Express0001.lzma
2023-07-31T17:13:22.914Z,1690823602.914 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-07-31T17:13:28.717Z,1690823608.717 [DataOverHttps](IMPORTANT): Could not stat file Logs/20230731T170924/Express0001.lzma
2023-07-31T17:13:28.717Z,1690823608.717 [DataOverHttps](FAULT): Could not open file Logs/20230731T170924/Express0001.lzma
2023-07-31T17:13:36.693Z,1690823616.693 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-07-31T17:13:44.373Z,1690823624.373 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-31T17:13:50.431Z,1690823630.431 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-07-31T17:13:56.401Z,1690823636.401 [DataOverHttps](IMPORTANT): Could not stat file Logs/20230731T170924/Express0001.lzma
2023-07-31T17:13:56.401Z,1690823636.401 [DataOverHttps](FAULT): Could not open file Logs/20230731T170924/Express0001.lzma
2023-07-31T17:14:04.578Z,1690823644.578 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-07-31T17:14:18.710Z,1690823658.710 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-07-31T17:14:29.113Z,1690823669.113 [DataOverHttps](IMPORTANT): Could not stat file Logs/20230731T170924/Express0001.lzma
2023-07-31T17:14:29.113Z,1690823669.113 [DataOverHttps](FAULT): Could not open file Logs/20230731T170924/Express0001.lzma
2023-07-31T17:14:32.917Z,1690823672.917 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2023-07-31T17:14:33.277Z,1690823673.277 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-07-31T17:14:38.125Z,1690823678.125 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2023-07-31T17:14:48.226Z,1690823688.226 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-07-31T17:14:58.857Z,1690823698.857 [DataOverHttps](IMPORTANT): Could not stat file Logs/20230731T170924/Express0001.lzma
2023-07-31T17:14:58.857Z,1690823698.857 [DataOverHttps](FAULT): Could not open file Logs/20230731T170924/Express0001.lzma
2023-07-31T17:14:59.860Z,1690823699.860 [DataOverHttps](IMPORTANT): SBD MTMSN=20230731T171459
2023-07-31T17:15:03.177Z,1690823703.177 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-07-31T17:15:07.201Z,1690823707.201 [DataOverHttps](IMPORTANT): Could not stat file Logs/20230731T170924/Express0001.lzma
2023-07-31T17:15:07.201Z,1690823707.201 [DataOverHttps](FAULT): Could not open file Logs/20230731T170924/Express0001.lzma
2023-07-31T17:15:07.208Z,1690823707.208 [DataOverHttps](INFO): Received command: sched asap "ibit" 3l3wt 1 2
2023-07-31T17:15:07.274Z,1690823707.274 [CommandExec](IMPORTANT): got command schedule asap "ibit" 3l3wt 1 2.000000
2023-07-31T17:15:07.274Z,1690823707.274 [CommandExec](IMPORTANT): Scheduling command #1 of 2 with id=3l3wt
2023-07-31T17:15:07.275Z,1690823707.275 [CommandExec](IMPORTANT): Scheduled #1 (#1 of 2 with id='3l3wt'): "ibit", ASAP
2023-07-31T17:15:08.205Z,1690823708.205 [DataOverHttps](IMPORTANT): SBD MTMSN=20230731T171507
2023-07-31T17:15:15.697Z,1690823715.697 [DataOverHttps](IMPORTANT): Could not stat file Logs/20230731T170924/Express0001.lzma
2023-07-31T17:15:15.698Z,1690823715.698 [DataOverHttps](FAULT): Could not open file Logs/20230731T170924/Express0001.lzma
2023-07-31T17:15:15.700Z,1690823715.700 [DataOverHttps](INFO): Received command: sched asap "" 3l3wt 2 2
2023-07-31T17:15:15.734Z,1690823715.734 [CommandExec](IMPORTANT): got command schedule asap "" 3l3wt 2 2.000000
2023-07-31T17:15:15.734Z,1690823715.734 [CommandExec](IMPORTANT): Scheduling command #2 of 2 with id=3l3wt
2023-07-31T17:15:15.735Z,1690823715.735 [CommandExec](IMPORTANT): Scheduled #2 (#2 of 2 with id='3l3wt'): "", ASAP
2023-07-31T17:15:15.836Z,1690823715.836 [CommandExec](IMPORTANT): got command ibit
2023-07-31T17:15:16.145Z,1690823716.145 [IBIT](IMPORTANT): Beginning Initiated BIT
2023-07-31T17:15:16.145Z,1690823716.145 [IBIT](IMPORTANT): Beginning control surface checks.
2023-07-31T17:15:16.149Z,1690823716.149 [CBIT](IMPORTANT): Beginning ground fault scan
2023-07-31T17:15:17.726Z,1690823717.726 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171517.00,A,3648.14180,N,12147.22760,W,0.039,337.32,310723,,,D*70
2023-07-31T17:15:17.729Z,1690823717.729 [NAL9602](INFO): GPS fix at 20230731T171517: (36.802363, -121.787127)
2023-07-31T17:15:18.934Z,1690823718.934 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-07-31T17:15:27.059Z,1690823727.059 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2023-07-31T17:15:27.443Z,1690823727.443 [CBIT](IMPORTANT): Beginning ground fault scan
2023-07-31T17:15:34.287Z,1690823734.287 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-07-31T17:15:35.906Z,1690823735.906 [NAL9602](INFO): SBD MO Status=0, MOMSN=44257, MT Status=0, MTMSN=0
2023-07-31T17:15:35.906Z,1690823735.906 [NAL9602](INFO): No messages in MT queue
2023-07-31T17:15:37.122Z,1690823737.122 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171536.00,A,3648.14223,N,12147.22757,W,0.097,337.32,310723,,,D*79
2023-07-31T17:15:37.124Z,1690823737.124 [NAL9602](INFO): GPS fix at 20230731T171536: (36.802371, -121.787126)
2023-07-31T17:15:38.447Z,1690823738.447 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.002802
CHAN A1 (24V): 0.000475
CHAN A2 (12V): -0.002888
CHAN A3 (5V): -0.001559
CHAN B0 (3.3V): -0.000021
CHAN B1 (3.15aV): 0.000189
CHAN B2 (3.15bV): -0.000098
CHAN B3 (GND): 0.000435
OPEN: -0.000400
Full Scale: +/- 1 mA
2023-07-31T17:15:39.946Z,1690823739.946 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171539.00,A,3648.14219,N,12147.22761,W,0.078,337.32,310723,,,D*7B
2023-07-31T17:15:39.958Z,1690823739.958 [NAL9602](INFO): GPS fix at 20230731T171539: (36.802370, -121.787127)
2023-07-31T17:15:42.778Z,1690823742.778 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171542.00,A,3648.14220,N,12147.22766,W,0.039,337.32,310723,,,D*7F
2023-07-31T17:15:42.780Z,1690823742.780 [NAL9602](INFO): GPS fix at 20230731T171542: (36.802370, -121.787128)
2023-07-31T17:15:46.008Z,1690823746.008 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171545.00,A,3648.14225,N,12147.22768,W,0.078,337.32,310723,,,D*76
2023-07-31T17:15:46.010Z,1690823746.010 [NAL9602](INFO): GPS fix at 20230731T171545: (36.802371, -121.787128)
2023-07-31T17:15:46.541Z,1690823746.541 [DataOverHttps](IMPORTANT): Could not stat file Logs/20230731T170924/Express0001.lzma
2023-07-31T17:15:46.541Z,1690823746.541 [DataOverHttps](FAULT): Could not open file Logs/20230731T170924/Express0001.lzma
2023-07-31T17:15:48.881Z,1690823748.881 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171548.00,A,3648.14232,N,12147.22764,W,0.039,337.32,310723,,,D*74
2023-07-31T17:15:48.884Z,1690823748.884 [NAL9602](INFO): GPS fix at 20230731T171548: (36.802372, -121.787127)
2023-07-31T17:15:49.236Z,1690823749.236 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-07-31T17:15:52.074Z,1690823752.074 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171551.00,A,3648.14227,N,12147.22775,W,0.078,337.32,310723,,,D*7D
2023-07-31T17:15:52.076Z,1690823752.076 [NAL9602](INFO): GPS fix at 20230731T171551: (36.802371, -121.787129)
2023-07-31T17:15:54.894Z,1690823754.894 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171554.00,A,3648.14224,N,12147.22783,W,0.058,337.32,310723,,,D*70
2023-07-31T17:15:54.896Z,1690823754.896 [NAL9602](INFO): GPS fix at 20230731T171554: (36.802371, -121.787131)
2023-07-31T17:15:57.726Z,1690823757.726 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171557.00,A,3648.14222,N,12147.22793,W,0.039,337.32,310723,,,D*73
2023-07-31T17:15:57.728Z,1690823757.728 [NAL9602](INFO): GPS fix at 20230731T171557: (36.802370, -121.787132)
2023-07-31T17:16:00.953Z,1690823760.953 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171600.00,A,3648.14224,N,12147.22799,W,0.058,337.32,310723,,,D*79
2023-07-31T17:16:00.955Z,1690823760.955 [NAL9602](INFO): GPS fix at 20230731T171600: (36.802371, -121.787133)
2023-07-31T17:16:02.230Z,1690823762.230 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 4
Latitude: 36.802372 Longitude: -121.787132
2023-07-31T17:16:02.605Z,1690823762.605 [IBIT](FAULT): Warning: Battery Data not active. Expected only when running primaries. Threshold checking not active.
2023-07-31T17:16:03.012Z,1690823763.012 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2023-07-31T17:16:03.013Z,1690823763.013 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2023-07-31T17:16:03.013Z,1690823763.013 [IBIT](IMPORTANT): Pressure:9.659140 PSI
2023-07-31T17:16:03.013Z,1690823763.013 [IBIT](IMPORTANT): Humidity:11.341717 %
2023-07-31T17:16:03.397Z,1690823763.397 [IBIT](IMPORTANT): Vehicle Pitch:-0.543995 degrees
2023-07-31T17:16:03.397Z,1690823763.397 [IBIT](IMPORTANT): Vehicle  Roll:4.719742 degrees
2023-07-31T17:16:03.397Z,1690823763.397 [IBIT](IMPORTANT): Vehicle  Heading:29.812977 degrees
2023-07-31T17:16:03.848Z,1690823763.848 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2023-07-31T17:16:03.848Z,1690823763.848 [IBIT](IMPORTANT): buoyancyNeutral: 274.882965 cc
2023-07-31T17:16:03.849Z,1690823763.849 [IBIT](IMPORTANT): massDefault: -0.892205 cm
2023-07-31T17:16:03.849Z,1690823763.849 [IBIT](IMPORTANT): stopDepth: 250.000000 m
2023-07-31T17:16:03.849Z,1690823763.849 [IBIT](IMPORTANT): abortDepth: 270.000000 m
2023-07-31T17:16:03.849Z,1690823763.849 [IBIT](IMPORTANT): IBIT PASSED
2023-07-31T17:16:04.199Z,1690823764.199 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-07-31T17:16:17.010Z,1690823777.010 [DataOverHttps](IMPORTANT): Could not stat file Logs/20230731T170924/Express0001.lzma
2023-07-31T17:16:17.010Z,1690823777.010 [DataOverHttps](FAULT): Could not open file Logs/20230731T170924/Express0001.lzma
2023-07-31T17:16:19.130Z,1690823779.130 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-07-31T17:16:33.276Z,1690823793.276 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-31T17:16:34.481Z,1690823794.481 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-07-31T17:16:47.401Z,1690823807.401 [DataOverHttps](IMPORTANT): Could not stat file Logs/20230731T170924/Express0001.lzma
2023-07-31T17:16:47.401Z,1690823807.401 [DataOverHttps](FAULT): Could not open file Logs/20230731T170924/Express0001.lzma
2023-07-31T17:16:49.430Z,1690823809.430 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2023-07-31T17:16:49.460Z,1690823809.460 [BPC1](INFO): Calculating totals. Valid battery stick count: 37. Valid reserve battery stick count: 6.
2023-07-31T17:16:49.463Z,1690823809.463 [BPC1](INFO): Received data from all battery sticks.
2023-07-31T17:17:17.797Z,1690823837.797 [DataOverHttps](IMPORTANT): Could not stat file Logs/20230731T170924/Express0001.lzma
2023-07-31T17:17:17.797Z,1690823837.797 [DataOverHttps](FAULT): Could not open file Logs/20230731T170924/Express0001.lzma
2023-07-31T17:17:48.337Z,1690823868.337 [DataOverHttps](IMPORTANT): Could not stat file Logs/20230731T170924/Express0001.lzma
2023-07-31T17:17:48.337Z,1690823868.337 [DataOverHttps](FAULT): Could not open file Logs/20230731T170924/Express0001.lzma
2023-07-31T17:18:14.294Z,1690823894.294 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-31T17:18:14.294Z,1690823894.294 [Default:CheckIn:C.Wait] Stopped
2023-07-31T17:18:14.294Z,1690823894.294 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-31T17:18:14.294Z,1690823894.294 [Default:CheckIn:D] Running Loop=1
2023-07-31T17:18:14.737Z,1690823894.737 [Default:CheckIn:D] Stopped
2023-07-31T17:18:14.737Z,1690823894.737 [Default:CheckIn:E] Running Loop=1
2023-07-31T17:18:15.107Z,1690823895.107 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 5.795352 min 
2023-07-31T17:18:15.107Z,1690823895.107 [Default:CheckIn:E] Stopped
2023-07-31T17:18:15.108Z,1690823895.108 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-31T17:18:15.108Z,1690823895.108 [Default:CheckIn] Stopped
2023-07-31T17:18:15.108Z,1690823895.108 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-31T17:18:15.108Z,1690823895.108 [Default:CheckIn](INFO): Running loop #2
2023-07-31T17:18:15.108Z,1690823895.108 [Default:CheckIn] Running Loop=2
2023-07-31T17:18:15.108Z,1690823895.108 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-31T17:18:15.108Z,1690823895.108 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-31T17:18:17.106Z,1690823897.106 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171816.00,A,3648.13973,N,12147.22845,W,0.039,337.32,310723,,,D*77
2023-07-31T17:18:17.108Z,1690823897.108 [NAL9602](INFO): GPS fix at 20230731T171816: (36.802329, -121.787141)
2023-07-31T17:18:17.192Z,1690823897.192 [Default:CheckIn:Read_GPS] Stopped
2023-07-31T17:18:17.192Z,1690823897.192 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-31T17:18:19.842Z,1690823899.842 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20230731T170924/Courier0007.lzma
2023-07-31T17:18:20.421Z,1690823900.421 [DataOverHttps](INFO): Moved sent file to Logs/20230731T170924/Courier0007.lzma.bak
2023-07-31T17:18:20.421Z,1690823900.421 [DataOverHttps](INFO): SBD MOMSN=18503831
2023-07-31T17:18:36.938Z,1690823916.938 [NAL9602](INFO): SBD MO Status=0, MOMSN=44258, MT Status=0, MTMSN=0
2023-07-31T17:18:36.938Z,1690823916.938 [NAL9602](INFO): No messages in MT queue
2023-07-31T17:18:39.123Z,1690823919.123 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20230731T170924/Express0005.lzma
2023-07-31T17:18:40.125Z,1690823920.125 [DataOverHttps](INFO): Moved sent file to Logs/20230731T170924/Express0005.lzma.bak
2023-07-31T17:18:40.125Z,1690823920.125 [DataOverHttps](INFO): SBD MOMSN=18503834
2023-07-31T17:18:59.120Z,1690823939.120 [DataOverHttps](INFO): Sending 1104 bytes from file Logs/20230731T170924/Express0008.lzma
2023-07-31T17:19:00.121Z,1690823940.121 [DataOverHttps](INFO): Moved sent file to Logs/20230731T170924/Express0008.lzma.bak
2023-07-31T17:19:00.121Z,1690823940.121 [DataOverHttps](INFO): SBD MOMSN=18503837
2023-07-31T17:19:07.688Z,1690823947.688 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-31T17:19:15.819Z,1690823955.819 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20230731T170924/Express0011.lzma
2023-07-31T17:19:16.821Z,1690823956.821 [DataOverHttps](INFO): Moved sent file to Logs/20230731T170924/Express0011.lzma.bak
2023-07-31T17:19:16.821Z,1690823956.821 [DataOverHttps](INFO): SBD MOMSN=18503893
2023-07-31T17:19:18.201Z,1690823958.201 [Default:CheckIn:Read_Iridium] Stopped
2023-07-31T17:19:18.201Z,1690823958.201 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-31T17:19:18.201Z,1690823958.201 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-31T17:19:35.572Z,1690823975.572 [Power24vConverter](INFO): Powering down.
2023-07-31T17:24:18.980Z,1690824258.980 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-31T17:24:18.980Z,1690824258.980 [Default:CheckIn:C.Wait] Stopped
2023-07-31T17:24:18.980Z,1690824258.980 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-31T17:24:18.980Z,1690824258.980 [Default:CheckIn:D] Running Loop=1
2023-07-31T17:24:19.366Z,1690824259.366 [Default:CheckIn:D] Stopped
2023-07-31T17:24:19.366Z,1690824259.366 [Default:CheckIn:E] Running Loop=1
2023-07-31T17:24:19.778Z,1690824259.778 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.872499 min 
2023-07-31T17:24:19.778Z,1690824259.778 [Default:CheckIn:E] Stopped
2023-07-31T17:24:19.779Z,1690824259.779 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-31T17:24:19.779Z,1690824259.779 [Default:CheckIn] Stopped
2023-07-31T17:24:19.779Z,1690824259.779 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-31T17:24:19.779Z,1690824259.779 [Default:CheckIn](INFO): Running loop #3
2023-07-31T17:24:19.779Z,1690824259.779 [Default:CheckIn] Running Loop=3
2023-07-31T17:24:19.779Z,1690824259.779 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-31T17:24:19.779Z,1690824259.779 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-31T17:24:21.814Z,1690824261.814 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172421.00,A,3648.14017,N,12147.22855,W,0.019,337.32,310723,,,D*73
2023-07-31T17:24:21.836Z,1690824261.836 [NAL9602](INFO): GPS fix at 20230731T172421: (36.802336, -121.787143)
2023-07-31T17:24:21.857Z,1690824261.857 [Default:CheckIn:Read_GPS] Stopped
2023-07-31T17:24:21.857Z,1690824261.857 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-31T17:24:29.922Z,1690824269.922 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230731T170924/Courier0013.lzma
2023-07-31T17:24:30.925Z,1690824270.925 [DataOverHttps](INFO): Moved sent file to Logs/20230731T170924/Courier0013.lzma.bak
2023-07-31T17:24:30.925Z,1690824270.925 [DataOverHttps](INFO): SBD MOMSN=18503896
2023-07-31T17:24:38.773Z,1690824278.773 [NAL9602](INFO): SBD MO Status=0, MOMSN=44259, MT Status=0, MTMSN=0
2023-07-31T17:24:38.774Z,1690824278.774 [NAL9602](INFO): No messages in MT queue
2023-07-31T17:24:46.730Z,1690824286.730 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230731T170924/Express0014.lzma
2023-07-31T17:24:47.741Z,1690824287.741 [DataOverHttps](INFO): Moved sent file to Logs/20230731T170924/Express0014.lzma.bak
2023-07-31T17:24:47.741Z,1690824287.741 [DataOverHttps](INFO): SBD MOMSN=18503899
2023-07-31T17:24:48.888Z,1690824288.888 [Default:CheckIn:Read_Iridium] Stopped
2023-07-31T17:24:48.889Z,1690824288.889 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-31T17:24:48.889Z,1690824288.889 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-31T17:25:09.513Z,1690824309.513 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-31T17:29:49.666Z,1690824589.666 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-31T17:29:49.666Z,1690824589.666 [Default:CheckIn:C.Wait] Stopped
2023-07-31T17:29:49.666Z,1690824589.666 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-31T17:29:49.666Z,1690824589.666 [Default:CheckIn:D] Running Loop=1
2023-07-31T17:29:50.058Z,1690824590.058 [Default:CheckIn:D] Stopped
2023-07-31T17:29:50.058Z,1690824590.058 [Default:CheckIn:E] Running Loop=1
2023-07-31T17:29:50.456Z,1690824590.456 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 17.384037 min 
2023-07-31T17:29:50.456Z,1690824590.456 [Default:CheckIn:E] Stopped
2023-07-31T17:29:50.457Z,1690824590.457 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-31T17:29:50.457Z,1690824590.457 [Default:CheckIn] Stopped
2023-07-31T17:29:50.457Z,1690824590.457 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-31T17:29:50.457Z,1690824590.457 [Default:CheckIn](INFO): Running loop #4
2023-07-31T17:29:50.457Z,1690824590.457 [Default:CheckIn] Running Loop=4
2023-07-31T17:29:50.457Z,1690824590.457 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-31T17:29:50.457Z,1690824590.457 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-31T17:29:52.466Z,1690824592.466 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172951.00,A,3648.14089,N,12147.22848,W,0.019,337.32,310723,,,D*72
2023-07-31T17:29:52.469Z,1690824592.469 [NAL9602](INFO): GPS fix at 20230731T172951: (36.802348, -121.787141)
2023-07-31T17:29:52.480Z,1690824592.480 [Default:CheckIn:Read_GPS] Stopped
2023-07-31T17:29:52.480Z,1690824592.480 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-31T17:29:59.406Z,1690824599.406 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230731T170924/Courier0016.lzma
2023-07-31T17:30:00.410Z,1690824600.410 [DataOverHttps](INFO): Moved sent file to Logs/20230731T170924/Courier0016.lzma.bak
2023-07-31T17:30:00.410Z,1690824600.410 [DataOverHttps](INFO): SBD MOMSN=18503903
2023-07-31T17:30:09.432Z,1690824609.432 [NAL9602](INFO): SBD MO Status=0, MOMSN=44260, MT Status=0, MTMSN=0
2023-07-31T17:30:09.432Z,1690824609.432 [NAL9602](INFO): No messages in MT queue
2023-07-31T17:30:16.034Z,1690824616.034 [DataOverHttps](INFO): Sending 127 bytes from file Logs/20230731T170924/Express0017.lzma
2023-07-31T17:30:17.037Z,1690824617.037 [DataOverHttps](INFO): Moved sent file to Logs/20230731T170924/Express0017.lzma.bak
2023-07-31T17:30:17.037Z,1690824617.037 [DataOverHttps](INFO): SBD MOMSN=18503906
2023-07-31T17:30:18.337Z,1690824618.337 [Default:CheckIn:Read_Iridium] Stopped
2023-07-31T17:30:18.337Z,1690824618.337 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-31T17:30:18.337Z,1690824618.337 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-31T17:30:40.192Z,1690824640.192 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-31T17:35:19.083Z,1690824919.083 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-31T17:35:19.083Z,1690824919.083 [Default:CheckIn:C.Wait] Stopped
2023-07-31T17:35:19.083Z,1690824919.083 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-31T17:35:19.083Z,1690824919.083 [Default:CheckIn:D] Running Loop=1
2023-07-31T17:35:19.478Z,1690824919.478 [Default:CheckIn:D] Stopped
2023-07-31T17:35:19.478Z,1690824919.478 [Default:CheckIn:E] Running Loop=1
2023-07-31T17:35:19.886Z,1690824919.886 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 22.874373 min 
2023-07-31T17:35:19.886Z,1690824919.886 [Default:CheckIn:E] Stopped
2023-07-31T17:35:19.886Z,1690824919.886 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-31T17:35:19.887Z,1690824919.887 [Default:CheckIn] Stopped
2023-07-31T17:35:19.887Z,1690824919.887 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-31T17:35:19.887Z,1690824919.887 [Default:CheckIn](INFO): Running loop #5
2023-07-31T17:35:19.887Z,1690824919.887 [Default:CheckIn] Running Loop=5
2023-07-31T17:35:19.887Z,1690824919.887 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-31T17:35:19.887Z,1690824919.887 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-31T17:35:21.896Z,1690824921.896 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173521.00,A,3648.15019,N,12147.22278,W,0.019,19.67,310723,,,D*46
2023-07-31T17:35:21.898Z,1690824921.898 [NAL9602](INFO): GPS fix at 20230731T173521: (36.802503, -121.787046)
2023-07-31T17:35:21.909Z,1690824921.909 [Default:CheckIn:Read_GPS] Stopped
2023-07-31T17:35:21.909Z,1690824921.909 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-31T17:35:29.078Z,1690824929.078 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230731T170924/Courier0019.lzma
2023-07-31T17:35:30.081Z,1690824930.081 [DataOverHttps](INFO): Moved sent file to Logs/20230731T170924/Courier0019.lzma.bak
2023-07-31T17:35:30.081Z,1690824930.081 [DataOverHttps](INFO): SBD MOMSN=18503910
2023-07-31T17:35:45.703Z,1690824945.703 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230731T170924/Express0020.lzma
2023-07-31T17:35:46.705Z,1690824946.705 [DataOverHttps](INFO): Moved sent file to Logs/20230731T170924/Express0020.lzma.bak
2023-07-31T17:35:46.705Z,1690824946.705 [DataOverHttps](INFO): SBD MOMSN=18503913
2023-07-31T17:35:47.780Z,1690824947.780 [Default:CheckIn:Read_Iridium] Stopped
2023-07-31T17:35:47.780Z,1690824947.780 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-31T17:35:47.780Z,1690824947.780 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-31T17:38:04.414Z,1690825084.414 [NAL9602](INFO): SBD MO Status=2, MOMSN=44261, MT Status=2, MTMSN=0
2023-07-31T17:38:04.414Z,1690825084.414 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-31T17:38:12.086Z,1690825092.086 [NAL9602](INFO): SBD MO Status=0, MOMSN=44261, MT Status=0, MTMSN=0
2023-07-31T17:38:12.086Z,1690825092.086 [NAL9602](INFO): No messages in MT queue
2023-07-31T17:38:42.824Z,1690825122.824 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-31T17:40:48.577Z,1690825248.577 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-31T17:40:48.577Z,1690825248.577 [Default:CheckIn:C.Wait] Stopped
2023-07-31T17:40:48.577Z,1690825248.577 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-31T17:40:48.577Z,1690825248.577 [Default:CheckIn:D] Running Loop=1
2023-07-31T17:40:48.980Z,1690825248.980 [Default:CheckIn:D] Stopped
2023-07-31T17:40:48.980Z,1690825248.980 [Default:CheckIn:E] Running Loop=1
2023-07-31T17:40:49.373Z,1690825249.373 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 28.366069 min 
2023-07-31T17:40:49.373Z,1690825249.373 [Default:CheckIn:E] Stopped
2023-07-31T17:40:49.373Z,1690825249.373 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-31T17:40:49.373Z,1690825249.373 [Default:CheckIn] Stopped
2023-07-31T17:40:49.374Z,1690825249.374 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-31T17:40:49.374Z,1690825249.374 [Default:CheckIn](INFO): Running loop #6
2023-07-31T17:40:49.374Z,1690825249.374 [Default:CheckIn] Running Loop=6
2023-07-31T17:40:49.374Z,1690825249.374 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-31T17:40:49.374Z,1690825249.374 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-31T17:40:51.398Z,1690825251.398 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174050.00,A,3648.15037,N,12147.22260,W,0.408,19.67,310723,,,A*46
2023-07-31T17:40:51.400Z,1690825251.400 [NAL9602](INFO): GPS fix at 20230731T174050: (36.802506, -121.787043)
2023-07-31T17:40:51.410Z,1690825251.410 [Default:CheckIn:Read_GPS] Stopped
2023-07-31T17:40:51.410Z,1690825251.410 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-31T17:40:59.510Z,1690825259.510 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230731T170924/Courier0022.lzma
2023-07-31T17:41:00.514Z,1690825260.514 [DataOverHttps](INFO): Moved sent file to Logs/20230731T170924/Courier0022.lzma.bak
2023-07-31T17:41:00.514Z,1690825260.514 [DataOverHttps](INFO): SBD MOMSN=18503917
2023-07-31T17:41:16.247Z,1690825276.247 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230731T170924/Express0023.lzma
2023-07-31T17:41:17.249Z,1690825277.249 [DataOverHttps](INFO): Moved sent file to Logs/20230731T170924/Express0023.lzma.bak
2023-07-31T17:41:17.249Z,1690825277.249 [DataOverHttps](INFO): SBD MOMSN=18503920
2023-07-31T17:41:18.616Z,1690825278.616 [Default:CheckIn:Read_Iridium] Stopped
2023-07-31T17:41:18.616Z,1690825278.616 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-31T17:41:18.616Z,1690825278.616 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-31T17:41:26.287Z,1690825286.287 [NAL9602](INFO): SBD MO Status=0, MOMSN=44262, MT Status=0, MTMSN=0
2023-07-31T17:41:26.287Z,1690825286.287 [NAL9602](INFO): No messages in MT queue
2023-07-31T17:41:56.988Z,1690825316.988 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-31T17:46:19.332Z,1690825579.332 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-31T17:46:19.332Z,1690825579.332 [Default:CheckIn:C.Wait] Stopped
2023-07-31T17:46:19.332Z,1690825579.332 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-31T17:46:19.332Z,1690825579.332 [Default:CheckIn:D] Running Loop=1
2023-07-31T17:46:19.723Z,1690825579.723 [Default:CheckIn:D] Stopped
2023-07-31T17:46:19.723Z,1690825579.723 [Default:CheckIn:E] Running Loop=1
2023-07-31T17:46:20.151Z,1690825580.151 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 33.878451 min 
2023-07-31T17:46:20.151Z,1690825580.151 [Default:CheckIn:E] Stopped
2023-07-31T17:46:20.152Z,1690825580.152 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-31T17:46:20.152Z,1690825580.152 [Default:CheckIn] Stopped
2023-07-31T17:46:20.152Z,1690825580.152 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-31T17:46:20.152Z,1690825580.152 [Default:CheckIn](INFO): Running loop #7
2023-07-31T17:46:20.152Z,1690825580.152 [Default:CheckIn] Running Loop=7
2023-07-31T17:46:20.152Z,1690825580.152 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-31T17:46:20.152Z,1690825580.152 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-31T17:46:22.122Z,1690825582.122 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174621.00,A,3648.14926,N,12147.22106,W,0.039,69.32,310723,,,A*4C
2023-07-31T17:46:22.125Z,1690825582.125 [NAL9602](INFO): GPS fix at 20230731T174621: (36.802488, -121.787018)
2023-07-31T17:46:22.179Z,1690825582.179 [Default:CheckIn:Read_GPS] Stopped
2023-07-31T17:46:22.179Z,1690825582.179 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-31T17:46:31.971Z,1690825591.971 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230731T170924/Courier0025.lzma
2023-07-31T17:46:32.973Z,1690825592.973 [DataOverHttps](INFO): Moved sent file to Logs/20230731T170924/Courier0025.lzma.bak
2023-07-31T17:46:32.973Z,1690825592.973 [DataOverHttps](INFO): SBD MOMSN=18503925
2023-07-31T17:46:49.643Z,1690825609.643 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230731T170924/Express0026.lzma
2023-07-31T17:46:50.645Z,1690825610.645 [DataOverHttps](INFO): Moved sent file to Logs/20230731T170924/Express0026.lzma.bak
2023-07-31T17:46:50.645Z,1690825610.645 [DataOverHttps](INFO): SBD MOMSN=18503928
2023-07-31T17:46:51.718Z,1690825611.718 [Default:CheckIn:Read_Iridium] Stopped
2023-07-31T17:46:51.718Z,1690825611.718 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-31T17:46:51.718Z,1690825611.718 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-31T17:47:08.697Z,1690825628.697 [NAL9602](INFO): SBD MO Status=0, MOMSN=44263, MT Status=0, MTMSN=0
2023-07-31T17:47:08.698Z,1690825628.698 [NAL9602](INFO): No messages in MT queue
2023-07-31T17:47:39.395Z,1690825659.395 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-31T17:51:52.322Z,1690825912.322 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-31T17:51:52.322Z,1690825912.322 [Default:CheckIn:C.Wait] Stopped
2023-07-31T17:51:52.322Z,1690825912.322 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-31T17:51:52.322Z,1690825912.322 [Default:CheckIn:D] Running Loop=1
2023-07-31T17:51:52.716Z,1690825912.716 [Default:CheckIn:D] Stopped
2023-07-31T17:51:52.716Z,1690825912.716 [Default:CheckIn:E] Running Loop=1
2023-07-31T17:51:53.126Z,1690825913.126 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.428341 min 
2023-07-31T17:51:53.126Z,1690825913.126 [Default:CheckIn:E] Stopped
2023-07-31T17:51:53.126Z,1690825913.126 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-31T17:51:53.126Z,1690825913.126 [Default:CheckIn] Stopped
2023-07-31T17:51:53.126Z,1690825913.126 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-31T17:51:53.127Z,1690825913.127 [Default:CheckIn](INFO): Running loop #8
2023-07-31T17:51:53.127Z,1690825913.127 [Default:CheckIn] Running Loop=8
2023-07-31T17:51:53.127Z,1690825913.127 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-31T17:51:53.127Z,1690825913.127 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-31T17:51:55.146Z,1690825915.146 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175154.00,A,3648.23356,N,12147.14349,W,3.693,15.61,310723,,,D*40
2023-07-31T17:51:55.148Z,1690825915.148 [NAL9602](INFO): GPS fix at 20230731T175154: (36.803893, -121.785725)
2023-07-31T17:51:55.158Z,1690825915.158 [Default:CheckIn:Read_GPS] Stopped
2023-07-31T17:51:55.158Z,1690825915.158 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-31T17:52:02.366Z,1690825922.366 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230731T170924/Courier0028.lzma
2023-07-31T17:52:03.369Z,1690825923.369 [DataOverHttps](INFO): Moved sent file to Logs/20230731T170924/Courier0028.lzma.bak
2023-07-31T17:52:03.369Z,1690825923.369 [DataOverHttps](INFO): SBD MOMSN=18503933
2023-07-31T17:52:19.785Z,1690825939.785 [NAL9602](INFO): SBD MO Status=0, MOMSN=44264, MT Status=0, MTMSN=0
2023-07-31T17:52:19.785Z,1690825939.785 [NAL9602](INFO): No messages in MT queue
2023-07-31T17:52:20.143Z,1690825940.143 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20230731T170924/Express0029.lzma
2023-07-31T17:52:21.145Z,1690825941.145 [DataOverHttps](INFO): Moved sent file to Logs/20230731T170924/Express0029.lzma.bak
2023-07-31T17:52:21.145Z,1690825941.145 [DataOverHttps](INFO): SBD MOMSN=18503936
2023-07-31T17:52:22.217Z,1690825942.217 [Default:CheckIn:Read_Iridium] Stopped
2023-07-31T17:52:22.217Z,1690825942.217 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-31T17:52:22.217Z,1690825942.217 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-31T17:52:50.514Z,1690825970.514 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-31T17:57:22.841Z,1690826242.841 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-31T17:57:22.841Z,1690826242.841 [Default:CheckIn:C.Wait] Stopped
2023-07-31T17:57:22.841Z,1690826242.841 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-31T17:57:22.842Z,1690826242.842 [Default:CheckIn:D] Running Loop=1
2023-07-31T17:57:23.255Z,1690826243.255 [Default:CheckIn:D] Stopped
2023-07-31T17:57:23.255Z,1690826243.255 [Default:CheckIn:E] Running Loop=1
2023-07-31T17:57:23.648Z,1690826243.648 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 44.937317 min 
2023-07-31T17:57:23.649Z,1690826243.649 [Default:CheckIn:E] Stopped
2023-07-31T17:57:23.649Z,1690826243.649 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-31T17:57:23.649Z,1690826243.649 [Default:CheckIn] Stopped
2023-07-31T17:57:23.649Z,1690826243.649 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-31T17:57:23.649Z,1690826243.649 [Default:CheckIn](INFO): Running loop #9
2023-07-31T17:57:23.649Z,1690826243.649 [Default:CheckIn] Running Loop=9
2023-07-31T17:57:23.649Z,1690826243.649 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-31T17:57:23.649Z,1690826243.649 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-31T17:57:25.662Z,1690826245.662 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175725.00,A,3648.41550,N,12147.39669,W,12.091,231.79,310723,,,D*45
2023-07-31T17:57:25.664Z,1690826245.664 [NAL9602](INFO): GPS fix at 20230731T175725: (36.806925, -121.789945)
2023-07-31T17:57:25.674Z,1690826245.674 [Default:CheckIn:Read_GPS] Stopped
2023-07-31T17:57:25.674Z,1690826245.674 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-31T17:57:26.490Z,1690826246.490 [Default:CheckIn:Read_Iridium] Stopped
2023-07-31T17:57:26.490Z,1690826246.490 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-31T17:57:26.490Z,1690826246.490 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-31T17:57:38.994Z,1690826258.994 [NAL9602](INFO): SBD MO Status=0, MOMSN=44265, MT Status=0, MTMSN=0
2023-07-31T17:57:38.994Z,1690826258.994 [NAL9602](INFO): No messages in MT queue
2023-07-31T17:58:09.695Z,1690826289.695 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-31T18:02:27.085Z,1690826547.085 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-31T18:02:27.085Z,1690826547.085 [Default:CheckIn:C.Wait] Stopped
2023-07-31T18:02:27.085Z,1690826547.085 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-31T18:02:27.085Z,1690826547.085 [Default:CheckIn:D] Running Loop=1
2023-07-31T18:02:27.478Z,1690826547.478 [Default:CheckIn:D] Stopped
2023-07-31T18:02:27.478Z,1690826547.478 [Default:CheckIn:E] Running Loop=1
2023-07-31T18:02:27.877Z,1690826547.877 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 50.007699 min 
2023-07-31T18:02:27.877Z,1690826547.877 [Default:CheckIn:E] Stopped
2023-07-31T18:02:27.877Z,1690826547.877 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-31T18:02:27.877Z,1690826547.877 [Default:CheckIn] Stopped
2023-07-31T18:02:27.877Z,1690826547.877 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-31T18:02:27.877Z,1690826547.877 [Default:CheckIn](INFO): Running loop #10
2023-07-31T18:02:27.877Z,1690826547.877 [Default:CheckIn] Running Loop=10
2023-07-31T18:02:27.877Z,1690826547.877 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-31T18:02:27.878Z,1690826547.878 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-31T18:02:29.898Z,1690826549.898 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180229.00,A,3648.27139,N,12149.06532,W,16.503,238.99,310723,,,D*4F
2023-07-31T18:02:29.900Z,1690826549.900 [NAL9602](INFO): GPS fix at 20230731T180229: (36.804523, -121.817755)
2023-07-31T18:02:29.910Z,1690826549.910 [Default:CheckIn:Read_GPS] Stopped
2023-07-31T18:02:29.910Z,1690826549.910 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-31T18:02:37.119Z,1690826557.119 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230731T170924/Courier0031.lzma
2023-07-31T18:02:38.121Z,1690826558.121 [DataOverHttps](INFO): Moved sent file to Logs/20230731T170924/Courier0031.lzma.bak
2023-07-31T18:02:38.121Z,1690826558.121 [DataOverHttps](INFO): SBD MOMSN=18503942
2023-07-31T18:02:46.454Z,1690826566.454 [NAL9602](INFO): SBD MO Status=0, MOMSN=44266, MT Status=0, MTMSN=0
2023-07-31T18:02:46.454Z,1690826566.454 [NAL9602](INFO): No messages in MT queue
2023-07-31T18:02:56.519Z,1690826576.519 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230731T170924/Courier0034.lzma
2023-07-31T18:02:57.521Z,1690826577.521 [DataOverHttps](INFO): Moved sent file to Logs/20230731T170924/Courier0034.lzma.bak
2023-07-31T18:02:57.521Z,1690826577.521 [DataOverHttps](INFO): SBD MOMSN=18503945
2023-07-31T18:03:13.139Z,1690826593.139 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20230731T170924/Express0032.lzma
2023-07-31T18:03:14.141Z,1690826594.141 [DataOverHttps](INFO): Moved sent file to Logs/20230731T170924/Express0032.lzma.bak
2023-07-31T18:03:14.141Z,1690826594.141 [DataOverHttps](INFO): SBD MOMSN=18503948
2023-07-31T18:03:17.235Z,1690826597.235 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-31T18:03:29.747Z,1690826609.747 [DataOverHttps](INFO): Sending 143 bytes from file Logs/20230731T170924/Express0035.lzma
2023-07-31T18:03:30.749Z,1690826610.749 [DataOverHttps](INFO): Moved sent file to Logs/20230731T170924/Express0035.lzma.bak
2023-07-31T18:03:30.749Z,1690826610.749 [DataOverHttps](INFO): SBD MOMSN=18503951
2023-07-31T18:03:31.805Z,1690826611.805 [Default:CheckIn:Read_Iridium] Stopped
2023-07-31T18:03:31.805Z,1690826611.805 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-31T18:03:31.805Z,1690826611.805 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-31T18:08:32.388Z,1690826912.388 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-31T18:08:32.388Z,1690826912.388 [Default:CheckIn:C.Wait] Stopped
2023-07-31T18:08:32.388Z,1690826912.388 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-31T18:08:32.388Z,1690826912.388 [Default:CheckIn:D] Running Loop=1
2023-07-31T18:08:32.772Z,1690826912.772 [Default:CheckIn:D] Stopped
2023-07-31T18:08:32.773Z,1690826912.773 [Default:CheckIn:E] Running Loop=1
2023-07-31T18:08:33.178Z,1690826913.178 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 56.095947 min 
2023-07-31T18:08:33.178Z,1690826913.178 [Default:CheckIn:E] Stopped
2023-07-31T18:08:33.178Z,1690826913.178 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-31T18:08:33.178Z,1690826913.178 [Default:CheckIn] Stopped
2023-07-31T18:08:33.178Z,1690826913.178 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-31T18:08:33.178Z,1690826913.178 [Default:CheckIn](INFO): Running loop #11
2023-07-31T18:08:33.179Z,1690826913.179 [Default:CheckIn] Running Loop=11
2023-07-31T18:08:33.179Z,1690826913.179 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-31T18:08:33.179Z,1690826913.179 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-31T18:08:35.194Z,1690826915.194 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180834.00,A,3647.80955,N,12150.87692,W,1.769,271.72,310723,,,D*71
2023-07-31T18:08:35.196Z,1690826915.196 [NAL9602](INFO): GPS fix at 20230731T180834: (36.796826, -121.847949)
2023-07-31T18:08:35.229Z,1690826915.229 [Default:CheckIn:Read_GPS] Stopped
2023-07-31T18:08:35.229Z,1690826915.229 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-31T18:08:42.422Z,1690826922.422 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230731T170924/Courier0037.lzma
2023-07-31T18:08:43.425Z,1690826923.425 [DataOverHttps](INFO): Moved sent file to Logs/20230731T170924/Courier0037.lzma.bak
2023-07-31T18:08:43.425Z,1690826923.425 [DataOverHttps](INFO): SBD MOMSN=18503956
2023-07-31T18:09:02.749Z,1690826942.749 [NAL9602](INFO): SBD MO Status=2, MOMSN=44267, MT Status=2, MTMSN=0
2023-07-31T18:09:02.750Z,1690826942.750 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-31T18:09:07.111Z,1690826947.111 [DataOverHttps](INFO): Sending 143 bytes from file Logs/20230731T170924/Express0038.lzma
2023-07-31T18:09:08.113Z,1690826948.113 [DataOverHttps](INFO): Moved sent file to Logs/20230731T170924/Express0038.lzma.bak
2023-07-31T18:09:08.113Z,1690826948.113 [DataOverHttps](INFO): SBD MOMSN=18503960
2023-07-31T18:09:09.207Z,1690826949.207 [Default:CheckIn:Read_Iridium] Stopped
2023-07-31T18:09:09.207Z,1690826949.207 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-31T18:09:09.207Z,1690826949.207 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-31T18:09:12.834Z,1690826952.834 [NAL9602](INFO): SBD MO Status=0, MOMSN=44267, MT Status=0, MTMSN=0
2023-07-31T18:09:12.834Z,1690826952.834 [NAL9602](INFO): No messages in MT queue
2023-07-31T18:09:43.536Z,1690826983.536 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-31T18:14:09.832Z,1690827249.832 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-31T18:14:09.832Z,1690827249.832 [Default:CheckIn:C.Wait] Stopped
2023-07-31T18:14:09.832Z,1690827249.832 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-31T18:14:09.833Z,1690827249.833 [Default:CheckIn:D] Running Loop=1
2023-07-31T18:14:10.238Z,1690827250.238 [Default:CheckIn:D] Stopped
2023-07-31T18:14:10.238Z,1690827250.238 [Default:CheckIn:E] Running Loop=1
2023-07-31T18:14:10.654Z,1690827250.654 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 61.720378 min 
2023-07-31T18:14:10.654Z,1690827250.654 [Default:CheckIn:E] Stopped
2023-07-31T18:14:10.655Z,1690827250.655 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-31T18:14:10.655Z,1690827250.655 [Default:CheckIn] Stopped
2023-07-31T18:14:10.655Z,1690827250.655 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-31T18:14:10.655Z,1690827250.655 [Default:CheckIn](INFO): Running loop #12
2023-07-31T18:14:10.655Z,1690827250.655 [Default:CheckIn] Running Loop=12
2023-07-31T18:14:10.655Z,1690827250.655 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-31T18:14:10.655Z,1690827250.655 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-31T18:14:12.658Z,1690827252.658 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181411.00,A,3647.81392,N,12150.88260,W,0.486,296.07,310723,,,D*75
2023-07-31T18:14:12.661Z,1690827252.661 [NAL9602](INFO): GPS fix at 20230731T181411: (36.796899, -121.848043)
2023-07-31T18:14:12.691Z,1690827252.691 [Default:CheckIn:Read_GPS] Stopped
2023-07-31T18:14:12.691Z,1690827252.691 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-31T18:14:20.871Z,1690827260.871 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230731T170924/Courier0040.lzma
2023-07-31T18:14:21.873Z,1690827261.873 [DataOverHttps](INFO): Moved sent file to Logs/20230731T170924/Courier0040.lzma.bak
2023-07-31T18:14:21.873Z,1690827261.873 [DataOverHttps](IMPORTANT): SBD MOMSN=18503969, MTMSN=20230731T181421
2023-07-31T18:14:23.966Z,1690827263.966 [NAL9602](INFO): SBD MO Status=0, MOMSN=44268, MT Status=0, MTMSN=0
2023-07-31T18:14:23.966Z,1690827263.966 [NAL9602](INFO): No messages in MT queue
2023-07-31T18:14:30.911Z,1690827270.911 [DataOverHttps](INFO): Received command: restart logs