2023-10-16T14:38:32.896Z,1697467112.896 [Supervisor](DEBUG): Initializing supervisor. 2023-10-16T14:38:32.900Z,1697467112.900 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2023-10-16T14:38:32.901Z,1697467112.901 [SyncHandler](INFO): Protected caller Thread ID is 3482 2023-10-16T14:38:32.901Z,1697467112.901 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2023-10-16T14:38:32.902Z,1697467112.902 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2023-10-16T14:38:32.903Z,1697467112.903 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 3483 2023-10-16T14:38:32.907Z,1697467112.907 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2023-10-16T14:38:32.924Z,1697467112.924 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2023-10-16T14:38:32.924Z,1697467112.924 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2023-10-16T14:38:32.925Z,1697467112.925 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 3484 2023-10-16T14:38:32.929Z,1697467112.929 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2023-10-16T14:38:32.930Z,1697467112.930 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2023-10-16T14:38:32.930Z,1697467112.930 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 3485 2023-10-16T14:38:32.932Z,1697467112.932 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2023-10-16T14:38:32.933Z,1697467112.933 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2023-10-16T14:38:32.934Z,1697467112.934 [logger ThreadHandler](INFO): Protected caller Thread ID is 3486 2023-10-16T14:38:32.937Z,1697467112.937 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2023-10-16T14:38:32.937Z,1697467112.937 [Supervisor](INFO): Looking for Config files in directory: Config/ 2023-10-16T14:38:32.939Z,1697467112.939 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2023-10-16T14:38:33.034Z,1697467113.034 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2023-10-16T14:38:33.034Z,1697467113.034 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2023-10-16T14:38:33.704Z,1697467113.704 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2023-10-16T14:38:33.704Z,1697467113.704 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2023-10-16T14:38:33.916Z,1697467113.916 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2023-10-16T14:38:33.916Z,1697467113.916 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2023-10-16T14:38:33.996Z,1697467113.996 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2023-10-16T14:38:34.124Z,1697467114.124 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2023-10-16T14:38:34.125Z,1697467114.125 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2023-10-16T14:38:34.206Z,1697467114.206 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2023-10-16T14:38:34.311Z,1697467114.311 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2023-10-16T14:38:34.312Z,1697467114.312 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2023-10-16T14:38:34.680Z,1697467114.680 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2023-10-16T14:38:34.680Z,1697467114.680 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2023-10-16T14:38:35.148Z,1697467115.148 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2023-10-16T14:38:35.149Z,1697467115.149 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2023-10-16T14:38:35.356Z,1697467115.356 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2023-10-16T14:38:35.357Z,1697467115.357 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2023-10-16T14:38:35.547Z,1697467115.547 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2023-10-16T14:38:35.548Z,1697467115.548 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2023-10-16T14:38:36.158Z,1697467116.158 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2023-10-16T14:38:36.159Z,1697467116.159 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2023-10-16T14:38:36.432Z,1697467116.432 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2023-10-16T14:38:36.432Z,1697467116.432 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2023-10-16T14:38:36.675Z,1697467116.675 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2023-10-16T14:38:36.676Z,1697467116.676 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2023-10-16T14:38:37.785Z,1697467117.785 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2023-10-16T14:38:37.785Z,1697467117.785 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2023-10-16T14:38:38.107Z,1697467118.107 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2023-10-16T14:38:38.108Z,1697467118.108 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/ 2023-10-16T14:38:38.109Z,1697467118.109 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg 2023-10-16T14:38:38.194Z,1697467118.194 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg 2023-10-16T14:38:38.355Z,1697467118.355 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg 2023-10-16T14:38:38.458Z,1697467118.458 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg 2023-10-16T14:38:38.544Z,1697467118.544 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg 2023-10-16T14:38:38.639Z,1697467118.639 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg 2023-10-16T14:38:38.752Z,1697467118.752 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg 2023-10-16T14:38:39.015Z,1697467119.015 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2023-10-16T14:38:39.016Z,1697467119.016 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg 2023-10-16T14:38:39.110Z,1697467119.110 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg 2023-10-16T14:38:39.210Z,1697467119.210 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg 2023-10-16T14:38:39.347Z,1697467119.347 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg 2023-10-16T14:38:39.448Z,1697467119.448 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/root/ 2023-10-16T14:38:39.448Z,1697467119.448 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2023-10-16T14:38:39.458Z,1697467119.458 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2023-10-16T14:38:39.580Z,1697467119.580 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2023-10-16T14:38:39.580Z,1697467119.580 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2023-10-16T14:38:39.646Z,1697467119.646 [VerticalControl](DEBUG): Construct VerticalControl. 2023-10-16T14:38:39.705Z,1697467119.705 [VerticalControl] Loaded 2023-10-16T14:38:39.705Z,1697467119.705 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2023-10-16T14:38:39.708Z,1697467119.708 [HorizontalControl](DEBUG): Construct HorizontalControl. 2023-10-16T14:38:39.748Z,1697467119.748 [HorizontalControl] Loaded 2023-10-16T14:38:39.748Z,1697467119.748 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2023-10-16T14:38:39.750Z,1697467119.750 [SpeedControl](DEBUG): Construct SpeedControl. 2023-10-16T14:38:39.753Z,1697467119.753 [SpeedControl] Loaded 2023-10-16T14:38:39.754Z,1697467119.754 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2023-10-16T14:38:39.756Z,1697467119.756 [LoopControl](DEBUG): Construct LoopControl. 2023-10-16T14:38:39.757Z,1697467119.757 [LoopControl] Loaded 2023-10-16T14:38:39.757Z,1697467119.757 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2023-10-16T14:38:39.757Z,1697467119.757 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2023-10-16T14:38:39.758Z,1697467119.758 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2023-10-16T14:38:39.825Z,1697467119.825 [DepthRateCalculator] Loaded 2023-10-16T14:38:39.826Z,1697467119.826 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2023-10-16T14:38:39.830Z,1697467119.830 [PitchRateCalculator] Loaded 2023-10-16T14:38:39.831Z,1697467119.831 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2023-10-16T14:38:39.840Z,1697467119.840 [SpeedCalculator] Loaded 2023-10-16T14:38:39.841Z,1697467119.841 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2023-10-16T14:38:39.845Z,1697467119.845 [YawRateCalculator] Loaded 2023-10-16T14:38:39.845Z,1697467119.845 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2023-10-16T14:38:39.863Z,1697467119.863 [ElevatorOffsetCalculator] Loaded 2023-10-16T14:38:39.863Z,1697467119.863 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2023-10-16T14:38:39.864Z,1697467119.864 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2023-10-16T14:38:39.865Z,1697467119.865 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2023-10-16T14:38:39.906Z,1697467119.906 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2023-10-16T14:38:39.907Z,1697467119.907 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2023-10-16T14:38:39.987Z,1697467119.987 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2023-10-16T14:38:39.988Z,1697467119.988 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2023-10-16T14:38:40.337Z,1697467120.337 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2023-10-16T14:38:40.337Z,1697467120.337 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2023-10-16T14:38:40.512Z,1697467120.512 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2023-10-16T14:38:40.513Z,1697467120.513 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2023-10-16T14:38:41.184Z,1697467121.184 [AHRS_M2] Loaded 2023-10-16T14:38:41.184Z,1697467121.184 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2023-10-16T14:38:41.423Z,1697467121.423 [BackseatComponent] Loaded 2023-10-16T14:38:41.423Z,1697467121.423 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2023-10-16T14:38:41.466Z,1697467121.466 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 409894E0 2023-10-16T14:38:41.467Z,1697467121.467 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 3569 2023-10-16T14:38:41.470Z,1697467121.470 [LcmUniversalReporter] Loaded 2023-10-16T14:38:41.470Z,1697467121.470 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2023-10-16T14:38:42.804Z,1697467122.804 [BPC1] Loaded 2023-10-16T14:38:42.804Z,1697467122.804 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2023-10-16T14:38:43.007Z,1697467123.007 [DataOverHttps] Loaded 2023-10-16T14:38:43.007Z,1697467123.007 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2023-10-16T14:38:43.021Z,1697467123.021 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409B94E0 2023-10-16T14:38:43.022Z,1697467123.022 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 3570 2023-10-16T14:38:43.045Z,1697467123.045 [Depth_Keller] Loaded 2023-10-16T14:38:43.045Z,1697467123.045 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2023-10-16T14:38:43.050Z,1697467123.050 [DropWeight] Loaded 2023-10-16T14:38:43.050Z,1697467123.050 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2023-10-16T14:38:43.271Z,1697467123.271 [NAL9602] Loaded 2023-10-16T14:38:43.271Z,1697467123.271 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2023-10-16T14:38:43.301Z,1697467123.301 [Onboard] Loaded 2023-10-16T14:38:43.301Z,1697467123.301 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2023-10-16T14:38:43.302Z,1697467123.302 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409E94E0 2023-10-16T14:38:43.302Z,1697467123.302 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 3571 2023-10-16T14:38:43.308Z,1697467123.308 [PowerOnly](INFO): Adding load control power supply at /dev/loadB1 2023-10-16T14:38:43.319Z,1697467123.319 [PowerOnly] Loaded 2023-10-16T14:38:43.320Z,1697467123.320 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread. 2023-10-16T14:38:43.331Z,1697467123.331 [Power24vConverter] Loaded 2023-10-16T14:38:43.331Z,1697467123.331 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2023-10-16T14:38:43.344Z,1697467123.344 [Radio_Surface] Loaded 2023-10-16T14:38:43.345Z,1697467123.345 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2023-10-16T14:38:43.346Z,1697467123.346 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40A194E0 2023-10-16T14:38:43.346Z,1697467123.346 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 3572 2023-10-16T14:38:43.390Z,1697467123.390 [RDI_Pathfinder] Loaded 2023-10-16T14:38:43.391Z,1697467123.391 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread. 2023-10-16T14:38:43.482Z,1697467123.482 [DAT] Loaded 2023-10-16T14:38:43.483Z,1697467123.483 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2023-10-16T14:38:43.483Z,1697467123.483 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40A494E0 2023-10-16T14:38:43.484Z,1697467123.484 [DAT ThreadHandler](INFO): Protected caller Thread ID is 3573 2023-10-16T14:38:43.484Z,1697467123.484 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2023-10-16T14:38:43.485Z,1697467123.485 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2023-10-16T14:38:43.617Z,1697467123.617 [DeadReckonUsingMultipleVelocitySources] Loaded 2023-10-16T14:38:43.617Z,1697467123.617 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2023-10-16T14:38:43.630Z,1697467123.630 [NavChart] Loaded 2023-10-16T14:38:43.631Z,1697467123.631 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2023-10-16T14:38:43.636Z,1697467123.636 [UniversalFixResidualReporter] Loaded 2023-10-16T14:38:43.636Z,1697467123.636 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2023-10-16T14:38:43.637Z,1697467123.637 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2023-10-16T14:38:43.637Z,1697467123.637 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2023-10-16T14:38:43.798Z,1697467123.798 [SBIT](DEBUG): Construct Startup Built In Test. 2023-10-16T14:38:43.807Z,1697467123.807 [SBIT] Loaded 2023-10-16T14:38:43.808Z,1697467123.808 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2023-10-16T14:38:43.811Z,1697467123.811 [IBIT](DEBUG): Construct Initiated Built In Test. 2023-10-16T14:38:43.823Z,1697467123.823 [IBIT] Loaded 2023-10-16T14:38:43.823Z,1697467123.823 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2023-10-16T14:38:43.829Z,1697467123.829 [CBIT](DEBUG): Construct Continuous Built In Test. 2023-10-16T14:38:43.931Z,1697467123.931 [CBIT] Loaded 2023-10-16T14:38:43.931Z,1697467123.931 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2023-10-16T14:38:43.932Z,1697467123.932 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2023-10-16T14:38:43.932Z,1697467123.932 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2023-10-16T14:38:44.087Z,1697467124.087 [BuoyancyServo] Loaded 2023-10-16T14:38:44.088Z,1697467124.088 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2023-10-16T14:38:44.109Z,1697467124.109 [ElevatorServo] Loaded 2023-10-16T14:38:44.109Z,1697467124.109 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2023-10-16T14:38:44.128Z,1697467124.128 [MassServo] Loaded 2023-10-16T14:38:44.129Z,1697467124.129 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2023-10-16T14:38:44.147Z,1697467124.147 [RudderServo] Loaded 2023-10-16T14:38:44.147Z,1697467124.147 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2023-10-16T14:38:44.164Z,1697467124.164 [ThrusterServo] Loaded 2023-10-16T14:38:44.164Z,1697467124.164 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2023-10-16T14:38:44.165Z,1697467124.165 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2023-10-16T14:38:44.166Z,1697467124.166 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2023-10-16T14:38:44.181Z,1697467124.181 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2023-10-16T14:38:44.182Z,1697467124.182 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2023-10-16T14:38:44.399Z,1697467124.399 [CTD_Seabird] Loaded 2023-10-16T14:38:44.400Z,1697467124.400 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2023-10-16T14:38:44.423Z,1697467124.423 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40B944E0 2023-10-16T14:38:44.424Z,1697467124.424 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 3574 2023-10-16T14:38:44.444Z,1697467124.444 [PAR_Licor] Loaded 2023-10-16T14:38:44.444Z,1697467124.444 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2023-10-16T14:38:44.484Z,1697467124.484 [WetLabsBB2FL] Loaded 2023-10-16T14:38:44.484Z,1697467124.484 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2023-10-16T14:38:44.485Z,1697467124.485 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40BC44E0 2023-10-16T14:38:44.486Z,1697467124.486 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 3575 2023-10-16T14:38:44.505Z,1697467124.505 [WetLabsUBAT] Loaded 2023-10-16T14:38:44.505Z,1697467124.505 [ComponentRegistry](DEBUG): Component "WetLabsUBAT" handled in its own thread. 2023-10-16T14:38:44.506Z,1697467124.506 [WetLabsUBAT ThreadHandler](DEBUG): Created PCaller Thread at 40BF44E0 2023-10-16T14:38:44.506Z,1697467124.506 [WetLabsUBAT ThreadHandler](INFO): Protected caller Thread ID is 3576 2023-10-16T14:38:44.507Z,1697467124.507 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2023-10-16T14:38:44.513Z,1697467124.513 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2023-10-16T14:38:44.516Z,1697467124.516 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2023-10-16T14:38:44.528Z,1697467124.528 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2023-10-16T14:38:44.529Z,1697467124.529 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C244E0 2023-10-16T14:38:44.530Z,1697467124.530 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 3577 2023-10-16T14:38:44.534Z,1697467124.534 [Supervisor](INFO): Main Thread ID is 3481 2023-10-16T14:38:44.534Z,1697467124.534 [Supervisor](DEBUG): Running supervisor. 2023-10-16T14:38:44.535Z,1697467124.535 [CommandExec ThreadHandler](INFO): Handler Thread ID is 3578 2023-10-16T14:38:44.535Z,1697467124.535 [CommandExec](INFO): Initializing the command executive. 2023-10-16T14:38:44.537Z,1697467124.537 [CommandLine ThreadHandler](INFO): Handler Thread ID is 3579 2023-10-16T14:38:44.539Z,1697467124.539 [controlThread ThreadHandler](INFO): Handler Thread ID is 3580 2023-10-16T14:38:44.540Z,1697467124.540 [controlThread](DEBUG): Initializing ControlThread 2023-10-16T14:38:44.540Z,1697467124.540 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2023-10-16T14:38:44.542Z,1697467124.542 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2023-10-16T14:38:44.543Z,1697467124.543 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2023-10-16T14:38:44.544Z,1697467124.544 [LoopControl](DEBUG): Initialize LoopControlComponent. 2023-10-16T14:38:44.544Z,1697467124.544 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2023-10-16T14:38:44.544Z,1697467124.544 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2023-10-16T14:38:44.545Z,1697467124.545 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2023-10-16T14:38:44.545Z,1697467124.545 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2023-10-16T14:38:44.545Z,1697467124.545 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2023-10-16T14:38:44.552Z,1697467124.552 [NavChart](DEBUG): Initialize NavChart Navigation. 2023-10-16T14:38:44.552Z,1697467124.552 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2023-10-16T14:38:44.553Z,1697467124.553 [SBIT](INFO): Initialize SBIT Component. 2023-10-16T14:38:44.553Z,1697467124.553 [SBIT](IMPORTANT): git: 2023-10-12 2023-10-16T14:38:44.553Z,1697467124.553 [SBIT](INFO): git hash: f38038725fad7dfee583a1d6cb07fccd712c5d54 2023-10-16T14:38:44.554Z,1697467124.554 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2023-10-16T14:38:44.555Z,1697467124.555 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019 Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021 2023-10-16T14:38:44.556Z,1697467124.556 [SBIT](INFO): Beginning SBIT in 46.000000 seconds. 2023-10-16T14:38:44.556Z,1697467124.556 [IBIT](INFO): Initialize IBIT Component. 2023-10-16T14:38:44.558Z,1697467124.558 [CBIT](DEBUG): Initialize CBIT Component. 2023-10-16T14:38:44.558Z,1697467124.558 [logger ThreadHandler](INFO): Handler Thread ID is 3581 2023-10-16T14:38:44.569Z,1697467124.569 [CBIT](DEBUG): Initialized mux pins. 2023-10-16T14:38:44.569Z,1697467124.569 [CBIT](DEBUG): Initializing the watchdog timer. 2023-10-16T14:38:44.578Z,1697467124.578 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 3582 2023-10-16T14:38:44.590Z,1697467124.590 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 3583 2023-10-16T14:38:44.591Z,1697467124.591 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2023-10-16T14:38:44.593Z,1697467124.593 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2023-10-16T14:38:44.594Z,1697467124.594 [CBIT](DEBUG): Initializing heartbeat. 2023-10-16T14:38:44.602Z,1697467124.602 [Onboard ThreadHandler](INFO): Handler Thread ID is 3584 2023-10-16T14:38:44.619Z,1697467124.619 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 3585 2023-10-16T14:38:44.638Z,1697467124.638 [DAT ThreadHandler](INFO): Handler Thread ID is 3586 2023-10-16T14:38:44.639Z,1697467124.639 [DAT](INFO): Powering up 2023-10-16T14:38:44.639Z,1697467124.639 [DAT](DEBUG): Initializing DAT. 2023-10-16T14:38:44.643Z,1697467124.643 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 3588 2023-10-16T14:38:44.643Z,1697467124.643 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2023-10-16T14:38:44.647Z,1697467124.647 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 3590 2023-10-16T14:38:44.650Z,1697467124.650 [WetLabsBB2FL](INFO): Powering up 2023-10-16T14:38:44.651Z,1697467124.651 [WetLabsUBAT ThreadHandler](INFO): Handler Thread ID is 3592 2023-10-16T14:38:44.654Z,1697467124.654 [WetLabsUBAT](INFO): Powering up 2023-10-16T14:38:44.655Z,1697467124.655 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 3594 2023-10-16T14:38:44.660Z,1697467124.660 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2023-10-16T14:38:44.660Z,1697467124.660 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2023-10-16T14:38:44.660Z,1697467124.660 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2023-10-16T14:38:44.660Z,1697467124.660 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2023-10-16T14:38:44.660Z,1697467124.660 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2023-10-16T14:38:44.661Z,1697467124.661 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2023-10-16T14:38:44.661Z,1697467124.661 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2023-10-16T14:38:44.661Z,1697467124.661 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2023-10-16T14:38:44.665Z,1697467124.665 [CBIT](DEBUG): Deactivating GF circuits. 2023-10-16T14:38:44.666Z,1697467124.666 [CBIT](DEBUG): Deactivating emergency mode. 2023-10-16T14:38:44.705Z,1697467124.705 [CBIT](DEBUG): Backplane powered. 2023-10-16T14:38:44.710Z,1697467124.710 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml 2023-10-16T14:38:44.763Z,1697467124.763 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2023-10-16T14:38:44.798Z,1697467124.798 [MissionManager](DEBUG): 2023-10-16T14:38:44.799Z,1697467124.799 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml 2023-10-16T14:38:44.924Z,1697467124.924 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2023-10-16T14:38:44.925Z,1697467124.925 [Default:A.Wait](DEBUG): Construct Wait. 2023-10-16T14:38:44.928Z,1697467124.928 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2023-10-16T14:38:44.972Z,1697467124.972 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2023-10-16T14:38:44.975Z,1697467124.975 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2023-10-16T14:38:44.990Z,1697467124.990 [Default:E.Execute](DEBUG): Construct Execute. 2023-10-16T14:38:44.993Z,1697467124.993 [MissionManager](DEBUG): 0 Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. 13 Burn on Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2023-10-16T14:38:45.021Z,1697467125.021 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,PowerOnly,Power24vConverter,RDI_Pathfinder,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter, 2023-10-16T14:38:45.025Z,1697467125.025 [Radio_Surface](INFO): Powering up 2023-10-16T14:38:45.049Z,1697467125.049 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2023-10-16T14:38:45.127Z,1697467125.127 [Depth_Keller](ERROR): Pressure or depth reading out of range: -1.000394 decibar, -0.993016 m 2023-10-16T14:38:45.129Z,1697467125.129 [PowerOnly](INFO): Powering up loadControl 2023-10-16T14:38:45.150Z,1697467125.150 [Power24vConverter](INFO): Powering up. 2023-10-16T14:38:45.151Z,1697467125.151 [RDI_Pathfinder](IMPORTANT): Expecting PD13 message format 2023-10-16T14:38:45.164Z,1697467125.164 [DepthRateCalculator](ERROR): Depth measurement is not active 2023-10-16T14:38:45.196Z,1697467125.196 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2023-10-16T14:38:45.202Z,1697467125.202 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2023-10-16T14:38:45.203Z,1697467125.203 [ElevatorServo](DEBUG): Initializing EZServoServo. 2023-10-16T14:38:45.210Z,1697467125.210 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2023-10-16T14:38:45.211Z,1697467125.211 [MassServo](DEBUG): Initializing EZServoServo. 2023-10-16T14:38:45.218Z,1697467125.218 [MassServo](DEBUG): Initializing MassServo. 2023-10-16T14:38:45.218Z,1697467125.218 [RudderServo](DEBUG): Initializing EZServoServo. 2023-10-16T14:38:45.226Z,1697467125.226 [RudderServo](DEBUG): Initializing RudderServo. 2023-10-16T14:38:45.227Z,1697467125.227 [ThrusterServo](DEBUG): Initializing EZServoServo. 2023-10-16T14:38:45.234Z,1697467125.234 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2023-10-16T14:38:47.261Z,1697467127.261 [WetLabsBB2FL](INFO): Powering down 2023-10-16T14:38:53.929Z,1697467133.929 [WetLabsUBAT](INFO): Powering down 2023-10-16T14:38:56.990Z,1697467136.990 [DAT](INFO): DAT read: 2023-10-16T14:38:56.992Z,1697467136.992 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2023-10-16T14:38:58.502Z,1697467138.502 [DAT](INFO): DAT read: MF Frequency Band 2023-10-16T14:38:58.504Z,1697467138.504 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2023-10-16T14:38:58.504Z,1697467138.504 [DAT](INFO): DAT read: Oct 11 2023 23:07:40 2023-10-16T14:38:58.982Z,1697467138.982 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.054805 2023-10-16T14:38:59.763Z,1697467139.763 [DAT](INFO): DAT read: Features enabled [Bearing] 2023-10-16T14:38:59.764Z,1697467139.764 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP 2023-10-16T14:38:59.764Z,1697467139.764 [DAT](INFO): commRate: 800 2023-10-16T14:39:01.829Z,1697467141.829 [DAT](INFO): entering command mode 2023-10-16T14:39:02.030Z,1697467142.030 [DAT](INFO): DAT read: 2023-10-16T14:39:02.031Z,1697467142.031 [DAT](INFO): DAT read: user:1> 2023-10-16T14:39:02.031Z,1697467142.031 [DAT](INFO): setting verbose to 3 2023-10-16T14:39:02.282Z,1697467142.282 [DAT](INFO): DAT read: user:1> 2023-10-16T14:39:02.284Z,1697467142.284 [DAT](INFO): DAT read: Verbose | 3 2023-10-16T14:39:02.284Z,1697467142.284 [DAT](INFO): set verbose to 3 2023-10-16T14:39:02.284Z,1697467142.284 [DAT](INFO): setting DatVerbose to 27440 2023-10-16T14:39:02.534Z,1697467142.534 [DAT](INFO): DAT read: user:2> 2023-10-16T14:39:02.535Z,1697467142.535 [DAT](INFO): DAT read: DatVerbose | 27440 2023-10-16T14:39:02.536Z,1697467142.536 [DAT](INFO): set DatVerbose to 27440 2023-10-16T14:39:02.536Z,1697467142.536 [DAT](INFO): setting transmit power to 8 2023-10-16T14:39:02.788Z,1697467142.788 [DAT](INFO): DAT read: user:3> 2023-10-16T14:39:02.792Z,1697467142.792 [DAT](INFO): DAT read: TxPower | 8 (Max) 2023-10-16T14:39:02.793Z,1697467142.793 [DAT](INFO): set transmit power to 8 2023-10-16T14:39:02.794Z,1697467142.794 [DAT](INFO): setting local address to 10 2023-10-16T14:39:03.042Z,1697467143.042 [DAT](INFO): DAT read: user:4> 2023-10-16T14:39:03.044Z,1697467143.044 [DAT](INFO): DAT read: LocalAddr | 10 2023-10-16T14:39:03.044Z,1697467143.044 [DAT](INFO): set local address to 10 2023-10-16T14:39:03.045Z,1697467143.045 [DAT](INFO): Setting time to: 14:39:3 And date to:10/16/2023 2023-10-16T14:39:03.290Z,1697467143.290 [DAT](INFO): DAT read: user:5> 2023-10-16T14:39:03.291Z,1697467143.291 [DAT](INFO): DAT read: Mon Oct 16, 2023 14:39:03 2023-10-16T14:39:03.291Z,1697467143.291 [DAT](INFO): Local DAT time set to Mon Oct 16, 2023 14:39:03 2023-10-16T14:39:13.399Z,1697467153.399 [NAL9602](INFO): Powering up NAL9602 2023-10-16T14:39:17.070Z,1697467157.070 [CommandExec](IMPORTANT): got command failComponent 2023-10-16T14:39:17.070Z,1697467157.070 [CommandExec](IMPORTANT): Failed components: 2023-10-16T14:39:17.071Z,1697467157.071 [CommandExec](IMPORTANT): No failed Components. 2023-10-16T14:39:24.307Z,1697467164.307 [NAL9602](INFO): NAL9602 initialized 2023-10-16T14:39:31.223Z,1697467171.223 [SBIT](IMPORTANT): Beginning Startup BIT 2023-10-16T14:39:31.231Z,1697467171.231 [CBIT](IMPORTANT): Beginning ground fault scan 2023-10-16T14:39:41.631Z,1697467181.631 [CommandExec](IMPORTANT): got command strobe off 2023-10-16T14:39:41.631Z,1697467181.631 [CommandExec](IMPORTANT): Deactivating strobe 2023-10-16T14:39:42.175Z,1697467182.175 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.010640 CHAN A1 (24V): 0.001292 CHAN A2 (12V): -0.007435 CHAN A3 (5V): -0.001227 CHAN B0 (3.3V): 0.000187 CHAN B1 (3.15aV): 0.000887 CHAN B2 (3.15bV): 0.000140 CHAN B3 (GND): 0.001238 OPEN: 0.005265 Full Scale: +/- 1 mA 2023-10-16T14:40:11.181Z,1697467211.181 [NAL9602](INFO): SBD MO Status=2, MOMSN=31844, MT Status=2, MTMSN=0 2023-10-16T14:40:11.181Z,1697467211.181 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-10-16T14:40:24.933Z,1697467224.933 [SBIT](IMPORTANT): SBIT PASSED 2023-10-16T14:40:24.934Z,1697467224.934 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2023-10-16T14:40:24.935Z,1697467224.935 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count; 2023-10-16T14:40:24.935Z,1697467224.935 [SBIT](IMPORTANT): Express none CTD_Seabird.bin_median_sea_water_salinity; 2023-10-16T14:40:24.935Z,1697467224.935 [SBIT](IMPORTANT): Express linearApproximation PowerOnly.component_avgCurrent_loadControl 50.000000 milliampere; 2023-10-16T14:40:24.935Z,1697467224.935 [SBIT](IMPORTANT): Express linearApproximation WetLabsUBAT.flow_rate 0.300000 liter_per_second; 2023-10-16T14:40:24.935Z,1697467224.935 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=235.728337 cubic_centimeter; 2023-10-16T14:40:24.935Z,1697467224.935 [SBIT](IMPORTANT): VerticalControl.kdPitchMass=0 second; 2023-10-16T14:40:24.935Z,1697467224.935 [SBIT](IMPORTANT): VerticalControl.kiPitchMass=0.0015 reciprocal_second; 2023-10-16T14:40:24.935Z,1697467224.935 [SBIT](IMPORTANT): VerticalControl.kpPitchMass=0.01 none; 2023-10-16T14:40:24.936Z,1697467224.936 [SBIT](IMPORTANT): VerticalControl.massDeadband=0.1 millimeter; 2023-10-16T14:40:24.936Z,1697467224.936 [SBIT](IMPORTANT): VerticalControl.massDefault=6.637162 millimeter; 2023-10-16T14:40:25.340Z,1697467225.340 [MissionManager](IMPORTANT): Started mission Startup 2023-10-16T14:40:25.340Z,1697467225.340 [Startup] Running Loop=1 2023-10-16T14:40:25.340Z,1697467225.340 [Startup](DEBUG): Aggregate::initialize Startup 2023-10-16T14:40:25.341Z,1697467225.341 [Startup:A.GoToSurface] Running Loop=1 2023-10-16T14:40:25.341Z,1697467225.341 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2023-10-16T14:40:25.341Z,1697467225.341 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2023-10-16T14:40:25.342Z,1697467225.342 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2023-10-16T14:40:25.342Z,1697467225.342 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2023-10-16T14:40:25.343Z,1697467225.343 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2023-10-16T14:40:25.343Z,1697467225.343 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2023-10-16T14:40:25.344Z,1697467225.344 [Startup:StartupSatComms] Running Loop=1 2023-10-16T14:40:25.344Z,1697467225.344 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2023-10-16T14:40:25.344Z,1697467225.344 [Startup:StartupSatComms:A] Running Loop=1 2023-10-16T14:40:25.733Z,1697467225.733 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2023-10-16T14:40:51.581Z,1697467251.581 [NAL9602](INFO): SBD MO Status=2, MOMSN=31844, MT Status=2, MTMSN=0 2023-10-16T14:40:51.581Z,1697467251.581 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-10-16T14:41:18.860Z,1697467278.860 [CommandExec](IMPORTANT): got command ! /etc/rc.d/init.dsettime restart 2023-10-16T14:41:25.544Z,1697467285.544 [Startup:StartupSatComms:A](INFO): Timed out from 2023-10-16T14:40:25.3Z 2023-10-16T14:41:25.544Z,1697467285.544 [Startup:StartupSatComms:A] Stopped 2023-10-16T14:41:25.544Z,1697467285.544 [Startup:StartupSatComms:B] Running Loop=1 2023-10-16T14:41:25.989Z,1697467285.989 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2023-10-16T14:41:33.257Z,1697467293.257 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20231016T143832/Courier0000.lzma 2023-10-16T14:41:34.259Z,1697467294.259 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0000.lzma.bak 2023-10-16T14:41:34.260Z,1697467294.260 [DataOverHttps](INFO): SBD MOMSN=18997790 2023-10-16T14:41:44.552Z,1697467304.552 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2023-10-16T14:41:44.552Z,1697467304.552 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-10-16T14:41:44.575Z,1697467304.575 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-10-16T14:41:44.925Z,1697467304.925 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-10-16T14:41:44.925Z,1697467304.925 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2023-10-16T14:41:50.531Z,1697467310.531 [DataOverHttps](INFO): Sending 1082 bytes from file Logs/20231016T143832/Express0001.lzma 2023-10-16T14:41:51.531Z,1697467311.531 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0001.lzma.bak 2023-10-16T14:41:51.532Z,1697467311.532 [DataOverHttps](INFO): SBD MOMSN=18997793 2023-10-16T14:41:52.678Z,1697467312.678 [Startup:StartupSatComms:B] Stopped 2023-10-16T14:41:52.678Z,1697467312.678 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2023-10-16T14:41:52.678Z,1697467312.678 [Startup:StartupSatComms] Stopped 2023-10-16T14:41:52.678Z,1697467312.678 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2023-10-16T14:41:52.679Z,1697467312.679 [Startup](INFO): Completed Startup 2023-10-16T14:41:52.679Z,1697467312.679 [MissionManager](INFO): Startup is completed. 2023-10-16T14:41:52.679Z,1697467312.679 [MissionManager](INFO): Uninitializing Mission Startup 2023-10-16T14:41:52.679Z,1697467312.679 [Startup] Stopped 2023-10-16T14:41:52.679Z,1697467312.679 [Startup](DEBUG): Aggregate::uninitialize Startup 2023-10-16T14:41:52.679Z,1697467312.679 [Startup:A.GoToSurface] Stopped 2023-10-16T14:41:52.679Z,1697467312.679 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2023-10-16T14:41:53.004Z,1697467313.004 [MissionManager](IMPORTANT): Started mission Default 2023-10-16T14:41:53.004Z,1697467313.004 [Default] Running Loop=1 2023-10-16T14:41:53.004Z,1697467313.004 [Default](DEBUG): Aggregate::initialize Default 2023-10-16T14:41:53.004Z,1697467313.004 [Default:B.GoToSurface] Running Loop=1 2023-10-16T14:41:53.004Z,1697467313.004 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2023-10-16T14:41:53.004Z,1697467313.004 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2023-10-16T14:41:53.005Z,1697467313.005 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2023-10-16T14:41:53.005Z,1697467313.005 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2023-10-16T14:41:53.006Z,1697467313.006 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2023-10-16T14:41:53.006Z,1697467313.006 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2023-10-16T14:41:53.006Z,1697467313.006 [Default:A.Wait] Running Loop=1 2023-10-16T14:41:53.006Z,1697467313.006 [Default:A.Wait](DEBUG): Initialize Wait Component. 2023-10-16T14:41:58.900Z,1697467318.900 [CommandExec](IMPORTANT): got command ! /etc/rc.d/init.d/settime restart 2023-10-16T14:42:01.446Z,1697467321.446 [CommandExec](IMPORTANT): settime stop or restart Setting hardware clock from system clock Mon Oct 16 14:41:59 2023 0.000000 seconds settime start or restart Setting clock frequency and tick values from nonvolatile memory. mode: 16386 -o offset: 0 -f frequency: 794192 maxerror: 499638 esterror: 15 status: 1 (PLL) -p timeconstant: 6 precision: 1 tolerance: 32768000 -t tick: 10000 time.tv_sec: 1697467319 time.tv_usec: 244319 return value: 0 (clock synchronized) ping returned from NTP server: 216.239.35.4 45213 52920.476 44404.0 0.0 -341690.6 91.6 794192 Time set from NTP server: 216.239.35.4 Setting hardware clock from system clock Mon Oct 16 14:42:01 2023 0.000000 seconds NTPD already running. 2023-10-16T14:42:06.029Z,1697467326.029 [Default:A.Wait](INFO): Done Waiting. 2023-10-16T14:42:06.029Z,1697467326.029 [Default:A.Wait] Stopped 2023-10-16T14:42:06.029Z,1697467326.029 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T14:42:06.440Z,1697467326.440 [Default:CheckIn] Running Loop=1 2023-10-16T14:42:06.440Z,1697467326.440 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T14:42:06.440Z,1697467326.440 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T14:42:06.868Z,1697467326.868 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2023-10-16T14:43:42.158Z,1697467422.158 [BPC1](ERROR): BPC1A: No match for serial number 7FC7 in BPC1A's battery stick inventory (sticks 1-31 in onboard configuration file). 2023-10-16T14:44:27.767Z,1697467467.767 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-10-16T14:44:45.571Z,1697467485.571 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2023-10-16T14:44:45.571Z,1697467485.571 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-10-16T14:44:45.582Z,1697467485.582 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-10-16T14:44:45.979Z,1697467485.979 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-10-16T14:44:45.979Z,1697467485.979 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2023-10-16T14:45:01.783Z,1697467501.783 [CommandExec](IMPORTANT): got command burn on 2023-10-16T14:45:01.783Z,1697467501.783 [CommandExec](IMPORTANT): Activating dropweight wire 2023-10-16T14:45:10.023Z,1697467510.023 [CommandExec](IMPORTANT): got command burn off 2023-10-16T14:45:10.023Z,1697467510.023 [CommandExec](IMPORTANT): Deactivating dropweight wire 2023-10-16T14:46:09.580Z,1697467569.580 [BPC1](ERROR): Battery stick #9 (s/n: 01D1) reported OVER_TEMP_ALARM. Status code: 0x1717. 2023-10-16T14:46:09.581Z,1697467569.581 [BPC1](INFO): Calculating totals. Valid battery stick count: 53. Valid reserve battery stick count: 6. 2023-10-16T14:46:09.584Z,1697467569.584 [BPC1](INFO): Received data from all battery sticks. 2023-10-16T14:46:58.458Z,1697467618.458 [CommandExec](IMPORTANT): got command failComponent 2023-10-16T14:46:58.458Z,1697467618.458 [CommandExec](IMPORTANT): Failed components: 2023-10-16T14:46:58.459Z,1697467618.459 [CommandExec](IMPORTANT): No failed Components. 2023-10-16T14:47:06.564Z,1697467626.564 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-10-16T14:42:06.4Z 2023-10-16T14:47:06.564Z,1697467626.564 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T14:47:06.564Z,1697467626.564 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T14:47:06.973Z,1697467626.973 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2023-10-16T14:47:14.164Z,1697467634.164 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20231016T143832/Courier0004.lzma 2023-10-16T14:47:15.163Z,1697467635.163 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0004.lzma.bak 2023-10-16T14:47:15.164Z,1697467635.164 [DataOverHttps](INFO): SBD MOMSN=18997831 2023-10-16T14:47:31.154Z,1697467651.154 [DataOverHttps](INFO): Sending 717 bytes from file Logs/20231016T143832/Express0005.lzma 2023-10-16T14:47:32.159Z,1697467652.159 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0005.lzma.bak 2023-10-16T14:47:32.159Z,1697467652.159 [DataOverHttps](INFO): SBD MOMSN=18997835 2023-10-16T14:47:33.221Z,1697467653.221 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T14:47:33.221Z,1697467653.221 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T14:47:33.221Z,1697467653.221 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T14:47:46.559Z,1697467666.559 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2023-10-16T14:47:46.559Z,1697467666.559 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-10-16T14:47:46.570Z,1697467666.570 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-10-16T14:47:46.980Z,1697467666.980 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-10-16T14:47:46.980Z,1697467666.980 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2023-10-16T14:49:25.511Z,1697467765.511 [NAL9602](FAULT): GPS failed to acquire within timeout. 2023-10-16T14:49:25.511Z,1697467765.511 [NAL9602] Data Fault, FailCount= 1 2023-10-16T14:49:25.512Z,1697467765.512 [NAL9602](ERROR): Data Fault 2023-10-16T14:49:25.549Z,1697467765.549 [CBIT](ERROR): Data Fault in component: NAL9602 2023-10-16T14:49:25.926Z,1697467765.926 [NAL9602](INFO): Powering down 2023-10-16T14:49:26.749Z,1697467766.749 [CBIT](INFO): Clearing failed state for component NAL9602 2023-10-16T14:49:26.749Z,1697467766.749 [NAL9602] No Fault, FailCount= 1 2023-10-16T14:49:56.219Z,1697467796.219 [NAL9602](INFO): Powering up NAL9602 2023-10-16T14:50:07.121Z,1697467807.121 [NAL9602](INFO): NAL9602 initialized 2023-10-16T14:50:47.559Z,1697467847.559 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2023-10-16T14:50:47.559Z,1697467847.559 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-10-16T14:50:47.600Z,1697467847.600 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-10-16T14:50:47.977Z,1697467847.977 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-10-16T14:50:47.977Z,1697467847.977 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2023-10-16T14:52:33.837Z,1697467953.837 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T14:52:33.837Z,1697467953.837 [Default:CheckIn:C.Wait] Stopped 2023-10-16T14:52:33.837Z,1697467953.837 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T14:52:33.837Z,1697467953.837 [Default:CheckIn:D] Running Loop=1 2023-10-16T14:52:34.290Z,1697467954.290 [Default:CheckIn:D] Stopped 2023-10-16T14:52:34.290Z,1697467954.290 [Default:CheckIn:E] Running Loop=1 2023-10-16T14:52:34.676Z,1697467954.676 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.687827 min 2023-10-16T14:52:34.676Z,1697467954.676 [Default:CheckIn:E] Stopped 2023-10-16T14:52:34.677Z,1697467954.677 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T14:52:34.677Z,1697467954.677 [Default:CheckIn] Stopped 2023-10-16T14:52:34.677Z,1697467954.677 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T14:52:34.677Z,1697467954.677 [Default:CheckIn](INFO): Running loop #2 2023-10-16T14:52:34.677Z,1697467954.677 [Default:CheckIn] Running Loop=2 2023-10-16T14:52:34.677Z,1697467954.677 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T14:52:34.677Z,1697467954.677 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T14:53:48.607Z,1697468028.607 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2023-10-16T14:53:48.607Z,1697468028.607 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-10-16T14:53:48.618Z,1697468028.618 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-10-16T14:53:49.005Z,1697468029.005 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-10-16T14:53:49.005Z,1697468029.005 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2023-10-16T14:56:49.567Z,1697468209.567 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2023-10-16T14:56:49.567Z,1697468209.567 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-10-16T14:56:49.598Z,1697468209.598 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-10-16T14:56:49.981Z,1697468209.981 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-10-16T14:56:49.981Z,1697468209.981 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2023-10-16T14:57:34.816Z,1697468254.816 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-10-16T14:52:34.7Z 2023-10-16T14:57:34.816Z,1697468254.816 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T14:57:34.816Z,1697468254.816 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T14:57:42.159Z,1697468262.159 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20231016T143832/Courier0007.lzma 2023-10-16T14:57:43.139Z,1697468263.139 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0007.lzma.bak 2023-10-16T14:57:43.140Z,1697468263.140 [DataOverHttps](INFO): SBD MOMSN=18997852 2023-10-16T14:57:58.998Z,1697468278.997 [DataOverHttps](INFO): Sending 191 bytes from file Logs/20231016T143832/Express0008.lzma 2023-10-16T14:57:59.999Z,1697468279.999 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0008.lzma.bak 2023-10-16T14:57:59.000Z,1697468280.000 [DataOverHttps](INFO): SBD MOMSN=18997855 2023-10-16T14:58:01.120Z,1697468281.120 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T14:58:01.120Z,1697468281.120 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T14:58:01.120Z,1697468281.120 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T14:59:50.591Z,1697468390.591 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7 2023-10-16T14:59:50.591Z,1697468390.591 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-10-16T14:59:50.610Z,1697468390.610 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-10-16T14:59:51.019Z,1697468391.019 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-10-16T14:59:51.019Z,1697468391.019 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7 2023-10-16T15:00:09.555Z,1697468409.555 [NAL9602](FAULT): GPS failed to acquire within timeout. 2023-10-16T15:00:09.555Z,1697468409.555 [NAL9602] Data Fault, FailCount= 2 2023-10-16T15:00:09.555Z,1697468409.555 [NAL9602](ERROR): Data Fault 2023-10-16T15:00:09.598Z,1697468409.598 [CBIT](ERROR): Data Fault in component: NAL9602 2023-10-16T15:00:09.956Z,1697468409.956 [NAL9602](INFO): Powering down 2023-10-16T15:00:10.804Z,1697468410.804 [CBIT](INFO): Clearing failed state for component NAL9602 2023-10-16T15:00:10.804Z,1697468410.804 [NAL9602] No Fault, FailCount= 2 2023-10-16T15:00:40.255Z,1697468440.255 [NAL9602](INFO): Powering up NAL9602 2023-10-16T15:00:51.167Z,1697468451.167 [NAL9602](INFO): NAL9602 initialized 2023-10-16T15:02:03.889Z,1697468523.889 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150202.00,A,3648.16891,N,12147.24811,W,2.546,191.94,161023,,,A*7F 2023-10-16T15:02:03.908Z,1697468523.908 [NAL9602](INFO): GPS fix at 20231016T150202: (36.802815, -121.787469) 2023-10-16T15:02:36.215Z,1697468556.215 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T15:03:01.682Z,1697468581.682 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T15:03:01.683Z,1697468581.683 [Default:CheckIn:C.Wait] Stopped 2023-10-16T15:03:01.683Z,1697468581.683 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T15:03:01.683Z,1697468581.683 [Default:CheckIn:D] Running Loop=1 2023-10-16T15:03:02.095Z,1697468582.095 [Default:CheckIn:D] Stopped 2023-10-16T15:03:02.095Z,1697468582.095 [Default:CheckIn:E] Running Loop=1 2023-10-16T15:03:02.519Z,1697468582.519 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.151506 min 2023-10-16T15:03:02.519Z,1697468582.519 [Default:CheckIn:E] Stopped 2023-10-16T15:03:02.520Z,1697468582.520 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T15:03:02.520Z,1697468582.520 [Default:CheckIn] Stopped 2023-10-16T15:03:02.520Z,1697468582.520 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T15:03:02.520Z,1697468582.520 [Default:CheckIn](INFO): Running loop #3 2023-10-16T15:03:02.520Z,1697468582.520 [Default:CheckIn] Running Loop=3 2023-10-16T15:03:02.520Z,1697468582.520 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T15:03:02.520Z,1697468582.520 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T15:03:04.501Z,1697468584.501 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150302.00,A,3648.13873,N,12147.24103,W,0.039,70.56,161023,,,A*42 2023-10-16T15:03:04.503Z,1697468584.503 [NAL9602](INFO): GPS fix at 20231016T150302: (36.802312, -121.787351) 2023-10-16T15:03:04.551Z,1697468584.551 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T15:03:04.551Z,1697468584.551 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T15:03:12.601Z,1697468592.601 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20231016T143832/Courier0010.lzma 2023-10-16T15:03:13.603Z,1697468593.603 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0010.lzma.bak 2023-10-16T15:03:13.604Z,1697468593.604 [DataOverHttps](INFO): SBD MOMSN=18997864 2023-10-16T15:03:26.716Z,1697468606.716 [NAL9602](INFO): SBD MO Status=0, MOMSN=31844, MT Status=0, MTMSN=0 2023-10-16T15:03:26.716Z,1697468606.716 [NAL9602](INFO): No messages in MT queue 2023-10-16T15:03:29.987Z,1697468609.987 [DataOverHttps](INFO): Sending 312 bytes from file Logs/20231016T143832/Express0011.lzma 2023-10-16T15:03:30.987Z,1697468610.987 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0011.lzma.bak 2023-10-16T15:03:30.988Z,1697468610.988 [DataOverHttps](INFO): SBD MOMSN=18997867 2023-10-16T15:03:32.403Z,1697468612.403 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T15:03:32.403Z,1697468612.403 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T15:03:32.403Z,1697468612.403 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T15:03:57.419Z,1697468637.419 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T15:06:38.907Z,1697468798.907 [DataOverHttps](IMPORTANT): SBD MTMSN=20231016T150638 2023-10-16T15:06:46.602Z,1697468806.602 [DataOverHttps](INFO): Received command: ibit 2023-10-16T15:06:46.698Z,1697468806.698 [CommandExec](IMPORTANT): got command ibit 2023-10-16T15:06:46.719Z,1697468806.719 [IBIT](IMPORTANT): Beginning Initiated BIT 2023-10-16T15:06:46.719Z,1697468806.719 [IBIT](IMPORTANT): Beginning control surface checks. 2023-10-16T15:06:46.722Z,1697468806.722 [CBIT](IMPORTANT): Beginning ground fault scan 2023-10-16T15:06:48.314Z,1697468808.314 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150647.00,A,3648.14116,N,12147.22995,W,0.019,58.49,161023,,,D*49 2023-10-16T15:06:48.316Z,1697468808.316 [NAL9602](INFO): GPS fix at 20231016T150647: (36.802353, -121.787166) 2023-10-16T15:06:57.636Z,1697468817.636 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.008126 CHAN A1 (24V): 0.001819 CHAN A2 (12V): -0.006544 CHAN A3 (5V): -0.001943 CHAN B0 (3.3V): 0.000117 CHAN B1 (3.15aV): -0.000304 CHAN B2 (3.15bV): 0.000605 CHAN B3 (GND): 0.001226 OPEN: 0.004935 Full Scale: +/- 1 mA 2023-10-16T15:07:08.918Z,1697468828.918 [NAL9602](INFO): SBD MO Status=0, MOMSN=31845, MT Status=0, MTMSN=0 2023-10-16T15:07:08.918Z,1697468828.918 [NAL9602](INFO): No messages in MT queue 2023-10-16T15:07:10.160Z,1697468830.160 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150709.00,A,3648.14056,N,12147.23000,W,0.058,58.49,161023,,,D*46 2023-10-16T15:07:10.163Z,1697468830.163 [NAL9602](INFO): GPS fix at 20231016T150709: (36.802343, -121.787167) 2023-10-16T15:07:12.961Z,1697468832.961 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150712.00,A,3648.14048,N,12147.22998,W,0.019,58.49,161023,,,D*4F 2023-10-16T15:07:12.963Z,1697468832.963 [NAL9602](INFO): GPS fix at 20231016T150712: (36.802341, -121.787166) 2023-10-16T15:07:15.789Z,1697468835.789 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150715.00,A,3648.14047,N,12147.22996,W,0.039,58.49,161023,,,D*4B 2023-10-16T15:07:15.791Z,1697468835.791 [NAL9602](INFO): GPS fix at 20231016T150715: (36.802341, -121.787166) 2023-10-16T15:07:19.017Z,1697468839.017 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150718.00,A,3648.14051,N,12147.22993,W,0.019,58.49,161023,,,D*46 2023-10-16T15:07:19.019Z,1697468839.019 [NAL9602](INFO): GPS fix at 20231016T150718: (36.802342, -121.787166) 2023-10-16T15:07:21.849Z,1697468841.849 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150721.00,A,3648.14054,N,12147.22991,W,0.019,58.49,161023,,,D*4B 2023-10-16T15:07:21.851Z,1697468841.851 [NAL9602](INFO): GPS fix at 20231016T150721: (36.802342, -121.787165) 2023-10-16T15:07:25.081Z,1697468845.081 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150724.00,A,3648.14042,N,12147.22984,W,0.019,58.49,161023,,,D*4D 2023-10-16T15:07:25.083Z,1697468845.083 [NAL9602](INFO): GPS fix at 20231016T150724: (36.802340, -121.787164) 2023-10-16T15:07:27.905Z,1697468847.905 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150727.00,A,3648.14031,N,12147.22976,W,0.000,58.49,161023,,,D*4F 2023-10-16T15:07:27.907Z,1697468847.907 [NAL9602](INFO): GPS fix at 20231016T150727: (36.802338, -121.787163) 2023-10-16T15:07:31.141Z,1697468851.141 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150730.00,A,3648.14023,N,12147.22967,W,0.039,58.49,161023,,,D*40 2023-10-16T15:07:31.143Z,1697468851.143 [NAL9602](INFO): GPS fix at 20231016T150730: (36.802337, -121.787161) 2023-10-16T15:07:33.191Z,1697468853.191 [IBIT](IMPORTANT): Communications Status: Fix Status: 1 Iridium Signal Strength: 2 Latitude: 36.802338 Longitude: -121.787163 2023-10-16T15:07:33.613Z,1697468853.613 [IBIT](IMPORTANT): Battery Status: Battery Charge (AH): 0.000000 Voltage: 16.690001 2023-10-16T15:07:33.613Z,1697468853.613 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah 2023-10-16T15:07:33.618Z,1697468853.618 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V 2023-10-16T15:07:33.973Z,1697468853.973 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150733.00,A,3648.14012,N,12147.22953,W,0.019,58.49,161023,,,D*44 2023-10-16T15:07:33.975Z,1697468853.975 [NAL9602](INFO): GPS fix at 20231016T150733: (36.802335, -121.787159) 2023-10-16T15:07:33.997Z,1697468853.997 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2023-10-16T15:07:33.998Z,1697468853.998 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2023-10-16T15:07:33.998Z,1697468853.998 [IBIT](IMPORTANT): Pressure:7.872576 PSI 2023-10-16T15:07:33.998Z,1697468853.998 [IBIT](IMPORTANT): Humidity:24.679525 % 2023-10-16T15:07:34.450Z,1697468854.450 [IBIT](IMPORTANT): Vehicle Pitch:-0.218250 degrees 2023-10-16T15:07:34.450Z,1697468854.450 [IBIT](IMPORTANT): Vehicle Roll:-3.005028 degrees 2023-10-16T15:07:34.450Z,1697468854.450 [IBIT](IMPORTANT): Vehicle Heading:303.586029 degrees 2023-10-16T15:07:34.817Z,1697468854.817 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m 2023-10-16T15:07:34.817Z,1697468854.817 [IBIT](IMPORTANT): buoyancyNeutral: 235.728333 cc 2023-10-16T15:07:34.818Z,1697468854.818 [IBIT](IMPORTANT): massDefault: 0.663716 cm 2023-10-16T15:07:34.818Z,1697468854.818 [IBIT](IMPORTANT): stopDepth: 215.000000 m 2023-10-16T15:07:34.818Z,1697468854.818 [IBIT](IMPORTANT): abortDepth: 255.000000 m 2023-10-16T15:07:34.818Z,1697468854.818 [IBIT](IMPORTANT): IBIT PASSED 2023-10-16T15:08:06.284Z,1697468886.284 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T15:08:32.962Z,1697468912.962 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T15:08:32.962Z,1697468912.962 [Default:CheckIn:C.Wait] Stopped 2023-10-16T15:08:32.962Z,1697468912.962 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T15:08:32.963Z,1697468912.963 [Default:CheckIn:D] Running Loop=1 2023-10-16T15:08:33.376Z,1697468913.376 [Default:CheckIn:D] Stopped 2023-10-16T15:08:33.376Z,1697468913.376 [Default:CheckIn:E] Running Loop=1 2023-10-16T15:08:33.766Z,1697468913.766 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 26.672864 min 2023-10-16T15:08:33.766Z,1697468913.766 [Default:CheckIn:E] Stopped 2023-10-16T15:08:33.766Z,1697468913.766 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T15:08:33.766Z,1697468913.766 [Default:CheckIn] Stopped 2023-10-16T15:08:33.767Z,1697468913.767 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T15:08:33.767Z,1697468913.767 [Default:CheckIn](INFO): Running loop #4 2023-10-16T15:08:33.767Z,1697468913.767 [Default:CheckIn] Running Loop=4 2023-10-16T15:08:33.767Z,1697468913.767 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T15:08:33.767Z,1697468913.767 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T15:08:35.781Z,1697468915.781 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150835.00,A,3648.13954,N,12147.22922,W,0.019,58.49,161023,,,D*47 2023-10-16T15:08:35.783Z,1697468915.783 [NAL9602](INFO): GPS fix at 20231016T150835: (36.802326, -121.787154) 2023-10-16T15:08:35.796Z,1697468915.796 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T15:08:35.796Z,1697468915.796 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T15:08:43.501Z,1697468923.501 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231016T143832/Courier0013.lzma 2023-10-16T15:08:44.503Z,1697468924.503 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0013.lzma.bak 2023-10-16T15:08:44.504Z,1697468924.504 [DataOverHttps](INFO): SBD MOMSN=18997877 2023-10-16T15:09:00.846Z,1697468940.846 [DataOverHttps](INFO): Sending 823 bytes from file Logs/20231016T143832/Express0014.lzma 2023-10-16T15:09:01.847Z,1697468941.847 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0014.lzma.bak 2023-10-16T15:09:01.848Z,1697468941.848 [DataOverHttps](INFO): SBD MOMSN=18997885 2023-10-16T15:09:03.652Z,1697468943.652 [NAL9602](INFO): SBD MO Status=2, MOMSN=31846, MT Status=2, MTMSN=0 2023-10-16T15:09:03.652Z,1697468943.652 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-10-16T15:09:18.433Z,1697468958.433 [DataOverHttps](INFO): Sending 41 bytes from file Logs/20231016T143832/Express0017.lzma 2023-10-16T15:09:19.435Z,1697468959.435 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0017.lzma.bak 2023-10-16T15:09:19.436Z,1697468959.436 [DataOverHttps](INFO): SBD MOMSN=18997911 2023-10-16T15:09:20.642Z,1697468960.642 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T15:09:20.642Z,1697468960.642 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T15:09:20.643Z,1697468960.643 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T15:09:25.064Z,1697468965.064 [NAL9602](INFO): SBD MO Status=2, MOMSN=31846, MT Status=2, MTMSN=0 2023-10-16T15:09:25.065Z,1697468965.065 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-10-16T15:10:02.236Z,1697469002.236 [NAL9602](INFO): SBD MO Status=2, MOMSN=31846, MT Status=2, MTMSN=0 2023-10-16T15:10:02.236Z,1697469002.236 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-10-16T15:10:13.144Z,1697469013.144 [NAL9602](INFO): SBD MO Status=0, MOMSN=31846, MT Status=0, MTMSN=0 2023-10-16T15:10:13.144Z,1697469013.144 [NAL9602](INFO): No messages in MT queue 2023-10-16T15:10:28.512Z,1697469028.512 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS +0.00, +0.00, +0.00, 20.00,1893.93 2023-10-16T15:10:43.914Z,1697469043.914 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T15:14:21.342Z,1697469261.342 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T15:14:21.342Z,1697469261.342 [Default:CheckIn:C.Wait] Stopped 2023-10-16T15:14:21.342Z,1697469261.342 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T15:14:21.342Z,1697469261.342 [Default:CheckIn:D] Running Loop=1 2023-10-16T15:14:21.762Z,1697469261.762 [Default:CheckIn:D] Stopped 2023-10-16T15:14:21.762Z,1697469261.762 [Default:CheckIn:E] Running Loop=1 2023-10-16T15:14:22.253Z,1697469262.253 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 32.479305 min 2023-10-16T15:14:22.253Z,1697469262.253 [Default:CheckIn:E] Stopped 2023-10-16T15:14:22.253Z,1697469262.253 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T15:14:22.253Z,1697469262.253 [Default:CheckIn] Stopped 2023-10-16T15:14:22.253Z,1697469262.253 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T15:14:22.258Z,1697469262.258 [Default:CheckIn](INFO): Running loop #5 2023-10-16T15:14:22.258Z,1697469262.258 [Default:CheckIn] Running Loop=5 2023-10-16T15:14:22.258Z,1697469262.258 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T15:14:22.258Z,1697469262.258 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T15:14:24.181Z,1697469264.181 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151423.00,A,3648.14033,N,12147.22800,W,0.019,58.49,161023,,,D*43 2023-10-16T15:14:24.183Z,1697469264.183 [NAL9602](INFO): GPS fix at 20231016T151423: (36.802339, -121.787133) 2023-10-16T15:14:24.269Z,1697469264.269 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T15:14:24.269Z,1697469264.269 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T15:14:35.253Z,1697469275.253 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231016T143832/Courier0019.lzma 2023-10-16T15:14:36.255Z,1697469276.255 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0019.lzma.bak 2023-10-16T15:14:36.256Z,1697469276.256 [DataOverHttps](INFO): SBD MOMSN=18997915 2023-10-16T15:14:40.819Z,1697469280.819 [NAL9602](INFO): SBD MO Status=0, MOMSN=31847, MT Status=0, MTMSN=0 2023-10-16T15:14:40.819Z,1697469280.819 [NAL9602](INFO): No messages in MT queue 2023-10-16T15:14:52.961Z,1697469292.961 [DataOverHttps](INFO): Sending 137 bytes from file Logs/20231016T143832/Express0020.lzma 2023-10-16T15:14:53.964Z,1697469293.964 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0020.lzma.bak 2023-10-16T15:14:53.964Z,1697469293.964 [DataOverHttps](INFO): SBD MOMSN=18997918 2023-10-16T15:14:55.351Z,1697469295.351 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T15:14:55.351Z,1697469295.351 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T15:14:55.351Z,1697469295.351 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T15:15:11.475Z,1697469311.475 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T15:19:55.902Z,1697469595.902 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T15:19:55.902Z,1697469595.902 [Default:CheckIn:C.Wait] Stopped 2023-10-16T15:19:55.902Z,1697469595.902 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T15:19:55.903Z,1697469595.903 [Default:CheckIn:D] Running Loop=1 2023-10-16T15:19:56.338Z,1697469596.338 [Default:CheckIn:D] Stopped 2023-10-16T15:19:56.338Z,1697469596.338 [Default:CheckIn:E] Running Loop=1 2023-10-16T15:19:56.714Z,1697469596.714 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 38.055570 min 2023-10-16T15:19:56.714Z,1697469596.714 [Default:CheckIn:E] Stopped 2023-10-16T15:19:56.714Z,1697469596.714 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T15:19:56.714Z,1697469596.714 [Default:CheckIn] Stopped 2023-10-16T15:19:56.714Z,1697469596.714 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T15:19:56.715Z,1697469596.715 [Default:CheckIn](INFO): Running loop #6 2023-10-16T15:19:56.715Z,1697469596.715 [Default:CheckIn] Running Loop=6 2023-10-16T15:19:56.715Z,1697469596.715 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T15:19:56.715Z,1697469596.715 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T15:19:58.722Z,1697469598.722 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151958.00,A,3648.14063,N,12147.22955,W,0.039,58.49,161023,,,D*44 2023-10-16T15:19:58.724Z,1697469598.724 [NAL9602](INFO): GPS fix at 20231016T151958: (36.802344, -121.787159) 2023-10-16T15:19:58.736Z,1697469598.736 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T15:19:58.736Z,1697469598.736 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T15:20:05.977Z,1697469605.977 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231016T143832/Courier0022.lzma 2023-10-16T15:20:06.979Z,1697469606.979 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0022.lzma.bak 2023-10-16T15:20:06.980Z,1697469606.980 [DataOverHttps](INFO): SBD MOMSN=18997936 2023-10-16T15:20:16.912Z,1697469616.912 [NAL9602](INFO): SBD MO Status=0, MOMSN=31848, MT Status=0, MTMSN=0 2023-10-16T15:20:16.912Z,1697469616.912 [NAL9602](INFO): No messages in MT queue 2023-10-16T15:20:23.693Z,1697469623.693 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20231016T143832/Express0023.lzma 2023-10-16T15:20:24.695Z,1697469624.695 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0023.lzma.bak 2023-10-16T15:20:24.696Z,1697469624.696 [DataOverHttps](INFO): SBD MOMSN=18997939 2023-10-16T15:20:25.835Z,1697469625.835 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T15:20:25.835Z,1697469625.835 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T15:20:25.835Z,1697469625.835 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T15:20:47.667Z,1697469647.667 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T15:21:06.274Z,1697469666.274 [RDI_Pathfinder](ERROR): only read 2 of 4 data items for water velocity. Device response is::WS,-2768,-32768,V 2023-10-16T15:24:52.190Z,1697469892.190 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for water mass range. Device response is::WD, +0.00, 1.83 2023-10-16T15:25:26.512Z,1697469926.512 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T15:25:26.512Z,1697469926.512 [Default:CheckIn:C.Wait] Stopped 2023-10-16T15:25:26.512Z,1697469926.512 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T15:25:26.512Z,1697469926.512 [Default:CheckIn:D] Running Loop=1 2023-10-16T15:25:26.908Z,1697469926.908 [Default:CheckIn:D] Stopped 2023-10-16T15:25:26.908Z,1697469926.908 [Default:CheckIn:E] Running Loop=1 2023-10-16T15:25:27.299Z,1697469927.299 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 43.565072 min 2023-10-16T15:25:27.299Z,1697469927.299 [Default:CheckIn:E] Stopped 2023-10-16T15:25:27.300Z,1697469927.300 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T15:25:27.300Z,1697469927.300 [Default:CheckIn] Stopped 2023-10-16T15:25:27.300Z,1697469927.300 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T15:25:27.300Z,1697469927.300 [Default:CheckIn](INFO): Running loop #7 2023-10-16T15:25:27.300Z,1697469927.300 [Default:CheckIn] Running Loop=7 2023-10-16T15:25:27.300Z,1697469927.300 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T15:25:27.300Z,1697469927.300 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T15:25:29.309Z,1697469929.309 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,152528.00,A,3648.14019,N,12147.22922,W,0.019,58.49,161023,,,D*43 2023-10-16T15:25:29.311Z,1697469929.311 [NAL9602](INFO): GPS fix at 20231016T152528: (36.802337, -121.787154) 2023-10-16T15:25:29.323Z,1697469929.323 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T15:25:29.323Z,1697469929.323 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T15:25:36.921Z,1697469936.921 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20231016T143832/Courier0025.lzma 2023-10-16T15:25:37.924Z,1697469937.924 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0025.lzma.bak 2023-10-16T15:25:37.924Z,1697469937.924 [DataOverHttps](INFO): SBD MOMSN=18997943 2023-10-16T15:25:54.349Z,1697469954.349 [DataOverHttps](INFO): Sending 138 bytes from file Logs/20231016T143832/Express0026.lzma 2023-10-16T15:25:55.352Z,1697469955.352 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0026.lzma.bak 2023-10-16T15:25:55.352Z,1697469955.352 [DataOverHttps](INFO): SBD MOMSN=18997946 2023-10-16T15:25:56.449Z,1697469956.449 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T15:25:56.449Z,1697469956.449 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T15:25:56.449Z,1697469956.449 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T15:26:02.840Z,1697469962.840 [NAL9602](INFO): SBD MO Status=0, MOMSN=31849, MT Status=0, MTMSN=0 2023-10-16T15:26:02.840Z,1697469962.840 [NAL9602](INFO): No messages in MT queue 2023-10-16T15:26:33.538Z,1697469993.538 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T15:28:36.409Z,1697470116.409 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS,23101607, 0 2023-10-16T15:30:57.002Z,1697470257.002 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T15:30:57.002Z,1697470257.002 [Default:CheckIn:C.Wait] Stopped 2023-10-16T15:30:57.002Z,1697470257.002 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T15:30:57.002Z,1697470257.002 [Default:CheckIn:D] Running Loop=1 2023-10-16T15:30:57.404Z,1697470257.404 [Default:CheckIn:D] Stopped 2023-10-16T15:30:57.404Z,1697470257.404 [Default:CheckIn:E] Running Loop=1 2023-10-16T15:30:57.820Z,1697470257.820 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 49.073328 min 2023-10-16T15:30:57.820Z,1697470257.820 [Default:CheckIn:E] Stopped 2023-10-16T15:30:57.820Z,1697470257.820 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T15:30:57.820Z,1697470257.820 [Default:CheckIn] Stopped 2023-10-16T15:30:57.821Z,1697470257.821 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T15:30:57.821Z,1697470257.821 [Default:CheckIn](INFO): Running loop #8 2023-10-16T15:30:57.821Z,1697470257.821 [Default:CheckIn] Running Loop=8 2023-10-16T15:30:57.821Z,1697470257.821 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T15:30:57.821Z,1697470257.821 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T15:30:59.821Z,1697470259.821 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,153059.00,A,3648.14069,N,12147.22908,W,0.058,58.49,161023,,,D*4B 2023-10-16T15:30:59.823Z,1697470259.823 [NAL9602](INFO): GPS fix at 20231016T153059: (36.802345, -121.787151) 2023-10-16T15:30:59.855Z,1697470259.855 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T15:30:59.855Z,1697470259.855 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T15:31:07.865Z,1697470267.865 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231016T143832/Courier0028.lzma 2023-10-16T15:31:08.867Z,1697470268.867 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0028.lzma.bak 2023-10-16T15:31:08.868Z,1697470268.868 [DataOverHttps](INFO): SBD MOMSN=18997957 2023-10-16T15:31:13.556Z,1697470273.556 [NAL9602](INFO): SBD MO Status=0, MOMSN=31850, MT Status=0, MTMSN=0 2023-10-16T15:31:13.557Z,1697470273.557 [NAL9602](INFO): No messages in MT queue 2023-10-16T15:31:25.413Z,1697470285.413 [DataOverHttps](INFO): Sending 138 bytes from file Logs/20231016T143832/Express0029.lzma 2023-10-16T15:31:26.416Z,1697470286.416 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0029.lzma.bak 2023-10-16T15:31:26.416Z,1697470286.416 [DataOverHttps](INFO): SBD MOMSN=18997960 2023-10-16T15:31:27.722Z,1697470287.722 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T15:31:27.722Z,1697470287.722 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T15:31:27.722Z,1697470287.722 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T15:31:44.254Z,1697470304.254 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T15:34:33.727Z,1697470473.727 [DataOverHttps](IMPORTANT): SBD MTMSN=20231016T153432 2023-10-16T15:34:41.489Z,1697470481.489 [DataOverHttps](INFO): Received command: ibit 2023-10-16T15:34:41.530Z,1697470481.530 [CommandExec](IMPORTANT): got command ibit 2023-10-16T15:34:41.641Z,1697470481.641 [IBIT](IMPORTANT): Beginning Initiated BIT 2023-10-16T15:34:41.642Z,1697470481.642 [IBIT](IMPORTANT): Beginning control surface checks. 2023-10-16T15:34:41.645Z,1697470481.645 [CBIT](IMPORTANT): Beginning ground fault scan 2023-10-16T15:34:43.245Z,1697470483.245 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,153442.00,A,3648.14066,N,12147.22844,W,0.019,58.49,161023,,,D*46 2023-10-16T15:34:43.247Z,1697470483.247 [NAL9602](INFO): GPS fix at 20231016T153442: (36.802344, -121.787141) 2023-10-16T15:34:52.608Z,1697470492.608 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.010051 CHAN A1 (24V): 0.000715 CHAN A2 (12V): -0.006614 CHAN A3 (5V): -0.002037 CHAN B0 (3.3V): 0.000514 CHAN B1 (3.15aV): 0.000423 CHAN B2 (3.15bV): 0.000481 CHAN B3 (GND): 0.001418 OPEN: 0.005223 Full Scale: +/- 1 mA 2023-10-16T15:35:04.244Z,1697470504.244 [NAL9602](INFO): SBD MO Status=2, MOMSN=31851, MT Status=2, MTMSN=0 2023-10-16T15:35:04.244Z,1697470504.244 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-10-16T15:35:11.920Z,1697470511.920 [NAL9602](INFO): SBD MO Status=0, MOMSN=31851, MT Status=0, MTMSN=0 2023-10-16T15:35:11.920Z,1697470511.920 [NAL9602](INFO): No messages in MT queue 2023-10-16T15:35:13.133Z,1697470513.133 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,153512.00,A,3648.14138,N,12147.22872,W,0.019,58.49,161023,,,D*4D 2023-10-16T15:35:13.135Z,1697470513.135 [NAL9602](INFO): GPS fix at 20231016T153512: (36.802356, -121.787145) 2023-10-16T15:35:15.961Z,1697470515.961 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,153515.00,A,3648.14132,N,12147.22868,W,0.019,58.49,161023,,,D*4B 2023-10-16T15:35:15.963Z,1697470515.963 [NAL9602](INFO): GPS fix at 20231016T153515: (36.802355, -121.787145) 2023-10-16T15:35:18.796Z,1697470518.796 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,153518.00,A,3648.14124,N,12147.22865,W,0.019,58.49,161023,,,D*4C 2023-10-16T15:35:18.798Z,1697470518.798 [NAL9602](INFO): GPS fix at 20231016T153518: (36.802354, -121.787144) 2023-10-16T15:35:22.025Z,1697470522.025 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,153521.00,A,3648.14117,N,12147.22865,W,0.019,58.49,161023,,,D*46 2023-10-16T15:35:22.027Z,1697470522.027 [NAL9602](INFO): GPS fix at 20231016T153521: (36.802353, -121.787144) 2023-10-16T15:35:24.853Z,1697470524.853 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,153524.00,A,3648.14115,N,12147.22879,W,0.019,58.49,161023,,,D*4C 2023-10-16T15:35:24.856Z,1697470524.856 [NAL9602](INFO): GPS fix at 20231016T153524: (36.802352, -121.787147) 2023-10-16T15:35:28.085Z,1697470528.085 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,153527.00,A,3648.14113,N,12147.22893,W,0.019,58.49,161023,,,D*4D 2023-10-16T15:35:28.088Z,1697470528.088 [NAL9602](INFO): GPS fix at 20231016T153527: (36.802352, -121.787149) 2023-10-16T15:35:28.148Z,1697470528.148 [IBIT](IMPORTANT): Communications Status: Fix Status: 1 Iridium Signal Strength: 4 Latitude: 36.802353 Longitude: -121.787148 2023-10-16T15:35:28.536Z,1697470528.536 [IBIT](IMPORTANT): Battery Status: Battery Charge (AH): 0.000000 Voltage: 16.650999 2023-10-16T15:35:28.536Z,1697470528.536 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah 2023-10-16T15:35:28.536Z,1697470528.536 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V 2023-10-16T15:35:28.932Z,1697470528.932 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2023-10-16T15:35:28.932Z,1697470528.932 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2023-10-16T15:35:28.932Z,1697470528.932 [IBIT](IMPORTANT): Pressure:7.797435 PSI 2023-10-16T15:35:28.933Z,1697470528.933 [IBIT](IMPORTANT): Humidity:24.911488 % 2023-10-16T15:35:29.349Z,1697470529.349 [IBIT](IMPORTANT): Vehicle Pitch:-0.188389 degrees 2023-10-16T15:35:29.349Z,1697470529.349 [IBIT](IMPORTANT): Vehicle Roll:-2.989245 degrees 2023-10-16T15:35:29.349Z,1697470529.349 [IBIT](IMPORTANT): Vehicle Heading:303.644836 degrees 2023-10-16T15:35:29.726Z,1697470529.726 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m 2023-10-16T15:35:29.727Z,1697470529.727 [IBIT](IMPORTANT): buoyancyNeutral: 235.728333 cc 2023-10-16T15:35:29.727Z,1697470529.727 [IBIT](IMPORTANT): massDefault: 0.663716 cm 2023-10-16T15:35:29.727Z,1697470529.727 [IBIT](IMPORTANT): stopDepth: 215.000000 m 2023-10-16T15:35:29.727Z,1697470529.727 [IBIT](IMPORTANT): abortDepth: 255.000000 m 2023-10-16T15:35:29.727Z,1697470529.727 [IBIT](IMPORTANT): IBIT PASSED 2023-10-16T15:36:00.403Z,1697470560.403 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T15:36:28.428Z,1697470588.428 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T15:36:28.428Z,1697470588.428 [Default:CheckIn:C.Wait] Stopped 2023-10-16T15:36:28.428Z,1697470588.428 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T15:36:28.428Z,1697470588.428 [Default:CheckIn:D] Running Loop=1 2023-10-16T15:36:28.812Z,1697470588.812 [Default:CheckIn:D] Stopped 2023-10-16T15:36:28.812Z,1697470588.812 [Default:CheckIn:E] Running Loop=1 2023-10-16T15:36:29.199Z,1697470589.199 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 54.596798 min 2023-10-16T15:36:29.199Z,1697470589.199 [Default:CheckIn:E] Stopped 2023-10-16T15:36:29.199Z,1697470589.199 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T15:36:29.199Z,1697470589.199 [Default:CheckIn] Stopped 2023-10-16T15:36:29.199Z,1697470589.199 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T15:36:29.199Z,1697470589.199 [Default:CheckIn](INFO): Running loop #9 2023-10-16T15:36:29.199Z,1697470589.199 [Default:CheckIn] Running Loop=9 2023-10-16T15:36:29.199Z,1697470589.199 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T15:36:29.200Z,1697470589.200 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T15:36:31.165Z,1697470591.165 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,153630.00,A,3648.14089,N,12147.23056,W,0.019,58.49,161023,,,D*4A 2023-10-16T15:36:31.168Z,1697470591.168 [NAL9602](INFO): GPS fix at 20231016T153630: (36.802348, -121.787176) 2023-10-16T15:36:31.188Z,1697470591.188 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T15:36:31.188Z,1697470591.188 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T15:36:40.649Z,1697470600.649 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231016T143832/Courier0031.lzma 2023-10-16T15:36:41.652Z,1697470601.652 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0031.lzma.bak 2023-10-16T15:36:41.652Z,1697470601.652 [DataOverHttps](INFO): SBD MOMSN=18997994 2023-10-16T15:36:53.429Z,1697470613.429 [NAL9602](INFO): SBD MO Status=0, MOMSN=31852, MT Status=0, MTMSN=0 2023-10-16T15:36:53.429Z,1697470613.429 [NAL9602](INFO): No messages in MT queue 2023-10-16T15:36:57.859Z,1697470617.859 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20231016T143832/Courier0034.lzma 2023-10-16T15:36:58.856Z,1697470618.856 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0034.lzma.bak 2023-10-16T15:36:58.856Z,1697470618.856 [DataOverHttps](INFO): SBD MOMSN=18997997 2023-10-16T15:37:15.374Z,1697470635.374 [DataOverHttps](INFO): Sending 787 bytes from file Logs/20231016T143832/Express0032.lzma 2023-10-16T15:37:16.376Z,1697470636.376 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0032.lzma.bak 2023-10-16T15:37:16.376Z,1697470636.376 [DataOverHttps](INFO): SBD MOMSN=18997999 2023-10-16T15:37:24.157Z,1697470644.157 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T15:37:32.729Z,1697470652.729 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20231016T143832/Express0035.lzma 2023-10-16T15:37:33.732Z,1697470653.732 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0035.lzma.bak 2023-10-16T15:37:33.732Z,1697470653.732 [DataOverHttps](INFO): SBD MOMSN=18998025 2023-10-16T15:37:35.058Z,1697470655.058 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T15:37:35.058Z,1697470655.058 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T15:37:35.058Z,1697470655.058 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T15:41:42.316Z,1697470902.316 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude. Device response is::BD, + +0.00, +0.00, 0.00,3761.71 2023-10-16T15:42:34.428Z,1697470954.428 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude. Device response is::BD, +0.00, +0.0 2023-10-16T15:42:35.633Z,1697470955.633 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T15:42:35.633Z,1697470955.633 [Default:CheckIn:C.Wait] Stopped 2023-10-16T15:42:35.633Z,1697470955.633 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T15:42:35.633Z,1697470955.633 [Default:CheckIn:D] Running Loop=1 2023-10-16T15:42:36.047Z,1697470956.047 [Default:CheckIn:D] Stopped 2023-10-16T15:42:36.047Z,1697470956.047 [Default:CheckIn:E] Running Loop=1 2023-10-16T15:42:36.488Z,1697470956.488 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 60.717379 min 2023-10-16T15:42:36.488Z,1697470956.488 [Default:CheckIn:E] Stopped 2023-10-16T15:42:36.489Z,1697470956.489 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T15:42:36.489Z,1697470956.489 [Default:CheckIn] Stopped 2023-10-16T15:42:36.489Z,1697470956.489 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T15:42:36.489Z,1697470956.489 [Default:CheckIn](INFO): Running loop #10 2023-10-16T15:42:36.489Z,1697470956.489 [Default:CheckIn] Running Loop=10 2023-10-16T15:42:36.489Z,1697470956.489 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T15:42:36.489Z,1697470956.489 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T15:42:38.450Z,1697470958.450 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,154237.00,A,3648.13930,N,12147.22845,W,0.019,58.49,161023,,,D*49 2023-10-16T15:42:38.453Z,1697470958.453 [NAL9602](INFO): GPS fix at 20231016T154237: (36.802322, -121.787141) 2023-10-16T15:42:38.486Z,1697470958.486 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T15:42:38.486Z,1697470958.486 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T15:42:45.853Z,1697470965.853 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231016T143832/Courier0037.lzma 2023-10-16T15:42:46.856Z,1697470966.856 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0037.lzma.bak 2023-10-16T15:42:46.856Z,1697470966.856 [DataOverHttps](INFO): SBD MOMSN=18998067 2023-10-16T15:42:55.007Z,1697470975.007 [NAL9602](INFO): SBD MO Status=0, MOMSN=31853, MT Status=0, MTMSN=0 2023-10-16T15:42:55.007Z,1697470975.007 [NAL9602](INFO): No messages in MT queue 2023-10-16T15:43:03.201Z,1697470983.201 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20231016T143832/Express0038.lzma 2023-10-16T15:43:04.204Z,1697470984.204 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0038.lzma.bak 2023-10-16T15:43:04.204Z,1697470984.204 [DataOverHttps](INFO): SBD MOMSN=18998070 2023-10-16T15:43:05.534Z,1697470985.534 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T15:43:05.534Z,1697470985.534 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T15:43:05.534Z,1697470985.534 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T15:43:25.719Z,1697471005.719 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T15:48:06.216Z,1697471286.216 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T15:48:06.216Z,1697471286.216 [Default:CheckIn:C.Wait] Stopped 2023-10-16T15:48:06.216Z,1697471286.216 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T15:48:06.216Z,1697471286.216 [Default:CheckIn:D] Running Loop=1 2023-10-16T15:48:06.570Z,1697471286.570 [Default:CheckIn:D] Stopped 2023-10-16T15:48:06.570Z,1697471286.570 [Default:CheckIn:E] Running Loop=1 2023-10-16T15:48:06.967Z,1697471286.967 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 66.226099 min 2023-10-16T15:48:06.967Z,1697471286.967 [Default:CheckIn:E] Stopped 2023-10-16T15:48:06.967Z,1697471286.967 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T15:48:06.967Z,1697471286.967 [Default:CheckIn] Stopped 2023-10-16T15:48:06.967Z,1697471286.967 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T15:48:06.968Z,1697471286.968 [Default:CheckIn](INFO): Running loop #11 2023-10-16T15:48:06.968Z,1697471286.968 [Default:CheckIn] Running Loop=11 2023-10-16T15:48:06.968Z,1697471286.968 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T15:48:06.968Z,1697471286.968 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T15:48:08.974Z,1697471288.974 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,154808.00,A,3648.14174,N,12147.22892,W,0.019,0.00,161023,,,D*7A 2023-10-16T15:48:08.976Z,1697471288.976 [NAL9602](INFO): GPS fix at 20231016T154808: (36.802362, -121.787149) 2023-10-16T15:48:08.987Z,1697471288.987 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T15:48:08.987Z,1697471288.987 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T15:48:17.553Z,1697471297.553 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20231016T143832/Courier0040.lzma 2023-10-16T15:48:18.556Z,1697471298.556 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0040.lzma.bak 2023-10-16T15:48:18.556Z,1697471298.556 [DataOverHttps](INFO): SBD MOMSN=18998087 2023-10-16T15:48:22.329Z,1697471302.329 [NAL9602](INFO): SBD MO Status=0, MOMSN=31854, MT Status=0, MTMSN=0 2023-10-16T15:48:22.329Z,1697471302.329 [NAL9602](INFO): No messages in MT queue 2023-10-16T15:48:38.665Z,1697471318.665 [DataOverHttps](INFO): Sending 136 bytes from file Logs/20231016T143832/Express0041.lzma 2023-10-16T15:48:39.668Z,1697471319.668 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0041.lzma.bak 2023-10-16T15:48:39.668Z,1697471319.668 [DataOverHttps](INFO): SBD MOMSN=18998090 2023-10-16T15:48:40.959Z,1697471320.959 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T15:48:40.960Z,1697471320.960 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T15:48:40.960Z,1697471320.960 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T15:48:53.070Z,1697471333.070 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T15:51:34.248Z,1697471494.248 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T15:51:41.116Z,1697471501.116 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T15:51:53.237Z,1697471513.237 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T15:52:05.761Z,1697471525.761 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T15:52:18.690Z,1697471538.690 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T15:52:31.212Z,1697471551.212 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T15:52:44.161Z,1697471564.161 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T15:52:57.069Z,1697471577.069 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T15:53:09.592Z,1697471589.592 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T15:53:22.121Z,1697471602.121 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T15:53:39.496Z,1697471619.496 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2023-10-16T15:53:39.515Z,1697471619.515 [BPC1](INFO): Received data from all battery sticks. 2023-10-16T15:53:41.525Z,1697471621.525 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T15:53:41.525Z,1697471621.525 [Default:CheckIn:C.Wait] Stopped 2023-10-16T15:53:41.525Z,1697471621.525 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T15:53:41.525Z,1697471621.525 [Default:CheckIn:D] Running Loop=1 2023-10-16T15:53:41.927Z,1697471621.927 [Default:CheckIn:D] Stopped 2023-10-16T15:53:41.927Z,1697471621.927 [Default:CheckIn:E] Running Loop=1 2023-10-16T15:53:42.366Z,1697471622.366 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 71.815381 min 2023-10-16T15:53:42.366Z,1697471622.366 [Default:CheckIn:E] Stopped 2023-10-16T15:53:42.366Z,1697471622.366 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T15:53:42.366Z,1697471622.366 [Default:CheckIn] Stopped 2023-10-16T15:53:42.366Z,1697471622.366 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T15:53:42.366Z,1697471622.366 [Default:CheckIn](INFO): Running loop #12 2023-10-16T15:53:42.366Z,1697471622.366 [Default:CheckIn] Running Loop=12 2023-10-16T15:53:42.367Z,1697471622.367 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T15:53:42.367Z,1697471622.367 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T15:53:44.345Z,1697471624.345 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155343.00,A,3648.13938,N,12147.22977,W,0.019,0.00,161023,,,D*72 2023-10-16T15:53:44.347Z,1697471624.347 [NAL9602](INFO): GPS fix at 20231016T155343: (36.802323, -121.787163) 2023-10-16T15:53:44.397Z,1697471624.397 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T15:53:44.397Z,1697471624.397 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T15:53:52.597Z,1697471632.597 [DataOverHttps](INFO): Sending 83 bytes from file Logs/20231016T143832/Courier0043.lzma 2023-10-16T15:53:53.600Z,1697471633.600 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0043.lzma.bak 2023-10-16T15:53:53.600Z,1697471633.600 [DataOverHttps](INFO): SBD MOMSN=18998117 2023-10-16T15:54:10.187Z,1697471650.187 [DataOverHttps](INFO): Sending 138 bytes from file Logs/20231016T143832/Express0044.lzma 2023-10-16T15:54:11.180Z,1697471651.180 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0044.lzma.bak 2023-10-16T15:54:11.180Z,1697471651.180 [DataOverHttps](INFO): SBD MOMSN=18998120 2023-10-16T15:54:12.264Z,1697471652.264 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T15:54:12.264Z,1697471652.264 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T15:54:12.264Z,1697471652.264 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T15:54:16.664Z,1697471656.664 [NAL9602](INFO): SBD MO Status=0, MOMSN=31855, MT Status=0, MTMSN=0 2023-10-16T15:54:16.665Z,1697471656.665 [NAL9602](INFO): No messages in MT queue 2023-10-16T15:54:47.362Z,1697471687.362 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T15:59:12.806Z,1697471952.806 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T15:59:12.806Z,1697471952.806 [Default:CheckIn:C.Wait] Stopped 2023-10-16T15:59:12.806Z,1697471952.806 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T15:59:12.806Z,1697471952.806 [Default:CheckIn:D] Running Loop=1 2023-10-16T15:59:13.214Z,1697471953.214 [Default:CheckIn:D] Stopped 2023-10-16T15:59:13.214Z,1697471953.214 [Default:CheckIn:E] Running Loop=1 2023-10-16T15:59:13.622Z,1697471953.622 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 77.336833 min 2023-10-16T15:59:13.622Z,1697471953.622 [Default:CheckIn:E] Stopped 2023-10-16T15:59:13.622Z,1697471953.622 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T15:59:13.622Z,1697471953.622 [Default:CheckIn] Stopped 2023-10-16T15:59:13.623Z,1697471953.623 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T15:59:13.623Z,1697471953.623 [Default:CheckIn](INFO): Running loop #13 2023-10-16T15:59:13.623Z,1697471953.623 [Default:CheckIn] Running Loop=13 2023-10-16T15:59:13.623Z,1697471953.623 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T15:59:13.623Z,1697471953.623 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T15:59:15.621Z,1697471955.621 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155914.00,A,3648.13964,N,12147.22786,W,0.019,343.76,161023,,,D*76 2023-10-16T15:59:15.623Z,1697471955.623 [NAL9602](INFO): GPS fix at 20231016T155914: (36.802327, -121.787131) 2023-10-16T15:59:15.636Z,1697471955.636 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T15:59:15.636Z,1697471955.636 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T15:59:22.973Z,1697471962.973 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231016T143832/Courier0046.lzma 2023-10-16T15:59:23.976Z,1697471963.976 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0046.lzma.bak 2023-10-16T15:59:23.976Z,1697471963.976 [DataOverHttps](INFO): SBD MOMSN=18998133 2023-10-16T15:59:27.741Z,1697471967.741 [NAL9602](INFO): SBD MO Status=0, MOMSN=31856, MT Status=0, MTMSN=0 2023-10-16T15:59:27.741Z,1697471967.741 [NAL9602](INFO): No messages in MT queue 2023-10-16T15:59:40.389Z,1697471980.389 [DataOverHttps](INFO): Sending 137 bytes from file Logs/20231016T143832/Express0047.lzma 2023-10-16T15:59:41.392Z,1697471981.392 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0047.lzma.bak 2023-10-16T15:59:41.392Z,1697471981.392 [DataOverHttps](INFO): SBD MOMSN=18998140 2023-10-16T15:59:42.711Z,1697471982.711 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T15:59:42.711Z,1697471982.711 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T15:59:42.711Z,1697471982.711 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T15:59:58.443Z,1697471998.443 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T16:04:43.318Z,1697472283.318 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T16:04:43.318Z,1697472283.318 [Default:CheckIn:C.Wait] Stopped 2023-10-16T16:04:43.319Z,1697472283.319 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T16:04:43.319Z,1697472283.319 [Default:CheckIn:D] Running Loop=1 2023-10-16T16:04:43.739Z,1697472283.739 [Default:CheckIn:D] Stopped 2023-10-16T16:04:43.739Z,1697472283.739 [Default:CheckIn:E] Running Loop=1 2023-10-16T16:04:44.184Z,1697472284.184 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 82.845581 min 2023-10-16T16:04:44.184Z,1697472284.184 [Default:CheckIn:E] Stopped 2023-10-16T16:04:44.185Z,1697472284.185 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T16:04:44.185Z,1697472284.185 [Default:CheckIn] Stopped 2023-10-16T16:04:44.185Z,1697472284.185 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T16:04:44.190Z,1697472284.190 [Default:CheckIn](INFO): Running loop #14 2023-10-16T16:04:44.190Z,1697472284.190 [Default:CheckIn] Running Loop=14 2023-10-16T16:04:44.190Z,1697472284.190 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T16:04:44.190Z,1697472284.190 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T16:04:46.176Z,1697472286.176 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160445.00,A,3648.14005,N,12147.22865,W,0.039,343.76,161023,,,D*70 2023-10-16T16:04:46.183Z,1697472286.183 [NAL9602](INFO): GPS fix at 20231016T160445: (36.802334, -121.787144) 2023-10-16T16:04:46.238Z,1697472286.238 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T16:04:46.238Z,1697472286.238 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T16:04:54.495Z,1697472294.495 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20231016T143832/Courier0049.lzma 2023-10-16T16:04:55.495Z,1697472295.495 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0049.lzma.bak 2023-10-16T16:04:55.496Z,1697472295.496 [DataOverHttps](INFO): SBD MOMSN=18998180 2023-10-16T16:05:05.936Z,1697472305.936 [NAL9602](INFO): SBD MO Status=0, MOMSN=31857, MT Status=0, MTMSN=0 2023-10-16T16:05:05.936Z,1697472305.936 [NAL9602](INFO): No messages in MT queue 2023-10-16T16:05:11.933Z,1697472311.933 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20231016T143832/Express0050.lzma 2023-10-16T16:05:12.936Z,1697472312.936 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0050.lzma.bak 2023-10-16T16:05:12.936Z,1697472312.936 [DataOverHttps](INFO): SBD MOMSN=18998183 2023-10-16T16:05:14.034Z,1697472314.034 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T16:05:14.034Z,1697472314.034 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T16:05:14.034Z,1697472314.034 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T16:05:36.643Z,1697472336.643 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T16:10:14.686Z,1697472614.686 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T16:10:14.686Z,1697472614.686 [Default:CheckIn:C.Wait] Stopped 2023-10-16T16:10:14.686Z,1697472614.686 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T16:10:14.686Z,1697472614.686 [Default:CheckIn:D] Running Loop=1 2023-10-16T16:10:15.149Z,1697472615.149 [Default:CheckIn:D] Stopped 2023-10-16T16:10:15.149Z,1697472615.149 [Default:CheckIn:E] Running Loop=1 2023-10-16T16:10:15.503Z,1697472615.503 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 88.369076 min 2023-10-16T16:10:15.504Z,1697472615.504 [Default:CheckIn:E] Stopped 2023-10-16T16:10:15.504Z,1697472615.504 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T16:10:15.504Z,1697472615.504 [Default:CheckIn] Stopped 2023-10-16T16:10:15.504Z,1697472615.504 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T16:10:15.504Z,1697472615.504 [Default:CheckIn](INFO): Running loop #15 2023-10-16T16:10:15.504Z,1697472615.504 [Default:CheckIn] Running Loop=15 2023-10-16T16:10:15.504Z,1697472615.504 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T16:10:15.504Z,1697472615.504 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T16:10:17.508Z,1697472617.508 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161016.00,A,3648.14024,N,12147.22795,W,0.019,343.76,161023,,,A*77 2023-10-16T16:10:17.510Z,1697472617.510 [NAL9602](INFO): GPS fix at 20231016T161016: (36.802337, -121.787132) 2023-10-16T16:10:17.560Z,1697472617.560 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T16:10:17.560Z,1697472617.560 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T16:10:28.953Z,1697472628.953 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20231016T143832/Courier0052.lzma 2023-10-16T16:10:29.956Z,1697472629.956 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0052.lzma.bak 2023-10-16T16:10:29.956Z,1697472629.956 [DataOverHttps](INFO): SBD MOMSN=18998202 2023-10-16T16:10:39.044Z,1697472639.044 [NAL9602](INFO): SBD MO Status=0, MOMSN=31858, MT Status=0, MTMSN=0 2023-10-16T16:10:39.045Z,1697472639.045 [NAL9602](INFO): No messages in MT queue 2023-10-16T16:10:46.481Z,1697472646.481 [DataOverHttps](INFO): Sending 138 bytes from file Logs/20231016T143832/Express0053.lzma 2023-10-16T16:10:47.484Z,1697472647.484 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0053.lzma.bak 2023-10-16T16:10:47.484Z,1697472647.484 [DataOverHttps](INFO): SBD MOMSN=18998205 2023-10-16T16:10:48.773Z,1697472648.773 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T16:10:48.773Z,1697472648.773 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T16:10:48.773Z,1697472648.773 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T16:11:09.751Z,1697472669.751 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T16:15:49.374Z,1697472949.374 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T16:15:49.375Z,1697472949.375 [Default:CheckIn:C.Wait] Stopped 2023-10-16T16:15:49.375Z,1697472949.375 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T16:15:49.375Z,1697472949.375 [Default:CheckIn:D] Running Loop=1 2023-10-16T16:15:49.771Z,1697472949.771 [Default:CheckIn:D] Stopped 2023-10-16T16:15:49.771Z,1697472949.771 [Default:CheckIn:E] Running Loop=1 2023-10-16T16:15:50.225Z,1697472950.225 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 93.946126 min 2023-10-16T16:15:50.225Z,1697472950.225 [Default:CheckIn:E] Stopped 2023-10-16T16:15:50.225Z,1697472950.225 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T16:15:50.225Z,1697472950.225 [Default:CheckIn] Stopped 2023-10-16T16:15:50.225Z,1697472950.225 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T16:15:50.226Z,1697472950.226 [Default:CheckIn](INFO): Running loop #16 2023-10-16T16:15:50.226Z,1697472950.226 [Default:CheckIn] Running Loop=16 2023-10-16T16:15:50.226Z,1697472950.226 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T16:15:50.226Z,1697472950.226 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T16:15:52.198Z,1697472952.198 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161551.00,A,3648.13995,N,12147.22729,W,0.019,343.76,161023,,,A*72 2023-10-16T16:15:52.200Z,1697472952.200 [NAL9602](INFO): GPS fix at 20231016T161551: (36.802332, -121.787121) 2023-10-16T16:15:52.252Z,1697472952.252 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T16:15:52.252Z,1697472952.252 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T16:15:59.345Z,1697472959.345 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231016T143832/Courier0055.lzma 2023-10-16T16:16:00.348Z,1697472960.348 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0055.lzma.bak 2023-10-16T16:16:00.348Z,1697472960.348 [DataOverHttps](INFO): SBD MOMSN=18998219 2023-10-16T16:16:11.601Z,1697472971.601 [NAL9602](INFO): SBD MO Status=0, MOMSN=31859, MT Status=0, MTMSN=0 2023-10-16T16:16:11.601Z,1697472971.601 [NAL9602](INFO): No messages in MT queue 2023-10-16T16:16:19.874Z,1697472979.874 [DataOverHttps](INFO): Sending 137 bytes from file Logs/20231016T143832/Express0056.lzma 2023-10-16T16:16:20.876Z,1697472980.876 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0056.lzma.bak 2023-10-16T16:16:20.876Z,1697472980.876 [DataOverHttps](INFO): SBD MOMSN=18998222 2023-10-16T16:16:22.200Z,1697472982.200 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T16:16:22.200Z,1697472982.200 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T16:16:22.200Z,1697472982.200 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T16:16:42.327Z,1697473002.327 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T16:21:22.710Z,1697473282.710 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T16:21:22.711Z,1697473282.711 [Default:CheckIn:C.Wait] Stopped 2023-10-16T16:21:22.711Z,1697473282.711 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T16:21:22.711Z,1697473282.711 [Default:CheckIn:D] Running Loop=1 2023-10-16T16:21:23.125Z,1697473283.125 [Default:CheckIn:D] Stopped 2023-10-16T16:21:23.125Z,1697473283.125 [Default:CheckIn:E] Running Loop=1 2023-10-16T16:21:23.535Z,1697473283.535 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 99.502010 min 2023-10-16T16:21:23.535Z,1697473283.535 [Default:CheckIn:E] Stopped 2023-10-16T16:21:23.535Z,1697473283.535 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T16:21:23.535Z,1697473283.535 [Default:CheckIn] Stopped 2023-10-16T16:21:23.535Z,1697473283.535 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T16:21:23.536Z,1697473283.536 [Default:CheckIn](INFO): Running loop #17 2023-10-16T16:21:23.536Z,1697473283.536 [Default:CheckIn] Running Loop=17 2023-10-16T16:21:23.536Z,1697473283.536 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T16:21:23.536Z,1697473283.536 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T16:21:25.533Z,1697473285.533 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162124.00,A,3648.13961,N,12147.22837,W,0.039,343.76,161023,,,A*7E 2023-10-16T16:21:25.535Z,1697473285.535 [NAL9602](INFO): GPS fix at 20231016T162124: (36.802327, -121.787139) 2023-10-16T16:21:25.549Z,1697473285.549 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T16:21:25.549Z,1697473285.549 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T16:21:33.121Z,1697473293.121 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20231016T143832/Courier0058.lzma 2023-10-16T16:21:34.127Z,1697473294.127 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0058.lzma.bak 2023-10-16T16:21:34.127Z,1697473294.127 [DataOverHttps](INFO): SBD MOMSN=18998298 2023-10-16T16:21:45.727Z,1697473305.727 [NAL9602](INFO): SBD MO Status=0, MOMSN=31860, MT Status=0, MTMSN=0 2023-10-16T16:21:45.727Z,1697473305.727 [NAL9602](INFO): No messages in MT queue 2023-10-16T16:21:50.701Z,1697473310.701 [DataOverHttps](INFO): Sending 137 bytes from file Logs/20231016T143832/Express0059.lzma 2023-10-16T16:21:51.704Z,1697473311.704 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0059.lzma.bak 2023-10-16T16:21:51.704Z,1697473311.704 [DataOverHttps](INFO): SBD MOMSN=18998301 2023-10-16T16:21:53.011Z,1697473313.011 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T16:21:53.011Z,1697473313.011 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T16:21:53.011Z,1697473313.011 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T16:22:16.444Z,1697473336.444 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T16:26:53.607Z,1697473613.607 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T16:26:53.607Z,1697473613.607 [Default:CheckIn:C.Wait] Stopped 2023-10-16T16:26:53.607Z,1697473613.607 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T16:26:53.607Z,1697473613.607 [Default:CheckIn:D] Running Loop=1 2023-10-16T16:26:54.017Z,1697473614.017 [Default:CheckIn:D] Stopped 2023-10-16T16:26:54.017Z,1697473614.017 [Default:CheckIn:E] Running Loop=1 2023-10-16T16:26:54.439Z,1697473614.439 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 105.016878 min 2023-10-16T16:26:54.439Z,1697473614.439 [Default:CheckIn:E] Stopped 2023-10-16T16:26:54.439Z,1697473614.439 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T16:26:54.439Z,1697473614.439 [Default:CheckIn] Stopped 2023-10-16T16:26:54.439Z,1697473614.439 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T16:26:54.440Z,1697473614.440 [Default:CheckIn](INFO): Running loop #18 2023-10-16T16:26:54.440Z,1697473614.440 [Default:CheckIn] Running Loop=18 2023-10-16T16:26:54.440Z,1697473614.440 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T16:26:54.440Z,1697473614.440 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T16:26:56.417Z,1697473616.417 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162655.99,A,3648.14119,N,12147.22779,W,0.039,343.76,161023,,,A*7A 2023-10-16T16:26:56.419Z,1697473616.419 [NAL9602](INFO): GPS fix at 20231016T162655: (36.802353, -121.787130) 2023-10-16T16:26:56.475Z,1697473616.475 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T16:26:56.475Z,1697473616.475 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T16:27:03.819Z,1697473623.819 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231016T143832/Courier0061.lzma 2023-10-16T16:27:04.820Z,1697473624.820 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0061.lzma.bak 2023-10-16T16:27:04.820Z,1697473624.820 [DataOverHttps](INFO): SBD MOMSN=18998376 2023-10-16T16:27:21.387Z,1697473641.387 [DataOverHttps](INFO): Sending 138 bytes from file Logs/20231016T143832/Express0062.lzma 2023-10-16T16:27:22.388Z,1697473642.388 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0062.lzma.bak 2023-10-16T16:27:22.388Z,1697473642.388 [DataOverHttps](INFO): SBD MOMSN=18998379 2023-10-16T16:27:23.496Z,1697473643.496 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T16:27:23.496Z,1697473643.496 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T16:27:23.496Z,1697473643.496 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T16:27:40.053Z,1697473660.053 [NAL9602](INFO): SBD MO Status=0, MOMSN=31861, MT Status=0, MTMSN=0 2023-10-16T16:27:40.054Z,1697473660.054 [NAL9602](INFO): No messages in MT queue 2023-10-16T16:28:10.751Z,1697473690.751 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T16:32:24.207Z,1697473944.207 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T16:32:24.207Z,1697473944.207 [Default:CheckIn:C.Wait] Stopped 2023-10-16T16:32:24.207Z,1697473944.207 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T16:32:24.207Z,1697473944.207 [Default:CheckIn:D] Running Loop=1 2023-10-16T16:32:24.591Z,1697473944.591 [Default:CheckIn:D] Stopped 2023-10-16T16:32:24.591Z,1697473944.591 [Default:CheckIn:E] Running Loop=1 2023-10-16T16:32:24.977Z,1697473944.977 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 110.526440 min 2023-10-16T16:32:24.977Z,1697473944.977 [Default:CheckIn:E] Stopped 2023-10-16T16:32:24.977Z,1697473944.977 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T16:32:24.978Z,1697473944.978 [Default:CheckIn] Stopped 2023-10-16T16:32:24.978Z,1697473944.978 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T16:32:24.978Z,1697473944.978 [Default:CheckIn](INFO): Running loop #19 2023-10-16T16:32:24.979Z,1697473944.979 [Default:CheckIn] Running Loop=19 2023-10-16T16:32:24.979Z,1697473944.979 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T16:32:24.979Z,1697473944.979 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T16:32:26.961Z,1697473946.961 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163226.00,A,3648.13928,N,12147.22812,W,0.019,343.76,161023,,,A*76 2023-10-16T16:32:26.964Z,1697473946.964 [NAL9602](INFO): GPS fix at 20231016T163226: (36.802321, -121.787135) 2023-10-16T16:32:26.983Z,1697473946.983 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T16:32:26.983Z,1697473946.983 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T16:32:34.645Z,1697473954.645 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231016T143832/Courier0064.lzma 2023-10-16T16:32:35.649Z,1697473955.649 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0064.lzma.bak 2023-10-16T16:32:35.649Z,1697473955.649 [DataOverHttps](INFO): SBD MOMSN=18998396 2023-10-16T16:32:43.132Z,1697473963.132 [NAL9602](INFO): SBD MO Status=0, MOMSN=31862, MT Status=0, MTMSN=0 2023-10-16T16:32:43.133Z,1697473963.133 [NAL9602](INFO): No messages in MT queue 2023-10-16T16:32:52.021Z,1697473972.021 [DataOverHttps](INFO): Sending 138 bytes from file Logs/20231016T143832/Express0065.lzma 2023-10-16T16:32:53.024Z,1697473973.024 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0065.lzma.bak 2023-10-16T16:32:53.024Z,1697473973.024 [DataOverHttps](INFO): SBD MOMSN=18998401 2023-10-16T16:32:54.059Z,1697473974.059 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T16:32:54.059Z,1697473974.059 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T16:32:54.059Z,1697473974.059 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T16:33:13.835Z,1697473993.835 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T16:37:54.638Z,1697474274.638 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T16:37:54.638Z,1697474274.638 [Default:CheckIn:C.Wait] Stopped 2023-10-16T16:37:54.638Z,1697474274.638 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T16:37:54.638Z,1697474274.638 [Default:CheckIn:D] Running Loop=1 2023-10-16T16:37:55.051Z,1697474275.051 [Default:CheckIn:D] Stopped 2023-10-16T16:37:55.053Z,1697474275.053 [Default:CheckIn:E] Running Loop=1 2023-10-16T16:37:55.434Z,1697474275.434 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 116.034106 min 2023-10-16T16:37:55.434Z,1697474275.434 [Default:CheckIn:E] Stopped 2023-10-16T16:37:55.434Z,1697474275.434 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T16:37:55.434Z,1697474275.434 [Default:CheckIn] Stopped 2023-10-16T16:37:55.434Z,1697474275.434 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T16:37:55.434Z,1697474275.434 [Default:CheckIn](INFO): Running loop #20 2023-10-16T16:37:55.435Z,1697474275.435 [Default:CheckIn] Running Loop=20 2023-10-16T16:37:55.435Z,1697474275.435 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T16:37:55.435Z,1697474275.435 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T16:37:57.442Z,1697474277.442 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163756.00,A,3648.13971,N,12147.22935,W,0.039,343.76,161023,,,A*7E 2023-10-16T16:37:57.444Z,1697474277.444 [NAL9602](INFO): GPS fix at 20231016T163756: (36.802329, -121.787156) 2023-10-16T16:37:57.456Z,1697474277.456 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T16:37:57.456Z,1697474277.456 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T16:38:04.889Z,1697474284.889 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20231016T143832/Courier0067.lzma 2023-10-16T16:38:05.892Z,1697474285.892 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0067.lzma.bak 2023-10-16T16:38:05.892Z,1697474285.892 [DataOverHttps](INFO): SBD MOMSN=18998426 2023-10-16T16:38:10.776Z,1697474290.776 [NAL9602](INFO): SBD MO Status=0, MOMSN=31863, MT Status=0, MTMSN=0 2023-10-16T16:38:10.776Z,1697474290.776 [NAL9602](INFO): No messages in MT queue 2023-10-16T16:38:25.502Z,1697474305.502 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20231016T143832/Express0068.lzma 2023-10-16T16:38:26.504Z,1697474306.504 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0068.lzma.bak 2023-10-16T16:38:26.504Z,1697474306.504 [DataOverHttps](INFO): SBD MOMSN=18998429 2023-10-16T16:38:27.821Z,1697474307.821 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T16:38:27.821Z,1697474307.821 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T16:38:27.821Z,1697474307.821 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T16:38:41.547Z,1697474321.547 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T16:43:28.493Z,1697474608.493 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T16:43:28.493Z,1697474608.493 [Default:CheckIn:C.Wait] Stopped 2023-10-16T16:43:28.493Z,1697474608.493 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T16:43:28.493Z,1697474608.493 [Default:CheckIn:D] Running Loop=1 2023-10-16T16:43:28.870Z,1697474608.870 [Default:CheckIn:D] Stopped 2023-10-16T16:43:28.870Z,1697474608.870 [Default:CheckIn:E] Running Loop=1 2023-10-16T16:43:29.279Z,1697474609.279 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 121.597770 min 2023-10-16T16:43:29.279Z,1697474609.279 [Default:CheckIn:E] Stopped 2023-10-16T16:43:29.279Z,1697474609.279 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T16:43:29.279Z,1697474609.279 [Default:CheckIn] Stopped 2023-10-16T16:43:29.279Z,1697474609.279 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T16:43:29.279Z,1697474609.279 [Default:CheckIn](INFO): Running loop #21 2023-10-16T16:43:29.280Z,1697474609.280 [Default:CheckIn] Running Loop=21 2023-10-16T16:43:29.280Z,1697474609.280 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T16:43:29.280Z,1697474609.280 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T16:43:31.280Z,1697474611.280 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164330.00,A,3648.14023,N,12147.22821,W,0.019,0.00,161023,,,A*77 2023-10-16T16:43:31.294Z,1697474611.294 [NAL9602](INFO): GPS fix at 20231016T164330: (36.802337, -121.787137) 2023-10-16T16:43:31.306Z,1697474611.306 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T16:43:31.306Z,1697474611.306 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T16:43:39.481Z,1697474619.481 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231016T143832/Courier0070.lzma 2023-10-16T16:43:40.484Z,1697474620.484 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0070.lzma.bak 2023-10-16T16:43:40.484Z,1697474620.484 [DataOverHttps](INFO): SBD MOMSN=18998455 2023-10-16T16:43:41.413Z,1697474621.413 [NAL9602](INFO): SBD MO Status=0, MOMSN=31864, MT Status=0, MTMSN=0 2023-10-16T16:43:41.413Z,1697474621.413 [NAL9602](INFO): No messages in MT queue 2023-10-16T16:43:56.873Z,1697474636.873 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20231016T143832/Express0071.lzma 2023-10-16T16:43:57.876Z,1697474637.876 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0071.lzma.bak 2023-10-16T16:43:57.876Z,1697474637.876 [DataOverHttps](INFO): SBD MOMSN=18998458 2023-10-16T16:43:59.167Z,1697474639.167 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T16:43:59.167Z,1697474639.167 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T16:43:59.167Z,1697474639.167 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T16:44:12.088Z,1697474652.088 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T16:48:59.823Z,1697474939.823 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T16:48:59.823Z,1697474939.823 [Default:CheckIn:C.Wait] Stopped 2023-10-16T16:48:59.823Z,1697474939.823 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T16:48:59.823Z,1697474939.823 [Default:CheckIn:D] Running Loop=1 2023-10-16T16:49:00.264Z,1697474940.264 [Default:CheckIn:D] Stopped 2023-10-16T16:49:00.264Z,1697474940.264 [Default:CheckIn:E] Running Loop=1 2023-10-16T16:49:00.640Z,1697474940.640 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 127.120996 min 2023-10-16T16:49:00.640Z,1697474940.640 [Default:CheckIn:E] Stopped 2023-10-16T16:49:00.640Z,1697474940.640 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T16:49:00.641Z,1697474940.641 [Default:CheckIn] Stopped 2023-10-16T16:49:00.641Z,1697474940.641 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T16:49:00.641Z,1697474940.641 [Default:CheckIn](INFO): Running loop #22 2023-10-16T16:49:00.641Z,1697474940.641 [Default:CheckIn] Running Loop=22 2023-10-16T16:49:00.641Z,1697474940.641 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T16:49:00.641Z,1697474940.641 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T16:49:02.636Z,1697474942.636 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164901.00,A,3648.13981,N,12147.22947,W,0.019,0.00,161023,,,A*78 2023-10-16T16:49:02.638Z,1697474942.638 [NAL9602](INFO): GPS fix at 20231016T164901: (36.802330, -121.787158) 2023-10-16T16:49:02.670Z,1697474942.670 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T16:49:02.670Z,1697474942.670 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T16:49:10.814Z,1697474950.814 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231016T143832/Courier0073.lzma 2023-10-16T16:49:11.816Z,1697474951.816 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0073.lzma.bak 2023-10-16T16:49:11.816Z,1697474951.816 [DataOverHttps](INFO): SBD MOMSN=18998482 2023-10-16T16:49:16.780Z,1697474956.780 [NAL9602](INFO): SBD MO Status=0, MOMSN=31865, MT Status=0, MTMSN=0 2023-10-16T16:49:16.780Z,1697474956.780 [NAL9602](INFO): No messages in MT queue 2023-10-16T16:49:28.180Z,1697474968.180 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20231016T143832/Express0074.lzma 2023-10-16T16:49:29.176Z,1697474969.176 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0074.lzma.bak 2023-10-16T16:49:29.176Z,1697474969.176 [DataOverHttps](INFO): SBD MOMSN=18998487 2023-10-16T16:49:30.561Z,1697474970.561 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T16:49:30.561Z,1697474970.561 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T16:49:30.561Z,1697474970.561 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T16:49:47.478Z,1697474987.478 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T16:51:36.212Z,1697475096.212 [RDI_Pathfinder](ERROR): only read -1 of 1 data item for water mass range. Device response is::WD, +0.00, +0.00, 2023-10-16T16:54:31.105Z,1697475271.105 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T16:54:31.105Z,1697475271.105 [Default:CheckIn:C.Wait] Stopped 2023-10-16T16:54:31.105Z,1697475271.105 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T16:54:31.105Z,1697475271.105 [Default:CheckIn:D] Running Loop=1 2023-10-16T16:54:31.514Z,1697475271.514 [Default:CheckIn:D] Stopped 2023-10-16T16:54:31.514Z,1697475271.514 [Default:CheckIn:E] Running Loop=1 2023-10-16T16:54:31.929Z,1697475271.929 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 132.641829 min 2023-10-16T16:54:31.929Z,1697475271.929 [Default:CheckIn:E] Stopped 2023-10-16T16:54:31.929Z,1697475271.929 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T16:54:31.929Z,1697475271.929 [Default:CheckIn] Stopped 2023-10-16T16:54:31.929Z,1697475271.929 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T16:54:31.930Z,1697475271.930 [Default:CheckIn](INFO): Running loop #23 2023-10-16T16:54:31.930Z,1697475271.930 [Default:CheckIn] Running Loop=23 2023-10-16T16:54:31.930Z,1697475271.930 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T16:54:31.930Z,1697475271.930 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T16:54:33.926Z,1697475273.926 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165433.00,A,3648.14102,N,12147.22852,W,0.019,0.00,161023,,,A*74 2023-10-16T16:54:33.928Z,1697475273.928 [NAL9602](INFO): GPS fix at 20231016T165433: (36.802350, -121.787142) 2023-10-16T16:54:33.971Z,1697475273.971 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T16:54:33.971Z,1697475273.971 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T16:54:43.985Z,1697475283.985 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231016T143832/Courier0076.lzma 2023-10-16T16:54:44.988Z,1697475284.988 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0076.lzma.bak 2023-10-16T16:54:44.988Z,1697475284.988 [DataOverHttps](INFO): SBD MOMSN=18998510 2023-10-16T16:54:53.783Z,1697475293.783 [NAL9602](INFO): SBD MO Status=0, MOMSN=31866, MT Status=0, MTMSN=0 2023-10-16T16:54:53.783Z,1697475293.783 [NAL9602](INFO): No messages in MT queue 2023-10-16T16:55:03.365Z,1697475303.365 [DataOverHttps](INFO): Sending 138 bytes from file Logs/20231016T143832/Express0077.lzma 2023-10-16T16:55:04.368Z,1697475304.368 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0077.lzma.bak 2023-10-16T16:55:04.368Z,1697475304.368 [DataOverHttps](INFO): SBD MOMSN=18998513 2023-10-16T16:55:05.505Z,1697475305.505 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T16:55:05.506Z,1697475305.506 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T16:55:05.506Z,1697475305.506 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T16:55:24.479Z,1697475324.479 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T16:58:02.539Z,1697475482.539 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS,23101608590638,35.0, +17.3, 0.32768,V 2023-10-16T16:58:36.860Z,1697475516.860 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T16:58:43.324Z,1697475523.324 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T16:58:56.252Z,1697475536.252 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T16:59:08.373Z,1697475548.373 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T16:59:20.898Z,1697475560.898 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T16:59:33.826Z,1697475573.826 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T16:59:46.753Z,1697475586.753 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T16:59:59.681Z,1697475599.681 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T17:00:06.216Z,1697475606.216 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS,23101609011038,35.0, +17.3, 0.0,1513 2023-10-16T17:00:06.225Z,1697475606.225 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T17:00:06.225Z,1697475606.225 [Default:CheckIn:C.Wait] Stopped 2023-10-16T17:00:06.226Z,1697475606.226 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T17:00:06.226Z,1697475606.226 [Default:CheckIn:D] Running Loop=1 2023-10-16T17:00:06.564Z,1697475606.564 [Default:CheckIn:D] Stopped 2023-10-16T17:00:06.564Z,1697475606.564 [Default:CheckIn:E] Running Loop=1 2023-10-16T17:00:06.965Z,1697475606.965 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 138.225993 min 2023-10-16T17:00:06.966Z,1697475606.966 [Default:CheckIn:E] Stopped 2023-10-16T17:00:06.966Z,1697475606.966 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T17:00:06.966Z,1697475606.966 [Default:CheckIn] Stopped 2023-10-16T17:00:06.966Z,1697475606.966 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T17:00:06.966Z,1697475606.966 [Default:CheckIn](INFO): Running loop #24 2023-10-16T17:00:06.966Z,1697475606.966 [Default:CheckIn] Running Loop=24 2023-10-16T17:00:06.966Z,1697475606.966 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T17:00:06.966Z,1697475606.966 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T17:00:09.042Z,1697475609.042 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170008.00,A,3648.14122,N,12147.22850,W,0.039,0.00,161023,,,A*7E 2023-10-16T17:00:09.044Z,1697475609.044 [NAL9602](INFO): GPS fix at 20231016T170008: (36.802354, -121.787142) 2023-10-16T17:00:09.056Z,1697475609.056 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T17:00:09.056Z,1697475609.056 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T17:00:13.012Z,1697475613.012 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T17:00:18.279Z,1697475618.279 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20231016T143832/Courier0079.lzma 2023-10-16T17:00:19.272Z,1697475619.272 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0079.lzma.bak 2023-10-16T17:00:19.272Z,1697475619.272 [DataOverHttps](INFO): SBD MOMSN=18998541 2023-10-16T17:00:26.407Z,1697475626.407 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T17:00:26.472Z,1697475626.472 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for water mass range. Device response is::WD, +0.00, +0. +0.00,849BI,-32768,-32768,-32768,-32768,V 2023-10-16T17:00:30.845Z,1697475630.845 [NAL9602](INFO): SBD MO Status=2, MOMSN=31867, MT Status=2, MTMSN=0 2023-10-16T17:00:30.845Z,1697475630.845 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-10-16T17:00:38.535Z,1697475638.535 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20231016T143832/Express0080.lzma 2023-10-16T17:00:39.536Z,1697475639.536 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0080.lzma.bak 2023-10-16T17:00:39.536Z,1697475639.536 [DataOverHttps](INFO): SBD MOMSN=18998544 2023-10-16T17:00:39.728Z,1697475639.728 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T17:00:40.602Z,1697475640.602 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T17:00:40.602Z,1697475640.602 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T17:00:40.602Z,1697475640.602 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T17:00:52.253Z,1697475652.253 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T17:01:01.550Z,1697475661.550 [NAL9602](INFO): SBD MO Status=0, MOMSN=31867, MT Status=0, MTMSN=0 2023-10-16T17:01:01.550Z,1697475661.550 [NAL9602](INFO): No messages in MT queue 2023-10-16T17:01:09.229Z,1697475669.229 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5. 2023-10-16T17:01:09.231Z,1697475669.231 [BPC1](INFO): Received data from all battery sticks. 2023-10-16T17:01:32.255Z,1697475692.255 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T17:05:41.158Z,1697475941.158 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T17:05:41.158Z,1697475941.158 [Default:CheckIn:C.Wait] Stopped 2023-10-16T17:05:41.158Z,1697475941.158 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T17:05:41.159Z,1697475941.159 [Default:CheckIn:D] Running Loop=1 2023-10-16T17:05:41.562Z,1697475941.562 [Default:CheckIn:D] Stopped 2023-10-16T17:05:41.562Z,1697475941.562 [Default:CheckIn:E] Running Loop=1 2023-10-16T17:05:41.970Z,1697475941.970 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 143.809310 min 2023-10-16T17:05:41.971Z,1697475941.971 [Default:CheckIn:E] Stopped 2023-10-16T17:05:41.971Z,1697475941.971 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T17:05:41.971Z,1697475941.971 [Default:CheckIn] Stopped 2023-10-16T17:05:41.971Z,1697475941.971 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T17:05:41.971Z,1697475941.971 [Default:CheckIn](INFO): Running loop #25 2023-10-16T17:05:41.971Z,1697475941.971 [Default:CheckIn] Running Loop=25 2023-10-16T17:05:41.971Z,1697475941.971 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T17:05:41.971Z,1697475941.971 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T17:05:43.985Z,1697475943.985 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170543.00,A,3648.14009,N,12147.22976,W,0.019,0.00,161023,,,A*7B 2023-10-16T17:05:43.988Z,1697475943.988 [NAL9602](INFO): GPS fix at 20231016T170543: (36.802335, -121.787163) 2023-10-16T17:05:44.057Z,1697475944.057 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T17:05:44.057Z,1697475944.057 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T17:05:51.553Z,1697475951.553 [DataOverHttps](INFO): Sending 84 bytes from file Logs/20231016T143832/Courier0082.lzma 2023-10-16T17:05:52.556Z,1697475952.556 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0082.lzma.bak 2023-10-16T17:05:52.556Z,1697475952.556 [DataOverHttps](INFO): SBD MOMSN=18998562 2023-10-16T17:05:59.732Z,1697475959.732 [NAL9602](INFO): SBD MO Status=0, MOMSN=31868, MT Status=0, MTMSN=0 2023-10-16T17:05:59.733Z,1697475959.733 [NAL9602](INFO): No messages in MT queue 2023-10-16T17:06:08.945Z,1697475968.945 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20231016T143832/Express0083.lzma 2023-10-16T17:06:09.948Z,1697475969.948 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0083.lzma.bak 2023-10-16T17:06:09.948Z,1697475969.948 [DataOverHttps](INFO): SBD MOMSN=18998565 2023-10-16T17:06:11.053Z,1697475971.053 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T17:06:11.054Z,1697475971.054 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T17:06:11.054Z,1697475971.054 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T17:06:30.429Z,1697475990.429 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T17:11:11.660Z,1697476271.660 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T17:11:11.660Z,1697476271.660 [Default:CheckIn:C.Wait] Stopped 2023-10-16T17:11:11.661Z,1697476271.661 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T17:11:11.661Z,1697476271.661 [Default:CheckIn:D] Running Loop=1 2023-10-16T17:11:12.077Z,1697476272.077 [Default:CheckIn:D] Stopped 2023-10-16T17:11:12.077Z,1697476272.077 [Default:CheckIn:E] Running Loop=1 2023-10-16T17:11:12.494Z,1697476272.494 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 149.317887 min 2023-10-16T17:11:12.494Z,1697476272.494 [Default:CheckIn:E] Stopped 2023-10-16T17:11:12.494Z,1697476272.494 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T17:11:12.494Z,1697476272.494 [Default:CheckIn] Stopped 2023-10-16T17:11:12.494Z,1697476272.494 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T17:11:12.495Z,1697476272.495 [Default:CheckIn](INFO): Running loop #26 2023-10-16T17:11:12.495Z,1697476272.495 [Default:CheckIn] Running Loop=26 2023-10-16T17:11:12.495Z,1697476272.495 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T17:11:12.495Z,1697476272.495 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T17:11:14.467Z,1697476274.467 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171113.00,A,3648.13872,N,12147.22959,W,0.000,0.00,161023,,,A*7D 2023-10-16T17:11:14.470Z,1697476274.470 [NAL9602](INFO): GPS fix at 20231016T171113: (36.802312, -121.787160) 2023-10-16T17:11:14.501Z,1697476274.501 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T17:11:14.501Z,1697476274.501 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T17:11:22.069Z,1697476282.069 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231016T143832/Courier0085.lzma 2023-10-16T17:11:23.072Z,1697476283.072 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0085.lzma.bak 2023-10-16T17:11:23.072Z,1697476283.072 [DataOverHttps](INFO): SBD MOMSN=18998578 2023-10-16T17:11:39.817Z,1697476299.817 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20231016T143832/Express0086.lzma 2023-10-16T17:11:40.820Z,1697476300.820 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0086.lzma.bak 2023-10-16T17:11:40.820Z,1697476300.820 [DataOverHttps](INFO): SBD MOMSN=18998581 2023-10-16T17:11:41.946Z,1697476301.946 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T17:11:41.946Z,1697476301.946 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T17:11:41.946Z,1697476301.946 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T17:12:23.157Z,1697476343.157 [NAL9602](INFO): SBD MO Status=0, MOMSN=31869, MT Status=0, MTMSN=0 2023-10-16T17:12:23.157Z,1697476343.157 [NAL9602](INFO): No messages in MT queue 2023-10-16T17:12:53.865Z,1697476373.865 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T17:16:42.585Z,1697476602.585 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T17:16:42.585Z,1697476602.585 [Default:CheckIn:C.Wait] Stopped 2023-10-16T17:16:42.585Z,1697476602.585 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T17:16:42.586Z,1697476602.586 [Default:CheckIn:D] Running Loop=1 2023-10-16T17:16:42.997Z,1697476602.997 [Default:CheckIn:D] Stopped 2023-10-16T17:16:42.997Z,1697476602.997 [Default:CheckIn:E] Running Loop=1 2023-10-16T17:16:43.390Z,1697476603.390 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 154.833219 min 2023-10-16T17:16:43.390Z,1697476603.390 [Default:CheckIn:E] Stopped 2023-10-16T17:16:43.390Z,1697476603.390 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T17:16:43.390Z,1697476603.390 [Default:CheckIn] Stopped 2023-10-16T17:16:43.390Z,1697476603.390 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T17:16:43.391Z,1697476603.391 [Default:CheckIn](INFO): Running loop #27 2023-10-16T17:16:43.391Z,1697476603.391 [Default:CheckIn] Running Loop=27 2023-10-16T17:16:43.391Z,1697476603.391 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T17:16:43.391Z,1697476603.391 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T17:16:45.401Z,1697476605.401 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171644.00,A,3648.14002,N,12147.22935,W,0.019,0.00,161023,,,A*72 2023-10-16T17:16:45.403Z,1697476605.403 [NAL9602](INFO): GPS fix at 20231016T171644: (36.802334, -121.787156) 2023-10-16T17:16:45.415Z,1697476605.415 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T17:16:45.415Z,1697476605.415 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T17:16:53.545Z,1697476613.545 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20231016T143832/Courier0088.lzma 2023-10-16T17:16:54.548Z,1697476614.548 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0088.lzma.bak 2023-10-16T17:16:54.548Z,1697476614.548 [DataOverHttps](INFO): SBD MOMSN=18998599 2023-10-16T17:17:03.589Z,1697476623.589 [NAL9602](INFO): SBD MO Status=0, MOMSN=31870, MT Status=0, MTMSN=0 2023-10-16T17:17:03.589Z,1697476623.589 [NAL9602](INFO): No messages in MT queue 2023-10-16T17:17:10.817Z,1697476630.817 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20231016T143832/Express0089.lzma 2023-10-16T17:17:11.820Z,1697476631.820 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0089.lzma.bak 2023-10-16T17:17:11.820Z,1697476631.820 [DataOverHttps](INFO): SBD MOMSN=18998603 2023-10-16T17:17:12.922Z,1697476632.922 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T17:17:12.922Z,1697476632.922 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T17:17:12.922Z,1697476632.922 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T17:17:34.303Z,1697476654.303 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T17:22:13.542Z,1697476933.542 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T17:22:13.543Z,1697476933.543 [Default:CheckIn:C.Wait] Stopped 2023-10-16T17:22:13.543Z,1697476933.543 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T17:22:13.543Z,1697476933.543 [Default:CheckIn:D] Running Loop=1 2023-10-16T17:22:13.961Z,1697476933.961 [Default:CheckIn:D] Stopped 2023-10-16T17:22:13.961Z,1697476933.961 [Default:CheckIn:E] Running Loop=1 2023-10-16T17:22:14.382Z,1697476934.382 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 160.349284 min 2023-10-16T17:22:14.382Z,1697476934.382 [Default:CheckIn:E] Stopped 2023-10-16T17:22:14.382Z,1697476934.382 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T17:22:14.382Z,1697476934.382 [Default:CheckIn] Stopped 2023-10-16T17:22:14.382Z,1697476934.382 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T17:22:14.383Z,1697476934.383 [Default:CheckIn](INFO): Running loop #28 2023-10-16T17:22:14.383Z,1697476934.383 [Default:CheckIn] Running Loop=28 2023-10-16T17:22:14.383Z,1697476934.383 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T17:22:14.383Z,1697476934.383 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T17:22:16.356Z,1697476936.356 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172215.00,A,3648.14015,N,12147.23039,W,0.019,0.00,161023,,,A*73 2023-10-16T17:22:16.358Z,1697476936.358 [NAL9602](INFO): GPS fix at 20231016T172215: (36.802336, -121.787173) 2023-10-16T17:22:16.447Z,1697476936.447 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T17:22:16.447Z,1697476936.447 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T17:22:26.781Z,1697476946.781 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231016T143832/Courier0091.lzma 2023-10-16T17:22:27.785Z,1697476947.785 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0091.lzma.bak 2023-10-16T17:22:27.785Z,1697476947.785 [DataOverHttps](INFO): SBD MOMSN=18998613 2023-10-16T17:22:29.132Z,1697476949.132 [NAL9602](INFO): SBD MO Status=0, MOMSN=31871, MT Status=0, MTMSN=0 2023-10-16T17:22:29.133Z,1697476949.133 [NAL9602](INFO): No messages in MT queue 2023-10-16T17:22:44.369Z,1697476964.369 [DataOverHttps](INFO): Sending 138 bytes from file Logs/20231016T143832/Express0092.lzma 2023-10-16T17:22:45.373Z,1697476965.373 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0092.lzma.bak 2023-10-16T17:22:45.373Z,1697476965.373 [DataOverHttps](INFO): SBD MOMSN=18998616 2023-10-16T17:22:46.541Z,1697476966.541 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T17:22:46.541Z,1697476966.541 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T17:22:46.541Z,1697476966.541 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T17:22:59.830Z,1697476979.830 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T17:27:47.144Z,1697477267.144 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T17:27:47.144Z,1697477267.144 [Default:CheckIn:C.Wait] Stopped 2023-10-16T17:27:47.144Z,1697477267.144 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T17:27:47.145Z,1697477267.145 [Default:CheckIn:D] Running Loop=1 2023-10-16T17:27:47.567Z,1697477267.567 [Default:CheckIn:D] Stopped 2023-10-16T17:27:47.567Z,1697477267.567 [Default:CheckIn:E] Running Loop=1 2023-10-16T17:27:47.946Z,1697477267.946 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 165.909375 min 2023-10-16T17:27:47.946Z,1697477267.946 [Default:CheckIn:E] Stopped 2023-10-16T17:27:47.946Z,1697477267.946 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T17:27:47.946Z,1697477267.946 [Default:CheckIn] Stopped 2023-10-16T17:27:47.946Z,1697477267.946 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T17:27:47.947Z,1697477267.947 [Default:CheckIn](INFO): Running loop #29 2023-10-16T17:27:47.947Z,1697477267.947 [Default:CheckIn] Running Loop=29 2023-10-16T17:27:47.947Z,1697477267.947 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T17:27:47.947Z,1697477267.947 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T17:27:49.953Z,1697477269.953 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172749.00,A,3648.13955,N,12147.22852,W,0.019,0.00,161023,,,A*71 2023-10-16T17:27:49.955Z,1697477269.955 [NAL9602](INFO): GPS fix at 20231016T172749: (36.802326, -121.787142) 2023-10-16T17:27:49.967Z,1697477269.967 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T17:27:49.967Z,1697477269.967 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T17:27:50.790Z,1697477270.790 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T17:27:50.790Z,1697477270.790 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T17:27:50.791Z,1697477270.791 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T17:28:35.616Z,1697477315.616 [NAL9602](INFO): SBD MO Status=0, MOMSN=31872, MT Status=0, MTMSN=0 2023-10-16T17:28:35.616Z,1697477315.616 [NAL9602](INFO): No messages in MT queue 2023-10-16T17:29:06.315Z,1697477346.315 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T17:32:51.420Z,1697477571.420 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T17:32:51.420Z,1697477571.420 [Default:CheckIn:C.Wait] Stopped 2023-10-16T17:32:51.420Z,1697477571.420 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T17:32:51.420Z,1697477571.420 [Default:CheckIn:D] Running Loop=1 2023-10-16T17:32:51.827Z,1697477571.827 [Default:CheckIn:D] Stopped 2023-10-16T17:32:51.827Z,1697477571.827 [Default:CheckIn:E] Running Loop=1 2023-10-16T17:32:52.252Z,1697477572.252 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 170.980387 min 2023-10-16T17:32:52.252Z,1697477572.252 [Default:CheckIn:E] Stopped 2023-10-16T17:32:52.252Z,1697477572.252 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T17:32:52.252Z,1697477572.252 [Default:CheckIn] Stopped 2023-10-16T17:32:52.252Z,1697477572.252 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T17:32:52.253Z,1697477572.253 [Default:CheckIn](INFO): Running loop #30 2023-10-16T17:32:52.253Z,1697477572.253 [Default:CheckIn] Running Loop=30 2023-10-16T17:32:52.253Z,1697477572.253 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T17:32:52.253Z,1697477572.253 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T17:32:54.237Z,1697477574.237 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173253.00,A,3648.13913,N,12147.22841,W,0.039,0.00,161023,,,A*7C 2023-10-16T17:32:54.239Z,1697477574.239 [NAL9602](INFO): GPS fix at 20231016T173253: (36.802319, -121.787140) 2023-10-16T17:32:54.295Z,1697477574.295 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T17:32:54.295Z,1697477574.295 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T17:33:02.301Z,1697477582.301 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231016T143832/Courier0094.lzma 2023-10-16T17:33:03.304Z,1697477583.304 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0094.lzma.bak 2023-10-16T17:33:03.304Z,1697477583.304 [DataOverHttps](INFO): SBD MOMSN=18998638 2023-10-16T17:33:10.392Z,1697477590.392 [NAL9602](INFO): SBD MO Status=0, MOMSN=31873, MT Status=0, MTMSN=0 2023-10-16T17:33:10.392Z,1697477590.392 [NAL9602](INFO): No messages in MT queue 2023-10-16T17:33:19.721Z,1697477599.721 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231016T143832/Courier0097.lzma 2023-10-16T17:33:20.724Z,1697477600.724 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0097.lzma.bak 2023-10-16T17:33:20.724Z,1697477600.724 [DataOverHttps](INFO): SBD MOMSN=18998644 2023-10-16T17:33:36.934Z,1697477616.934 [DataOverHttps](INFO): Sending 167 bytes from file Logs/20231016T143832/Express0095.lzma 2023-10-16T17:33:37.936Z,1697477617.936 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0095.lzma.bak 2023-10-16T17:33:37.936Z,1697477617.936 [DataOverHttps](INFO): SBD MOMSN=18998647 2023-10-16T17:33:41.095Z,1697477621.095 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T17:33:54.305Z,1697477634.305 [DataOverHttps](INFO): Sending 163 bytes from file Logs/20231016T143832/Express0098.lzma 2023-10-16T17:33:55.308Z,1697477635.308 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0098.lzma.bak 2023-10-16T17:33:55.308Z,1697477635.308 [DataOverHttps](INFO): SBD MOMSN=18998650 2023-10-16T17:33:56.490Z,1697477636.490 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T17:33:56.490Z,1697477636.490 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T17:33:56.490Z,1697477636.490 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T17:38:57.050Z,1697477937.050 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T17:38:57.050Z,1697477937.050 [Default:CheckIn:C.Wait] Stopped 2023-10-16T17:38:57.050Z,1697477937.050 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T17:38:57.050Z,1697477937.050 [Default:CheckIn:D] Running Loop=1 2023-10-16T17:38:57.456Z,1697477937.456 [Default:CheckIn:D] Stopped 2023-10-16T17:38:57.456Z,1697477937.456 [Default:CheckIn:E] Running Loop=1 2023-10-16T17:38:57.875Z,1697477937.875 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 177.074202 min 2023-10-16T17:38:57.876Z,1697477937.876 [Default:CheckIn:E] Stopped 2023-10-16T17:38:57.876Z,1697477937.876 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T17:38:57.876Z,1697477937.876 [Default:CheckIn] Stopped 2023-10-16T17:38:57.876Z,1697477937.876 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T17:38:57.876Z,1697477937.876 [Default:CheckIn](INFO): Running loop #31 2023-10-16T17:38:57.876Z,1697477937.876 [Default:CheckIn] Running Loop=31 2023-10-16T17:38:57.876Z,1697477937.876 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T17:38:57.876Z,1697477937.876 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T17:38:59.868Z,1697477939.868 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173859.00,A,3648.13910,N,12147.22978,W,0.039,0.00,161023,,,A*74 2023-10-16T17:38:59.870Z,1697477939.870 [NAL9602](INFO): GPS fix at 20231016T173859: (36.802318, -121.787163) 2023-10-16T17:38:59.882Z,1697477939.882 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T17:38:59.882Z,1697477939.882 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T17:39:07.993Z,1697477947.993 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231016T143832/Courier0100.lzma 2023-10-16T17:39:08.996Z,1697477948.996 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0100.lzma.bak 2023-10-16T17:39:08.996Z,1697477948.996 [DataOverHttps](INFO): SBD MOMSN=18998667 2023-10-16T17:39:25.457Z,1697477965.457 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20231016T143832/Express0101.lzma 2023-10-16T17:39:26.583Z,1697477966.583 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0101.lzma.bak 2023-10-16T17:39:26.583Z,1697477966.583 [DataOverHttps](INFO): SBD MOMSN=18998670 2023-10-16T17:39:27.775Z,1697477967.775 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T17:39:27.775Z,1697477967.775 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T17:39:27.775Z,1697477967.775 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T17:40:21.901Z,1697478021.901 [NAL9602](INFO): SBD MO Status=0, MOMSN=31874, MT Status=0, MTMSN=0 2023-10-16T17:40:21.901Z,1697478021.901 [NAL9602](INFO): No messages in MT queue 2023-10-16T17:40:52.598Z,1697478052.598 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T17:44:28.473Z,1697478268.473 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T17:44:28.473Z,1697478268.473 [Default:CheckIn:C.Wait] Stopped 2023-10-16T17:44:28.473Z,1697478268.473 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T17:44:28.473Z,1697478268.473 [Default:CheckIn:D] Running Loop=1 2023-10-16T17:44:28.755Z,1697478268.755 [Default:CheckIn:D] Stopped 2023-10-16T17:44:28.755Z,1697478268.755 [Default:CheckIn:E] Running Loop=1 2023-10-16T17:44:29.166Z,1697478269.166 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 182.595850 min 2023-10-16T17:44:29.166Z,1697478269.166 [Default:CheckIn:E] Stopped 2023-10-16T17:44:29.166Z,1697478269.166 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T17:44:29.166Z,1697478269.166 [Default:CheckIn] Stopped 2023-10-16T17:44:29.166Z,1697478269.166 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T17:44:29.166Z,1697478269.166 [Default:CheckIn](INFO): Running loop #32 2023-10-16T17:44:29.166Z,1697478269.166 [Default:CheckIn] Running Loop=32 2023-10-16T17:44:29.166Z,1697478269.166 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T17:44:29.167Z,1697478269.167 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T17:44:31.165Z,1697478271.165 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174430.00,A,3648.13981,N,12147.22901,W,0.039,0.00,161023,,,A*76 2023-10-16T17:44:31.167Z,1697478271.167 [NAL9602](INFO): GPS fix at 20231016T174430: (36.802330, -121.787150) 2023-10-16T17:44:31.179Z,1697478271.179 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T17:44:31.179Z,1697478271.179 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T17:44:38.943Z,1697478278.943 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231016T143832/Courier0103.lzma 2023-10-16T17:44:39.944Z,1697478279.944 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0103.lzma.bak 2023-10-16T17:44:39.944Z,1697478279.944 [DataOverHttps](INFO): SBD MOMSN=18998683 2023-10-16T17:44:51.373Z,1697478291.373 [NAL9602](INFO): SBD MO Status=0, MOMSN=31875, MT Status=0, MTMSN=0 2023-10-16T17:44:51.373Z,1697478291.373 [NAL9602](INFO): No messages in MT queue 2023-10-16T17:44:56.257Z,1697478296.257 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20231016T143832/Express0104.lzma 2023-10-16T17:44:57.260Z,1697478297.260 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0104.lzma.bak 2023-10-16T17:44:57.260Z,1697478297.260 [DataOverHttps](INFO): SBD MOMSN=18998686 2023-10-16T17:44:58.315Z,1697478298.315 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T17:44:58.315Z,1697478298.315 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T17:44:58.315Z,1697478298.315 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T17:45:22.073Z,1697478322.073 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T17:49:58.852Z,1697478598.852 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T17:49:58.852Z,1697478598.852 [Default:CheckIn:C.Wait] Stopped 2023-10-16T17:49:58.852Z,1697478598.852 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T17:49:58.852Z,1697478598.852 [Default:CheckIn:D] Running Loop=1 2023-10-16T17:49:59.243Z,1697478599.243 [Default:CheckIn:D] Stopped 2023-10-16T17:49:59.243Z,1697478599.243 [Default:CheckIn:E] Running Loop=1 2023-10-16T17:49:59.647Z,1697478599.647 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 188.103971 min 2023-10-16T17:49:59.647Z,1697478599.647 [Default:CheckIn:E] Stopped 2023-10-16T17:49:59.647Z,1697478599.647 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T17:49:59.647Z,1697478599.647 [Default:CheckIn] Stopped 2023-10-16T17:49:59.647Z,1697478599.647 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T17:49:59.647Z,1697478599.647 [Default:CheckIn](INFO): Running loop #33 2023-10-16T17:49:59.647Z,1697478599.647 [Default:CheckIn] Running Loop=33 2023-10-16T17:49:59.648Z,1697478599.648 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T17:49:59.648Z,1697478599.648 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T17:50:01.659Z,1697478601.659 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175000.00,A,3648.14000,N,12147.22891,W,0.019,0.00,161023,,,A*7D 2023-10-16T17:50:01.661Z,1697478601.661 [NAL9602](INFO): GPS fix at 20231016T175000: (36.802333, -121.787149) 2023-10-16T17:50:01.673Z,1697478601.673 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T17:50:01.673Z,1697478601.673 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T17:50:09.337Z,1697478609.337 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20231016T143832/Courier0106.lzma 2023-10-16T17:50:10.340Z,1697478610.340 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0106.lzma.bak 2023-10-16T17:50:10.340Z,1697478610.340 [DataOverHttps](INFO): SBD MOMSN=18998707 2023-10-16T17:50:28.012Z,1697478628.012 [NAL9602](INFO): SBD MO Status=2, MOMSN=31876, MT Status=2, MTMSN=0 2023-10-16T17:50:28.013Z,1697478628.013 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-10-16T17:50:30.204Z,1697478630.204 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20231016T143832/Express0107.lzma 2023-10-16T17:50:31.204Z,1697478631.204 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0107.lzma.bak 2023-10-16T17:50:31.204Z,1697478631.204 [DataOverHttps](INFO): SBD MOMSN=18998710 2023-10-16T17:50:32.508Z,1697478632.508 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T17:50:32.508Z,1697478632.508 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T17:50:32.508Z,1697478632.508 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T17:51:02.363Z,1697478662.363 [NAL9602](INFO): SBD MO Status=0, MOMSN=31876, MT Status=0, MTMSN=0 2023-10-16T17:51:02.363Z,1697478662.363 [NAL9602](INFO): No messages in MT queue 2023-10-16T17:51:33.059Z,1697478693.059 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T17:55:33.076Z,1697478933.076 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T17:55:33.077Z,1697478933.077 [Default:CheckIn:C.Wait] Stopped 2023-10-16T17:55:33.077Z,1697478933.077 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T17:55:33.077Z,1697478933.077 [Default:CheckIn:D] Running Loop=1 2023-10-16T17:55:33.482Z,1697478933.482 [Default:CheckIn:D] Stopped 2023-10-16T17:55:33.482Z,1697478933.482 [Default:CheckIn:E] Running Loop=1 2023-10-16T17:55:33.924Z,1697478933.924 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 193.674626 min 2023-10-16T17:55:33.924Z,1697478933.924 [Default:CheckIn:E] Stopped 2023-10-16T17:55:33.924Z,1697478933.924 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T17:55:33.925Z,1697478933.925 [Default:CheckIn] Stopped 2023-10-16T17:55:33.925Z,1697478933.925 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T17:55:33.925Z,1697478933.925 [Default:CheckIn](INFO): Running loop #34 2023-10-16T17:55:33.925Z,1697478933.925 [Default:CheckIn] Running Loop=34 2023-10-16T17:55:33.925Z,1697478933.925 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T17:55:33.925Z,1697478933.925 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T17:55:35.897Z,1697478935.897 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175535.00,A,3648.13858,N,12147.22865,W,0.019,0.00,161023,,,A*77 2023-10-16T17:55:35.899Z,1697478935.899 [NAL9602](INFO): GPS fix at 20231016T175535: (36.802310, -121.787144) 2023-10-16T17:55:35.939Z,1697478935.939 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T17:55:35.939Z,1697478935.939 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T17:55:43.882Z,1697478943.882 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231016T143832/Courier0109.lzma 2023-10-16T17:55:44.884Z,1697478944.884 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0109.lzma.bak 2023-10-16T17:55:44.884Z,1697478944.884 [DataOverHttps](INFO): SBD MOMSN=18998724 2023-10-16T17:55:47.219Z,1697478947.219 [NAL9602](INFO): SBD MO Status=0, MOMSN=31877, MT Status=0, MTMSN=0 2023-10-16T17:55:47.219Z,1697478947.219 [NAL9602](INFO): No messages in MT queue 2023-10-16T17:56:01.322Z,1697478961.322 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20231016T143832/Express0110.lzma 2023-10-16T17:56:02.324Z,1697478962.324 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0110.lzma.bak 2023-10-16T17:56:02.324Z,1697478962.324 [DataOverHttps](INFO): SBD MOMSN=18998727 2023-10-16T17:56:03.391Z,1697478963.391 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T17:56:03.391Z,1697478963.391 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T17:56:03.391Z,1697478963.391 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T17:56:17.910Z,1697478977.910 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T18:01:04.019Z,1697479264.019 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T18:01:04.019Z,1697479264.019 [Default:CheckIn:C.Wait] Stopped 2023-10-16T18:01:04.020Z,1697479264.020 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T18:01:04.020Z,1697479264.020 [Default:CheckIn:D] Running Loop=1 2023-10-16T18:01:04.445Z,1697479264.445 [Default:CheckIn:D] Stopped 2023-10-16T18:01:04.445Z,1697479264.445 [Default:CheckIn:E] Running Loop=1 2023-10-16T18:01:04.823Z,1697479264.823 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 199.190674 min 2023-10-16T18:01:04.823Z,1697479264.823 [Default:CheckIn:E] Stopped 2023-10-16T18:01:04.824Z,1697479264.824 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T18:01:04.824Z,1697479264.824 [Default:CheckIn] Stopped 2023-10-16T18:01:04.824Z,1697479264.824 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T18:01:04.824Z,1697479264.824 [Default:CheckIn](INFO): Running loop #35 2023-10-16T18:01:04.824Z,1697479264.824 [Default:CheckIn] Running Loop=35 2023-10-16T18:01:04.824Z,1697479264.824 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T18:01:04.824Z,1697479264.824 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T18:01:06.833Z,1697479266.833 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180106.00,A,3648.13823,N,12147.22916,W,0.019,0.00,161023,,,A*70 2023-10-16T18:01:06.843Z,1697479266.843 [NAL9602](INFO): GPS fix at 20231016T180106: (36.802304, -121.787153) 2023-10-16T18:01:06.854Z,1697479266.854 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T18:01:06.855Z,1697479266.855 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T18:01:14.909Z,1697479274.909 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231016T143832/Courier0112.lzma 2023-10-16T18:01:15.912Z,1697479275.912 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0112.lzma.bak 2023-10-16T18:01:15.912Z,1697479275.912 [DataOverHttps](INFO): SBD MOMSN=18998747 2023-10-16T18:01:19.760Z,1697479279.760 [NAL9602](INFO): SBD MO Status=0, MOMSN=31878, MT Status=0, MTMSN=0 2023-10-16T18:01:19.761Z,1697479279.761 [NAL9602](INFO): No messages in MT queue 2023-10-16T18:01:32.298Z,1697479292.298 [DataOverHttps](INFO): Sending 138 bytes from file Logs/20231016T143832/Express0113.lzma 2023-10-16T18:01:33.300Z,1697479293.300 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0113.lzma.bak 2023-10-16T18:01:33.300Z,1697479293.300 [DataOverHttps](INFO): SBD MOMSN=18998750 2023-10-16T18:01:34.356Z,1697479294.356 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T18:01:34.356Z,1697479294.356 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T18:01:34.356Z,1697479294.356 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T18:01:50.487Z,1697479310.487 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T18:06:07.105Z,1697479567.105 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T18:06:20.033Z,1697479580.033 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T18:06:32.614Z,1697479592.614 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T18:06:35.082Z,1697479595.082 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T18:06:35.082Z,1697479595.082 [Default:CheckIn:C.Wait] Stopped 2023-10-16T18:06:35.082Z,1697479595.082 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T18:06:35.082Z,1697479595.082 [Default:CheckIn:D] Running Loop=1 2023-10-16T18:06:35.474Z,1697479595.474 [Default:CheckIn:D] Stopped 2023-10-16T18:06:35.474Z,1697479595.474 [Default:CheckIn:E] Running Loop=1 2023-10-16T18:06:35.880Z,1697479595.880 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 204.707829 min 2023-10-16T18:06:35.880Z,1697479595.880 [Default:CheckIn:E] Stopped 2023-10-16T18:06:35.880Z,1697479595.880 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T18:06:35.880Z,1697479595.880 [Default:CheckIn] Stopped 2023-10-16T18:06:35.880Z,1697479595.880 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T18:06:35.880Z,1697479595.880 [Default:CheckIn](INFO): Running loop #36 2023-10-16T18:06:35.881Z,1697479595.881 [Default:CheckIn] Running Loop=36 2023-10-16T18:06:35.881Z,1697479595.881 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T18:06:35.881Z,1697479595.881 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T18:06:37.873Z,1697479597.873 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180637.00,A,3648.13787,N,12147.22845,W,0.019,0.00,161023,,,A*73 2023-10-16T18:06:37.875Z,1697479597.875 [NAL9602](INFO): GPS fix at 20231016T180637: (36.802298, -121.787141) 2023-10-16T18:06:37.907Z,1697479597.907 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T18:06:37.907Z,1697479597.907 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T18:06:45.543Z,1697479605.543 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T18:06:46.069Z,1697479606.069 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20231016T143832/Courier0115.lzma 2023-10-16T18:06:47.072Z,1697479607.072 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0115.lzma.bak 2023-10-16T18:06:47.072Z,1697479607.072 [DataOverHttps](INFO): SBD MOMSN=18998765 2023-10-16T18:06:58.468Z,1697479618.468 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T18:07:03.517Z,1697479623.517 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20231016T143832/Express0116.lzma 2023-10-16T18:07:04.520Z,1697479624.520 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0116.lzma.bak 2023-10-16T18:07:04.520Z,1697479624.520 [DataOverHttps](INFO): SBD MOMSN=18998768 2023-10-16T18:07:05.769Z,1697479625.769 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T18:07:05.769Z,1697479625.769 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T18:07:05.769Z,1697479625.769 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T18:07:11.801Z,1697479631.801 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T18:07:24.340Z,1697479644.340 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T18:07:37.659Z,1697479657.659 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T18:07:50.991Z,1697479670.991 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T18:08:03.512Z,1697479683.512 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T18:08:16.846Z,1697479696.846 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T18:08:29.815Z,1697479709.815 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T18:08:33.870Z,1697479713.870 [NAL9602](INFO): SBD MO Status=2, MOMSN=31879, MT Status=2, MTMSN=0 2023-10-16T18:08:33.870Z,1697479713.870 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-10-16T18:08:36.711Z,1697479716.711 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5. 2023-10-16T18:08:36.713Z,1697479716.713 [BPC1](INFO): Received data from all battery sticks. 2023-10-16T18:08:51.637Z,1697479731.637 [NAL9602](INFO): SBD MO Status=2, MOMSN=31879, MT Status=2, MTMSN=0 2023-10-16T18:08:51.637Z,1697479731.637 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-10-16T18:09:43.353Z,1697479783.353 [NAL9602](INFO): SBD MO Status=2, MOMSN=31879, MT Status=2, MTMSN=0 2023-10-16T18:09:43.353Z,1697479783.353 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-10-16T18:10:01.132Z,1697479801.132 [NAL9602](INFO): SBD MO Status=2, MOMSN=31879, MT Status=2, MTMSN=0 2023-10-16T18:10:01.132Z,1697479801.132 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-10-16T18:10:14.057Z,1697479814.057 [NAL9602](INFO): SBD MO Status=0, MOMSN=31879, MT Status=0, MTMSN=0 2023-10-16T18:10:14.057Z,1697479814.057 [NAL9602](INFO): No messages in MT queue 2023-10-16T18:10:22.544Z,1697479822.544 [RDI_Pathfinder](ERROR): only read 3 of 4 data items for beam range. Device response is::RA, 0.00, 0.00, 0.00, 0.0V 2023-10-16T18:10:44.759Z,1697479844.759 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T18:12:06.410Z,1697479926.410 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T18:12:06.410Z,1697479926.410 [Default:CheckIn:C.Wait] Stopped 2023-10-16T18:12:06.410Z,1697479926.410 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T18:12:06.410Z,1697479926.410 [Default:CheckIn:D] Running Loop=1 2023-10-16T18:12:06.787Z,1697479926.787 [Default:CheckIn:D] Stopped 2023-10-16T18:12:06.787Z,1697479926.787 [Default:CheckIn:E] Running Loop=1 2023-10-16T18:12:07.191Z,1697479927.191 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 210.229704 min 2023-10-16T18:12:07.191Z,1697479927.191 [Default:CheckIn:E] Stopped 2023-10-16T18:12:07.191Z,1697479927.191 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T18:12:07.191Z,1697479927.191 [Default:CheckIn] Stopped 2023-10-16T18:12:07.191Z,1697479927.191 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T18:12:07.191Z,1697479927.191 [Default:CheckIn](INFO): Running loop #37 2023-10-16T18:12:07.192Z,1697479927.192 [Default:CheckIn] Running Loop=37 2023-10-16T18:12:07.192Z,1697479927.192 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T18:12:07.192Z,1697479927.192 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T18:12:09.196Z,1697479929.196 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181208.00,A,3648.14082,N,12147.22826,W,0.019,0.00,161023,,,A*7A 2023-10-16T18:12:09.210Z,1697479929.210 [NAL9602](INFO): GPS fix at 20231016T181208: (36.802347, -121.787138) 2023-10-16T18:12:09.222Z,1697479929.222 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T18:12:09.222Z,1697479929.222 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T18:12:20.213Z,1697479940.213 [DataOverHttps](INFO): Sending 83 bytes from file Logs/20231016T143832/Courier0118.lzma 2023-10-16T18:12:20.216Z,1697479940.216 [NAL9602](INFO): SBD MO Status=0, MOMSN=31880, MT Status=0, MTMSN=0 2023-10-16T18:12:20.216Z,1697479940.216 [NAL9602](INFO): No messages in MT queue 2023-10-16T18:12:21.216Z,1697479941.216 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0118.lzma.bak 2023-10-16T18:12:21.216Z,1697479941.216 [DataOverHttps](INFO): SBD MOMSN=18998786 2023-10-16T18:12:37.689Z,1697479957.689 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20231016T143832/Express0119.lzma 2023-10-16T18:12:38.692Z,1697479958.692 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0119.lzma.bak 2023-10-16T18:12:38.692Z,1697479958.692 [DataOverHttps](INFO): SBD MOMSN=18998789 2023-10-16T18:12:39.983Z,1697479959.983 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T18:12:39.983Z,1697479959.983 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T18:12:39.983Z,1697479959.983 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T18:12:50.875Z,1697479970.875 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T18:17:40.681Z,1697480260.681 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T18:17:40.681Z,1697480260.681 [Default:CheckIn:C.Wait] Stopped 2023-10-16T18:17:40.681Z,1697480260.681 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T18:17:40.681Z,1697480260.681 [Default:CheckIn:D] Running Loop=1 2023-10-16T18:17:41.106Z,1697480261.106 [Default:CheckIn:D] Stopped 2023-10-16T18:17:41.106Z,1697480261.106 [Default:CheckIn:E] Running Loop=1 2023-10-16T18:17:41.479Z,1697480261.479 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 215.801709 min 2023-10-16T18:17:41.479Z,1697480261.479 [Default:CheckIn:E] Stopped 2023-10-16T18:17:41.479Z,1697480261.479 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T18:17:41.479Z,1697480261.479 [Default:CheckIn] Stopped 2023-10-16T18:17:41.479Z,1697480261.479 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T18:17:41.480Z,1697480261.480 [Default:CheckIn](INFO): Running loop #38 2023-10-16T18:17:41.480Z,1697480261.480 [Default:CheckIn] Running Loop=38 2023-10-16T18:17:41.480Z,1697480261.480 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T18:17:41.480Z,1697480261.480 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T18:17:43.486Z,1697480263.486 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181742.00,A,3648.14142,N,12147.22839,W,0.019,0.00,161023,,,A*72 2023-10-16T18:17:43.488Z,1697480263.488 [NAL9602](INFO): GPS fix at 20231016T181742: (36.802357, -121.787140) 2023-10-16T18:17:43.505Z,1697480263.505 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T18:17:43.505Z,1697480263.505 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T18:17:51.509Z,1697480271.509 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231016T143832/Courier0121.lzma 2023-10-16T18:17:52.512Z,1697480272.512 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0121.lzma.bak 2023-10-16T18:17:52.512Z,1697480272.512 [DataOverHttps](INFO): SBD MOMSN=18998803 2023-10-16T18:18:08.925Z,1697480288.925 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20231016T143832/Express0122.lzma 2023-10-16T18:18:09.929Z,1697480289.929 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0122.lzma.bak 2023-10-16T18:18:09.929Z,1697480289.929 [DataOverHttps](INFO): SBD MOMSN=18998810 2023-10-16T18:18:10.988Z,1697480290.988 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T18:18:10.988Z,1697480290.988 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T18:18:10.988Z,1697480290.988 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T18:18:17.065Z,1697480297.065 [NAL9602](INFO): SBD MO Status=2, MOMSN=31881, MT Status=2, MTMSN=0 2023-10-16T18:18:17.065Z,1697480297.065 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-10-16T18:18:51.027Z,1697480331.027 [NAL9602](INFO): SBD MO Status=0, MOMSN=31881, MT Status=0, MTMSN=0 2023-10-16T18:18:51.027Z,1697480331.027 [NAL9602](INFO): No messages in MT queue 2023-10-16T18:19:21.715Z,1697480361.715 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T18:23:11.651Z,1697480591.651 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T18:23:11.651Z,1697480591.651 [Default:CheckIn:C.Wait] Stopped 2023-10-16T18:23:11.651Z,1697480591.651 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T18:23:11.651Z,1697480591.651 [Default:CheckIn:D] Running Loop=1 2023-10-16T18:23:12.033Z,1697480592.033 [Default:CheckIn:D] Stopped 2023-10-16T18:23:12.034Z,1697480592.034 [Default:CheckIn:E] Running Loop=1 2023-10-16T18:23:12.458Z,1697480592.458 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 221.317155 min 2023-10-16T18:23:12.458Z,1697480592.458 [Default:CheckIn:E] Stopped 2023-10-16T18:23:12.458Z,1697480592.458 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T18:23:12.458Z,1697480592.458 [Default:CheckIn] Stopped 2023-10-16T18:23:12.458Z,1697480592.458 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T18:23:12.459Z,1697480592.459 [Default:CheckIn](INFO): Running loop #39 2023-10-16T18:23:12.459Z,1697480592.459 [Default:CheckIn] Running Loop=39 2023-10-16T18:23:12.459Z,1697480592.459 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T18:23:12.459Z,1697480592.459 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T18:23:14.440Z,1697480594.440 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182313.00,A,3648.14144,N,12147.22824,W,0.039,0.00,161023,,,D*7C 2023-10-16T18:23:14.442Z,1697480594.442 [NAL9602](INFO): GPS fix at 20231016T182313: (36.802357, -121.787137) 2023-10-16T18:23:14.492Z,1697480594.492 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T18:23:14.492Z,1697480594.492 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T18:23:21.625Z,1697480601.625 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20231016T143832/Courier0124.lzma 2023-10-16T18:23:22.628Z,1697480602.628 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0124.lzma.bak 2023-10-16T18:23:22.628Z,1697480602.628 [DataOverHttps](INFO): SBD MOMSN=18998821 2023-10-16T18:23:28.988Z,1697480608.988 [NAL9602](INFO): SBD MO Status=0, MOMSN=31882, MT Status=0, MTMSN=0 2023-10-16T18:23:28.988Z,1697480608.988 [NAL9602](INFO): No messages in MT queue 2023-10-16T18:23:39.005Z,1697480619.005 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20231016T143832/Express0125.lzma 2023-10-16T18:23:40.008Z,1697480620.008 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0125.lzma.bak 2023-10-16T18:23:40.008Z,1697480620.008 [DataOverHttps](INFO): SBD MOMSN=18998824 2023-10-16T18:23:41.126Z,1697480621.126 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T18:23:41.127Z,1697480621.127 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T18:23:41.127Z,1697480621.127 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T18:23:59.686Z,1697480639.686 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T18:28:41.794Z,1697480921.794 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T18:28:41.794Z,1697480921.794 [Default:CheckIn:C.Wait] Stopped 2023-10-16T18:28:41.794Z,1697480921.794 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T18:28:41.794Z,1697480921.794 [Default:CheckIn:D] Running Loop=1 2023-10-16T18:28:42.248Z,1697480922.248 [Default:CheckIn:D] Stopped 2023-10-16T18:28:42.248Z,1697480922.248 [Default:CheckIn:E] Running Loop=1 2023-10-16T18:28:42.607Z,1697480922.607 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 226.820736 min 2023-10-16T18:28:42.607Z,1697480922.607 [Default:CheckIn:E] Stopped 2023-10-16T18:28:42.607Z,1697480922.607 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T18:28:42.608Z,1697480922.608 [Default:CheckIn] Stopped 2023-10-16T18:28:42.608Z,1697480922.608 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T18:28:42.608Z,1697480922.608 [Default:CheckIn](INFO): Running loop #40 2023-10-16T18:28:42.608Z,1697480922.608 [Default:CheckIn] Running Loop=40 2023-10-16T18:28:42.608Z,1697480922.608 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T18:28:42.608Z,1697480922.608 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T18:28:44.613Z,1697480924.613 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182843.00,A,3648.13883,N,12147.22898,W,0.039,0.00,161023,,,D*70 2023-10-16T18:28:44.615Z,1697480924.615 [NAL9602](INFO): GPS fix at 20231016T182843: (36.802314, -121.787150) 2023-10-16T18:28:44.647Z,1697480924.647 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T18:28:44.647Z,1697480924.647 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T18:28:52.669Z,1697480932.669 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20231016T143832/Courier0127.lzma 2023-10-16T18:28:53.672Z,1697480933.672 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0127.lzma.bak 2023-10-16T18:28:53.672Z,1697480933.672 [DataOverHttps](INFO): SBD MOMSN=18998841 2023-10-16T18:28:55.924Z,1697480935.924 [NAL9602](INFO): SBD MO Status=0, MOMSN=31883, MT Status=0, MTMSN=0 2023-10-16T18:28:55.924Z,1697480935.924 [NAL9602](INFO): No messages in MT queue 2023-10-16T18:29:10.017Z,1697480950.017 [DataOverHttps](INFO): Sending 141 bytes from file Logs/20231016T143832/Express0128.lzma 2023-10-16T18:29:11.020Z,1697480951.020 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0128.lzma.bak 2023-10-16T18:29:11.020Z,1697480951.020 [DataOverHttps](INFO): SBD MOMSN=18998844 2023-10-16T18:29:12.098Z,1697480952.098 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T18:29:12.098Z,1697480952.098 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T18:29:12.099Z,1697480952.099 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T18:29:26.631Z,1697480966.631 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T18:31:20.279Z,1697481080.279 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude. Device response is::BD, +0.00, +0.00, +0.006 2023-10-16T18:34:12.802Z,1697481252.802 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T18:34:12.802Z,1697481252.802 [Default:CheckIn:C.Wait] Stopped 2023-10-16T18:34:12.802Z,1697481252.802 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T18:34:12.802Z,1697481252.802 [Default:CheckIn:D] Running Loop=1 2023-10-16T18:34:13.183Z,1697481253.183 [Default:CheckIn:D] Stopped 2023-10-16T18:34:13.183Z,1697481253.183 [Default:CheckIn:E] Running Loop=1 2023-10-16T18:34:13.587Z,1697481253.587 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 232.336312 min 2023-10-16T18:34:13.587Z,1697481253.587 [Default:CheckIn:E] Stopped 2023-10-16T18:34:13.587Z,1697481253.587 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T18:34:13.587Z,1697481253.587 [Default:CheckIn] Stopped 2023-10-16T18:34:13.587Z,1697481253.587 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T18:34:13.588Z,1697481253.588 [Default:CheckIn](INFO): Running loop #41 2023-10-16T18:34:13.588Z,1697481253.588 [Default:CheckIn] Running Loop=41 2023-10-16T18:34:13.588Z,1697481253.588 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T18:34:13.588Z,1697481253.588 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T18:34:15.593Z,1697481255.593 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183414.00,A,3648.14144,N,12147.22961,W,0.078,0.00,161023,,,D*78 2023-10-16T18:34:15.611Z,1697481255.611 [NAL9602](INFO): GPS fix at 20231016T183414: (36.802357, -121.787160) 2023-10-16T18:34:15.632Z,1697481255.632 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T18:34:15.632Z,1697481255.632 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T18:34:26.047Z,1697481266.047 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231016T143832/Courier0130.lzma 2023-10-16T18:34:27.048Z,1697481267.048 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0130.lzma.bak 2023-10-16T18:34:27.048Z,1697481267.048 [DataOverHttps](INFO): SBD MOMSN=18998855 2023-10-16T18:34:33.440Z,1697481273.440 [NAL9602](INFO): SBD MO Status=0, MOMSN=31884, MT Status=0, MTMSN=0 2023-10-16T18:34:33.440Z,1697481273.440 [NAL9602](INFO): No messages in MT queue 2023-10-16T18:34:43.833Z,1697481283.833 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20231016T143832/Express0131.lzma 2023-10-16T18:34:44.836Z,1697481284.836 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0131.lzma.bak 2023-10-16T18:34:44.837Z,1697481284.837 [DataOverHttps](INFO): SBD MOMSN=18998858 2023-10-16T18:34:45.983Z,1697481285.983 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T18:34:45.983Z,1697481285.983 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T18:34:45.983Z,1697481285.983 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T18:35:04.146Z,1697481304.146 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T18:39:46.580Z,1697481586.580 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T18:39:46.580Z,1697481586.580 [Default:CheckIn:C.Wait] Stopped 2023-10-16T18:39:46.580Z,1697481586.580 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T18:39:46.580Z,1697481586.580 [Default:CheckIn:D] Running Loop=1 2023-10-16T18:39:46.963Z,1697481586.963 [Default:CheckIn:D] Stopped 2023-10-16T18:39:46.963Z,1697481586.963 [Default:CheckIn:E] Running Loop=1 2023-10-16T18:39:47.383Z,1697481587.383 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 237.899316 min 2023-10-16T18:39:47.383Z,1697481587.383 [Default:CheckIn:E] Stopped 2023-10-16T18:39:47.383Z,1697481587.383 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T18:39:47.383Z,1697481587.383 [Default:CheckIn] Stopped 2023-10-16T18:39:47.383Z,1697481587.383 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T18:39:47.383Z,1697481587.383 [Default:CheckIn](INFO): Running loop #42 2023-10-16T18:39:47.384Z,1697481587.384 [Default:CheckIn] Running Loop=42 2023-10-16T18:39:47.384Z,1697481587.384 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T18:39:47.384Z,1697481587.384 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T18:39:49.373Z,1697481589.373 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183948.00,A,3648.14156,N,12147.23039,W,0.000,0.00,161023,,,A*70 2023-10-16T18:39:49.376Z,1697481589.376 [NAL9602](INFO): GPS fix at 20231016T183948: (36.802359, -121.787173) 2023-10-16T18:39:49.388Z,1697481589.388 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T18:39:49.388Z,1697481589.388 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T18:39:57.073Z,1697481597.073 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20231016T143832/Courier0133.lzma 2023-10-16T18:39:58.076Z,1697481598.076 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0133.lzma.bak 2023-10-16T18:39:58.076Z,1697481598.076 [DataOverHttps](INFO): SBD MOMSN=18998875 2023-10-16T18:40:00.688Z,1697481600.688 [NAL9602](INFO): SBD MO Status=0, MOMSN=31885, MT Status=0, MTMSN=0 2023-10-16T18:40:00.688Z,1697481600.688 [NAL9602](INFO): No messages in MT queue 2023-10-16T18:40:18.014Z,1697481618.014 [DataOverHttps](INFO): Sending 143 bytes from file Logs/20231016T143832/Express0134.lzma 2023-10-16T18:40:19.016Z,1697481619.016 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0134.lzma.bak 2023-10-16T18:40:19.016Z,1697481619.016 [DataOverHttps](INFO): SBD MOMSN=18998878 2023-10-16T18:40:20.214Z,1697481620.214 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T18:40:20.214Z,1697481620.214 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T18:40:20.214Z,1697481620.214 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T18:40:31.443Z,1697481631.443 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T18:45:20.727Z,1697481920.727 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T18:45:20.727Z,1697481920.727 [Default:CheckIn:C.Wait] Stopped 2023-10-16T18:45:20.727Z,1697481920.727 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T18:45:20.727Z,1697481920.727 [Default:CheckIn:D] Running Loop=1 2023-10-16T18:45:21.134Z,1697481921.134 [Default:CheckIn:D] Stopped 2023-10-16T18:45:21.134Z,1697481921.134 [Default:CheckIn:E] Running Loop=1 2023-10-16T18:45:21.574Z,1697481921.574 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 243.468831 min 2023-10-16T18:45:21.574Z,1697481921.574 [Default:CheckIn:E] Stopped 2023-10-16T18:45:21.574Z,1697481921.574 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T18:45:21.574Z,1697481921.574 [Default:CheckIn] Stopped 2023-10-16T18:45:21.574Z,1697481921.574 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T18:45:21.575Z,1697481921.575 [Default:CheckIn](INFO): Running loop #43 2023-10-16T18:45:21.575Z,1697481921.575 [Default:CheckIn] Running Loop=43 2023-10-16T18:45:21.575Z,1697481921.575 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T18:45:21.575Z,1697481921.575 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T18:45:23.540Z,1697481923.540 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184522.00,A,3648.14030,N,12147.22974,W,0.039,0.00,161023,,,A*7D 2023-10-16T18:45:23.542Z,1697481923.542 [NAL9602](INFO): GPS fix at 20231016T184522: (36.802338, -121.787162) 2023-10-16T18:45:23.571Z,1697481923.571 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T18:45:23.571Z,1697481923.571 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T18:45:31.785Z,1697481931.785 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231016T143832/Courier0136.lzma 2023-10-16T18:45:32.788Z,1697481932.788 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0136.lzma.bak 2023-10-16T18:45:32.789Z,1697481932.789 [DataOverHttps](INFO): SBD MOMSN=18998891 2023-10-16T18:45:38.091Z,1697481938.091 [NAL9602](INFO): SBD MO Status=0, MOMSN=31886, MT Status=0, MTMSN=0 2023-10-16T18:45:38.091Z,1697481938.091 [NAL9602](INFO): No messages in MT queue 2023-10-16T18:45:49.129Z,1697481949.129 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20231016T143832/Express0137.lzma 2023-10-16T18:45:50.132Z,1697481950.132 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0137.lzma.bak 2023-10-16T18:45:50.132Z,1697481950.132 [DataOverHttps](INFO): SBD MOMSN=18998894 2023-10-16T18:45:51.434Z,1697481951.434 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T18:45:51.434Z,1697481951.434 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T18:45:51.434Z,1697481951.434 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T18:46:08.791Z,1697481968.791 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T18:50:52.031Z,1697482252.031 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T18:50:52.031Z,1697482252.031 [Default:CheckIn:C.Wait] Stopped 2023-10-16T18:50:52.031Z,1697482252.031 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T18:50:52.031Z,1697482252.031 [Default:CheckIn:D] Running Loop=1 2023-10-16T18:50:52.447Z,1697482252.447 [Default:CheckIn:D] Stopped 2023-10-16T18:50:52.447Z,1697482252.447 [Default:CheckIn:E] Running Loop=1 2023-10-16T18:50:52.821Z,1697482252.821 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 248.990723 min 2023-10-16T18:50:52.821Z,1697482252.821 [Default:CheckIn:E] Stopped 2023-10-16T18:50:52.821Z,1697482252.821 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T18:50:52.821Z,1697482252.821 [Default:CheckIn] Stopped 2023-10-16T18:50:52.821Z,1697482252.821 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T18:50:52.821Z,1697482252.821 [Default:CheckIn](INFO): Running loop #44 2023-10-16T18:50:52.822Z,1697482252.822 [Default:CheckIn] Running Loop=44 2023-10-16T18:50:52.822Z,1697482252.822 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T18:50:52.822Z,1697482252.822 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T18:50:54.834Z,1697482254.834 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185054.00,A,3648.14068,N,12147.22979,W,0.078,0.00,161023,,,D*78 2023-10-16T18:50:54.837Z,1697482254.837 [NAL9602](INFO): GPS fix at 20231016T185054: (36.802345, -121.787163) 2023-10-16T18:50:54.848Z,1697482254.848 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T18:50:54.849Z,1697482254.849 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T18:51:02.013Z,1697482262.013 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231016T143832/Courier0139.lzma 2023-10-16T18:51:03.016Z,1697482263.016 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0139.lzma.bak 2023-10-16T18:51:03.016Z,1697482263.016 [DataOverHttps](INFO): SBD MOMSN=18998913 2023-10-16T18:51:06.173Z,1697482266.173 [NAL9602](INFO): SBD MO Status=0, MOMSN=31887, MT Status=0, MTMSN=0 2023-10-16T18:51:06.173Z,1697482266.173 [NAL9602](INFO): No messages in MT queue 2023-10-16T18:51:19.777Z,1697482279.777 [DataOverHttps](INFO): Sending 137 bytes from file Logs/20231016T143832/Express0140.lzma 2023-10-16T18:51:20.780Z,1697482280.780 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0140.lzma.bak 2023-10-16T18:51:20.780Z,1697482280.780 [DataOverHttps](INFO): SBD MOMSN=18998916 2023-10-16T18:51:21.910Z,1697482281.910 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T18:51:21.910Z,1697482281.910 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T18:51:21.910Z,1697482281.910 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T18:51:36.867Z,1697482296.867 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T18:56:22.628Z,1697482582.628 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T18:56:22.628Z,1697482582.628 [Default:CheckIn:C.Wait] Stopped 2023-10-16T18:56:22.628Z,1697482582.628 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T18:56:22.628Z,1697482582.628 [Default:CheckIn:D] Running Loop=1 2023-10-16T18:56:22.946Z,1697482582.946 [Default:CheckIn:D] Stopped 2023-10-16T18:56:22.946Z,1697482582.946 [Default:CheckIn:E] Running Loop=1 2023-10-16T18:56:23.359Z,1697482583.359 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 254.499040 min 2023-10-16T18:56:23.359Z,1697482583.359 [Default:CheckIn:E] Stopped 2023-10-16T18:56:23.359Z,1697482583.359 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T18:56:23.359Z,1697482583.359 [Default:CheckIn] Stopped 2023-10-16T18:56:23.359Z,1697482583.359 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T18:56:23.359Z,1697482583.359 [Default:CheckIn](INFO): Running loop #45 2023-10-16T18:56:23.360Z,1697482583.360 [Default:CheckIn] Running Loop=45 2023-10-16T18:56:23.360Z,1697482583.360 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T18:56:23.360Z,1697482583.360 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T18:56:25.348Z,1697482585.348 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185624.00,A,3648.15133,N,12147.22265,W,0.039,159.11,161023,,,A*7C 2023-10-16T18:56:25.350Z,1697482585.350 [NAL9602](INFO): GPS fix at 20231016T185624: (36.802522, -121.787044) 2023-10-16T18:56:25.362Z,1697482585.362 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T18:56:25.362Z,1697482585.362 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T18:56:32.657Z,1697482592.657 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20231016T143832/Courier0142.lzma 2023-10-16T18:56:33.660Z,1697482593.660 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0142.lzma.bak 2023-10-16T18:56:33.660Z,1697482593.660 [DataOverHttps](INFO): SBD MOMSN=18998928 2023-10-16T18:56:50.017Z,1697482610.017 [DataOverHttps](INFO): Sending 138 bytes from file Logs/20231016T143832/Express0143.lzma 2023-10-16T18:56:51.020Z,1697482611.020 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0143.lzma.bak 2023-10-16T18:56:51.020Z,1697482611.020 [DataOverHttps](INFO): SBD MOMSN=18998931 2023-10-16T18:56:52.457Z,1697482612.457 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T18:56:52.457Z,1697482612.457 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T18:56:52.457Z,1697482612.457 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T18:57:32.416Z,1697482652.416 [NAL9602](INFO): SBD MO Status=0, MOMSN=31888, MT Status=0, MTMSN=0 2023-10-16T18:57:32.416Z,1697482652.416 [NAL9602](INFO): No messages in MT queue 2023-10-16T18:57:52.239Z,1697482672.239 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS,231016105856 0.0,1524.7, 0 2023-10-16T18:58:03.125Z,1697482683.125 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T19:01:53.006Z,1697482913.006 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T19:01:53.006Z,1697482913.006 [Default:CheckIn:C.Wait] Stopped 2023-10-16T19:01:53.006Z,1697482913.006 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T19:01:53.006Z,1697482913.006 [Default:CheckIn:D] Running Loop=1 2023-10-16T19:01:53.419Z,1697482913.419 [Default:CheckIn:D] Stopped 2023-10-16T19:01:53.419Z,1697482913.419 [Default:CheckIn:E] Running Loop=1 2023-10-16T19:01:53.824Z,1697482913.824 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 260.006917 min 2023-10-16T19:01:53.825Z,1697482913.825 [Default:CheckIn:E] Stopped 2023-10-16T19:01:53.825Z,1697482913.825 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T19:01:53.825Z,1697482913.825 [Default:CheckIn] Stopped 2023-10-16T19:01:53.825Z,1697482913.825 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T19:01:53.825Z,1697482913.825 [Default:CheckIn](INFO): Running loop #46 2023-10-16T19:01:53.825Z,1697482913.825 [Default:CheckIn] Running Loop=46 2023-10-16T19:01:53.825Z,1697482913.825 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T19:01:53.825Z,1697482913.825 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T19:01:55.821Z,1697482915.821 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190155.00,A,3648.15056,N,12147.22293,W,0.039,159.11,161023,,,A*72 2023-10-16T19:01:55.823Z,1697482915.823 [NAL9602](INFO): GPS fix at 20231016T190155: (36.802509, -121.787049) 2023-10-16T19:01:55.839Z,1697482915.839 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T19:01:55.839Z,1697482915.839 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T19:02:03.021Z,1697482923.021 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231016T143832/Courier0145.lzma 2023-10-16T19:02:04.024Z,1697482924.024 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0145.lzma.bak 2023-10-16T19:02:04.024Z,1697482924.024 [DataOverHttps](INFO): SBD MOMSN=18998948 2023-10-16T19:02:05.920Z,1697482925.920 [NAL9602](INFO): SBD MO Status=0, MOMSN=31889, MT Status=0, MTMSN=0 2023-10-16T19:02:05.920Z,1697482925.920 [NAL9602](INFO): No messages in MT queue 2023-10-16T19:02:24.140Z,1697482944.140 [DataOverHttps](INFO): Sending 137 bytes from file Logs/20231016T143832/Express0146.lzma 2023-10-16T19:02:25.140Z,1697482945.140 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0146.lzma.bak 2023-10-16T19:02:25.140Z,1697482945.140 [DataOverHttps](INFO): SBD MOMSN=18998951 2023-10-16T19:02:26.255Z,1697482946.255 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T19:02:26.255Z,1697482946.255 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T19:02:26.255Z,1697482946.255 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T19:02:36.695Z,1697482956.695 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T19:07:26.850Z,1697483246.850 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T19:07:26.850Z,1697483246.850 [Default:CheckIn:C.Wait] Stopped 2023-10-16T19:07:26.850Z,1697483246.850 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T19:07:26.850Z,1697483246.850 [Default:CheckIn:D] Running Loop=1 2023-10-16T19:07:27.266Z,1697483247.266 [Default:CheckIn:D] Stopped 2023-10-16T19:07:27.266Z,1697483247.266 [Default:CheckIn:E] Running Loop=1 2023-10-16T19:07:27.680Z,1697483247.680 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 265.571029 min 2023-10-16T19:07:27.680Z,1697483247.680 [Default:CheckIn:E] Stopped 2023-10-16T19:07:27.681Z,1697483247.681 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T19:07:27.681Z,1697483247.681 [Default:CheckIn] Stopped 2023-10-16T19:07:27.681Z,1697483247.681 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T19:07:27.681Z,1697483247.681 [Default:CheckIn](INFO): Running loop #47 2023-10-16T19:07:27.681Z,1697483247.681 [Default:CheckIn] Running Loop=47 2023-10-16T19:07:27.681Z,1697483247.681 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T19:07:27.681Z,1697483247.681 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T19:07:29.664Z,1697483249.664 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190728.00,A,3648.31341,N,12147.11723,W,4.257,5.38,161023,,,D*7B 2023-10-16T19:07:29.667Z,1697483249.667 [NAL9602](INFO): GPS fix at 20231016T190728: (36.805223, -121.785287) 2023-10-16T19:07:29.679Z,1697483249.679 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T19:07:29.679Z,1697483249.679 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T19:07:36.849Z,1697483256.849 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20231016T143832/Courier0148.lzma 2023-10-16T19:07:37.852Z,1697483257.852 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0148.lzma.bak 2023-10-16T19:07:37.852Z,1697483257.852 [DataOverHttps](INFO): SBD MOMSN=18998962 2023-10-16T19:07:54.449Z,1697483274.449 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20231016T143832/Express0149.lzma 2023-10-16T19:07:55.452Z,1697483275.452 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0149.lzma.bak 2023-10-16T19:07:55.452Z,1697483275.452 [DataOverHttps](INFO): SBD MOMSN=18998965 2023-10-16T19:07:56.509Z,1697483276.509 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T19:07:56.509Z,1697483276.509 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T19:07:56.509Z,1697483276.509 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T19:08:34.421Z,1697483314.421 [NAL9602](INFO): SBD MO Status=0, MOMSN=31890, MT Status=0, MTMSN=0 2023-10-16T19:08:34.421Z,1697483314.421 [NAL9602](INFO): No messages in MT queue 2023-10-16T19:09:05.124Z,1697483345.124 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T19:12:57.067Z,1697483577.067 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T19:12:57.067Z,1697483577.067 [Default:CheckIn:C.Wait] Stopped 2023-10-16T19:12:57.067Z,1697483577.067 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T19:12:57.067Z,1697483577.067 [Default:CheckIn:D] Running Loop=1 2023-10-16T19:12:57.478Z,1697483577.478 [Default:CheckIn:D] Stopped 2023-10-16T19:12:57.478Z,1697483577.478 [Default:CheckIn:E] Running Loop=1 2023-10-16T19:12:57.871Z,1697483577.871 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 271.074365 min 2023-10-16T19:12:57.871Z,1697483577.871 [Default:CheckIn:E] Stopped 2023-10-16T19:12:57.871Z,1697483577.871 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T19:12:57.871Z,1697483577.871 [Default:CheckIn] Stopped 2023-10-16T19:12:57.872Z,1697483577.872 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T19:12:57.872Z,1697483577.872 [Default:CheckIn](INFO): Running loop #48 2023-10-16T19:12:57.872Z,1697483577.872 [Default:CheckIn] Running Loop=48 2023-10-16T19:12:57.872Z,1697483577.872 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T19:12:57.872Z,1697483577.872 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T19:12:59.881Z,1697483579.881 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191259.00,A,3648.39088,N,12147.43695,W,8.009,229.59,161023,,,D*72 2023-10-16T19:12:59.884Z,1697483579.884 [NAL9602](INFO): GPS fix at 20231016T191259: (36.806515, -121.790616) 2023-10-16T19:12:59.895Z,1697483579.895 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T19:12:59.896Z,1697483579.896 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T19:13:07.945Z,1697483587.945 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231016T143832/Courier0151.lzma 2023-10-16T19:13:08.948Z,1697483588.948 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0151.lzma.bak 2023-10-16T19:13:08.948Z,1697483588.948 [DataOverHttps](INFO): SBD MOMSN=18998984 2023-10-16T19:13:23.336Z,1697483603.336 [NAL9602](INFO): SBD MO Status=0, MOMSN=31891, MT Status=0, MTMSN=0 2023-10-16T19:13:23.337Z,1697483603.337 [NAL9602](INFO): No messages in MT queue 2023-10-16T19:13:25.709Z,1697483605.709 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20231016T143832/Express0152.lzma 2023-10-16T19:13:26.712Z,1697483606.712 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0152.lzma.bak 2023-10-16T19:13:26.712Z,1697483606.712 [DataOverHttps](INFO): SBD MOMSN=18998987 2023-10-16T19:13:27.791Z,1697483607.791 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T19:13:27.791Z,1697483607.791 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T19:13:27.791Z,1697483607.791 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T19:13:31.813Z,1697483611.813 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T19:13:38.277Z,1697483618.277 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T19:13:50.800Z,1697483630.800 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T19:13:54.039Z,1697483634.039 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T19:14:04.139Z,1697483644.139 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T19:14:17.464Z,1697483657.464 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T19:14:29.994Z,1697483669.994 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T19:14:42.930Z,1697483682.930 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T19:14:56.262Z,1697483696.262 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T19:15:08.368Z,1697483708.368 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T19:15:21.701Z,1697483721.701 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T19:15:34.225Z,1697483734.225 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T19:15:47.154Z,1697483747.154 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-10-16T19:16:02.916Z,1697483762.916 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5. 2023-10-16T19:16:02.918Z,1697483762.918 [BPC1](INFO): Received data from all battery sticks. 2023-10-16T19:18:28.552Z,1697483908.552 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T19:18:28.552Z,1697483908.552 [Default:CheckIn:C.Wait] Stopped 2023-10-16T19:18:28.552Z,1697483908.552 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T19:18:28.552Z,1697483908.552 [Default:CheckIn:D] Running Loop=1 2023-10-16T19:18:28.903Z,1697483908.903 [Default:CheckIn:D] Stopped 2023-10-16T19:18:28.903Z,1697483908.903 [Default:CheckIn:E] Running Loop=1 2023-10-16T19:18:29.286Z,1697483909.286 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 276.598307 min 2023-10-16T19:18:29.286Z,1697483909.286 [Default:CheckIn:E] Stopped 2023-10-16T19:18:29.286Z,1697483909.286 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T19:18:29.286Z,1697483909.286 [Default:CheckIn] Stopped 2023-10-16T19:18:29.286Z,1697483909.286 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T19:18:29.286Z,1697483909.286 [Default:CheckIn](INFO): Running loop #49 2023-10-16T19:18:29.286Z,1697483909.286 [Default:CheckIn] Running Loop=49 2023-10-16T19:18:29.287Z,1697483909.287 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T19:18:29.287Z,1697483909.287 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T19:18:31.295Z,1697483911.295 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191830.00,A,3648.06721,N,12148.88741,W,15.570,258.23,161023,,,D*43 2023-10-16T19:18:31.298Z,1697483911.298 [NAL9602](INFO): GPS fix at 20231016T191830: (36.801120, -121.814790) 2023-10-16T19:18:31.309Z,1697483911.309 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T19:18:31.309Z,1697483911.309 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T19:18:39.037Z,1697483919.037 [DataOverHttps](INFO): Sending 84 bytes from file Logs/20231016T143832/Courier0154.lzma 2023-10-16T19:18:40.040Z,1697483920.040 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0154.lzma.bak 2023-10-16T19:18:40.040Z,1697483920.040 [DataOverHttps](INFO): SBD MOMSN=18998998 2023-10-16T19:18:40.584Z,1697483920.584 [NAL9602](INFO): SBD MO Status=0, MOMSN=31892, MT Status=0, MTMSN=0 2023-10-16T19:18:40.584Z,1697483920.584 [NAL9602](INFO): No messages in MT queue 2023-10-16T19:18:56.497Z,1697483936.497 [DataOverHttps](INFO): Sending 156 bytes from file Logs/20231016T143832/Express0155.lzma 2023-10-16T19:18:57.500Z,1697483937.500 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0155.lzma.bak 2023-10-16T19:18:57.500Z,1697483937.500 [DataOverHttps](INFO): SBD MOMSN=18999001 2023-10-16T19:18:58.779Z,1697483938.779 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T19:18:58.779Z,1697483938.779 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T19:18:58.779Z,1697483938.779 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T19:19:11.295Z,1697483951.295 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T19:23:59.394Z,1697484239.394 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-10-16T19:23:59.394Z,1697484239.394 [Default:CheckIn:C.Wait] Stopped 2023-10-16T19:23:59.394Z,1697484239.394 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-10-16T19:23:59.394Z,1697484239.394 [Default:CheckIn:D] Running Loop=1 2023-10-16T19:23:59.803Z,1697484239.803 [Default:CheckIn:D] Stopped 2023-10-16T19:23:59.804Z,1697484239.804 [Default:CheckIn:E] Running Loop=1 2023-10-16T19:24:00.245Z,1697484240.245 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 282.113314 min 2023-10-16T19:24:00.245Z,1697484240.245 [Default:CheckIn:E] Stopped 2023-10-16T19:24:00.245Z,1697484240.245 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-10-16T19:24:00.266Z,1697484240.266 [Default:CheckIn] Stopped 2023-10-16T19:24:00.266Z,1697484240.266 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-10-16T19:24:00.266Z,1697484240.266 [Default:CheckIn](INFO): Running loop #50 2023-10-16T19:24:00.266Z,1697484240.266 [Default:CheckIn] Running Loop=50 2023-10-16T19:24:00.266Z,1697484240.266 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-10-16T19:24:00.266Z,1697484240.266 [Default:CheckIn:Read_GPS] Running Loop=1 2023-10-16T19:24:02.221Z,1697484242.221 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192401.00,A,3647.75968,N,12150.83279,W,2.313,302.96,161023,,,A*7A 2023-10-16T19:24:02.223Z,1697484242.223 [NAL9602](INFO): GPS fix at 20231016T192401: (36.795995, -121.847213) 2023-10-16T19:24:02.271Z,1697484242.271 [Default:CheckIn:Read_GPS] Stopped 2023-10-16T19:24:02.272Z,1697484242.272 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-10-16T19:24:10.285Z,1697484250.285 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20231016T143832/Courier0157.lzma 2023-10-16T19:24:11.288Z,1697484251.288 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Courier0157.lzma.bak 2023-10-16T19:24:11.289Z,1697484251.289 [DataOverHttps](INFO): SBD MOMSN=18999018 2023-10-16T19:24:23.725Z,1697484263.725 [NAL9602](INFO): SBD MO Status=2, MOMSN=31893, MT Status=2, MTMSN=0 2023-10-16T19:24:23.725Z,1697484263.725 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-10-16T19:24:31.505Z,1697484271.505 [DataOverHttps](INFO): Sending 156 bytes from file Logs/20231016T143832/Express0158.lzma 2023-10-16T19:24:34.516Z,1697484274.516 [DataOverHttps](INFO): Moved sent file to Logs/20231016T143832/Express0158.lzma.bak 2023-10-16T19:24:34.516Z,1697484274.516 [DataOverHttps](INFO): SBD MOMSN=18999021 2023-10-16T19:24:35.429Z,1697484275.429 [NAL9602](INFO): SBD MO Status=0, MOMSN=31893, MT Status=0, MTMSN=0 2023-10-16T19:24:35.429Z,1697484275.429 [NAL9602](INFO): No messages in MT queue 2023-10-16T19:24:35.848Z,1697484275.848 [Default:CheckIn:Read_Iridium] Stopped 2023-10-16T19:24:35.848Z,1697484275.848 [Default:CheckIn:C.Wait] Running Loop=1 2023-10-16T19:24:35.848Z,1697484275.848 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-10-16T19:25:06.127Z,1697484306.127 [NAL9602](INFO): Not Powering down - fast GPS 2023-10-16T19:25:50.558Z,1697484350.558 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.238857 2023-10-16T19:26:51.830Z,1697484411.830 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-10-16T19:27:07.486Z,1697484427.486 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002719 2023-10-16T19:28:02.702Z,1697484482.702 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-10-16T19:28:07.723Z,1697484487.723 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.239815 2023-10-16T19:28:50.483Z,1697484530.483 [DataOverHttps](IMPORTANT): SBD MTMSN=20231016T192849 2023-10-16T19:28:50.486Z,1697484530.486 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003139