2024-02-14T18:40:02.710Z,1707936002.710 [Supervisor](DEBUG): Initializing supervisor. 2024-02-14T18:40:02.714Z,1707936002.714 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2024-02-14T18:40:02.715Z,1707936002.715 [SyncHandler](INFO): Protected caller Thread ID is 1337 2024-02-14T18:40:02.715Z,1707936002.715 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2024-02-14T18:40:02.716Z,1707936002.716 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2024-02-14T18:40:02.717Z,1707936002.717 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1338 2024-02-14T18:40:02.721Z,1707936002.721 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2024-02-14T18:40:02.739Z,1707936002.739 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2024-02-14T18:40:02.739Z,1707936002.739 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2024-02-14T18:40:02.740Z,1707936002.740 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 1339 2024-02-14T18:40:02.744Z,1707936002.744 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2024-02-14T18:40:02.745Z,1707936002.745 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2024-02-14T18:40:02.745Z,1707936002.745 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1340 2024-02-14T18:40:02.748Z,1707936002.748 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2024-02-14T18:40:02.748Z,1707936002.748 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2024-02-14T18:40:02.749Z,1707936002.749 [logger ThreadHandler](INFO): Protected caller Thread ID is 1341 2024-02-14T18:40:02.753Z,1707936002.753 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2024-02-14T18:40:02.753Z,1707936002.753 [Supervisor](INFO): Looking for Config files in directory: Config/ 2024-02-14T18:40:02.754Z,1707936002.754 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2024-02-14T18:40:03.071Z,1707936003.071 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2024-02-14T18:40:03.072Z,1707936003.072 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2024-02-14T18:40:03.167Z,1707936003.167 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2024-02-14T18:40:03.656Z,1707936003.656 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2024-02-14T18:40:03.657Z,1707936003.657 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2024-02-14T18:40:03.983Z,1707936003.983 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2024-02-14T18:40:03.984Z,1707936003.984 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2024-02-14T18:40:04.080Z,1707936004.080 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2024-02-14T18:40:04.080Z,1707936004.080 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2024-02-14T18:40:04.475Z,1707936004.475 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2024-02-14T18:40:04.476Z,1707936004.476 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2024-02-14T18:40:04.691Z,1707936004.691 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2024-02-14T18:40:04.691Z,1707936004.691 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2024-02-14T18:40:05.744Z,1707936005.744 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2024-02-14T18:40:05.745Z,1707936005.745 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2024-02-14T18:40:06.002Z,1707936006.002 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2024-02-14T18:40:06.002Z,1707936006.002 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2024-02-14T18:40:06.121Z,1707936006.121 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2024-02-14T18:40:07.716Z,1707936007.716 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2024-02-14T18:40:07.716Z,1707936007.716 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2024-02-14T18:40:08.504Z,1707936008.504 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2024-02-14T18:40:08.505Z,1707936008.505 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2024-02-14T18:40:08.958Z,1707936008.958 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2024-02-14T18:40:08.959Z,1707936008.959 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2024-02-14T18:40:09.152Z,1707936009.152 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2024-02-14T18:40:09.153Z,1707936009.153 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2024-02-14T18:40:09.464Z,1707936009.464 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2024-02-14T18:40:09.465Z,1707936009.465 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2024-02-14T18:40:09.711Z,1707936009.711 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2024-02-14T18:40:09.713Z,1707936009.713 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2024-02-14T18:40:09.714Z,1707936009.714 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg 2024-02-14T18:40:09.805Z,1707936009.805 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2024-02-14T18:40:09.891Z,1707936009.891 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2024-02-14T18:40:09.993Z,1707936009.993 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2024-02-14T18:40:10.077Z,1707936010.077 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2024-02-14T18:40:10.180Z,1707936010.180 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2024-02-14T18:40:10.282Z,1707936010.282 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2024-02-14T18:40:10.396Z,1707936010.396 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2024-02-14T18:40:10.545Z,1707936010.545 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2024-02-14T18:40:10.685Z,1707936010.685 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2024-02-14T18:40:10.797Z,1707936010.797 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg 2024-02-14T18:40:11.062Z,1707936011.062 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2024-02-14T18:40:11.063Z,1707936011.063 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/ 2024-02-14T18:40:11.064Z,1707936011.064 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2024-02-14T18:40:11.072Z,1707936011.072 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2024-02-14T18:40:11.124Z,1707936011.124 [VerticalControl](DEBUG): Construct VerticalControl. 2024-02-14T18:40:11.185Z,1707936011.185 [VerticalControl] Loaded 2024-02-14T18:40:11.185Z,1707936011.185 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2024-02-14T18:40:11.188Z,1707936011.188 [HorizontalControl](DEBUG): Construct HorizontalControl. 2024-02-14T18:40:11.230Z,1707936011.230 [HorizontalControl] Loaded 2024-02-14T18:40:11.230Z,1707936011.230 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2024-02-14T18:40:11.232Z,1707936011.232 [SpeedControl](DEBUG): Construct SpeedControl. 2024-02-14T18:40:11.235Z,1707936011.235 [SpeedControl] Loaded 2024-02-14T18:40:11.235Z,1707936011.235 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2024-02-14T18:40:11.238Z,1707936011.238 [LoopControl](DEBUG): Construct LoopControl. 2024-02-14T18:40:11.239Z,1707936011.239 [LoopControl] Loaded 2024-02-14T18:40:11.239Z,1707936011.239 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2024-02-14T18:40:11.239Z,1707936011.239 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2024-02-14T18:40:11.240Z,1707936011.240 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2024-02-14T18:40:11.250Z,1707936011.250 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2024-02-14T18:40:11.250Z,1707936011.250 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2024-02-14T18:40:11.400Z,1707936011.400 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2024-02-14T18:40:11.400Z,1707936011.400 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2024-02-14T18:40:11.556Z,1707936011.556 [BuoyancyServo] Loaded 2024-02-14T18:40:11.556Z,1707936011.556 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2024-02-14T18:40:11.576Z,1707936011.576 [ElevatorServo] Loaded 2024-02-14T18:40:11.577Z,1707936011.577 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2024-02-14T18:40:11.595Z,1707936011.595 [MassServo] Loaded 2024-02-14T18:40:11.596Z,1707936011.596 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2024-02-14T18:40:11.614Z,1707936011.614 [RudderServo] Loaded 2024-02-14T18:40:11.614Z,1707936011.614 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2024-02-14T18:40:11.629Z,1707936011.629 [ThrusterHE] Loaded 2024-02-14T18:40:11.629Z,1707936011.629 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2024-02-14T18:40:11.630Z,1707936011.630 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2024-02-14T18:40:11.630Z,1707936011.630 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2024-02-14T18:40:11.744Z,1707936011.744 [DeadReckonUsingMultipleVelocitySources] Loaded 2024-02-14T18:40:11.744Z,1707936011.744 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2024-02-14T18:40:11.758Z,1707936011.758 [NavChart] Loaded 2024-02-14T18:40:11.758Z,1707936011.758 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2024-02-14T18:40:11.764Z,1707936011.764 [UniversalFixResidualReporter] Loaded 2024-02-14T18:40:11.764Z,1707936011.764 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2024-02-14T18:40:11.764Z,1707936011.764 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2024-02-14T18:40:11.765Z,1707936011.765 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2024-02-14T18:40:11.822Z,1707936011.822 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2024-02-14T18:40:11.822Z,1707936011.822 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2024-02-14T18:40:12.246Z,1707936012.246 [AHRS_M2] Loaded 2024-02-14T18:40:12.246Z,1707936012.246 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2024-02-14T18:40:13.076Z,1707936013.076 [BPC1] Loaded 2024-02-14T18:40:13.076Z,1707936013.076 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2024-02-14T18:40:13.154Z,1707936013.154 [DataOverHttps] Loaded 2024-02-14T18:40:13.154Z,1707936013.154 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2024-02-14T18:40:13.155Z,1707936013.155 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4090F4E0 2024-02-14T18:40:13.155Z,1707936013.155 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1423 2024-02-14T18:40:13.176Z,1707936013.176 [Depth_Keller] Loaded 2024-02-14T18:40:13.176Z,1707936013.176 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2024-02-14T18:40:13.181Z,1707936013.181 [DropWeight] Loaded 2024-02-14T18:40:13.181Z,1707936013.181 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2024-02-14T18:40:13.243Z,1707936013.243 [NAL9602] Loaded 2024-02-14T18:40:13.243Z,1707936013.243 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2024-02-14T18:40:13.273Z,1707936013.273 [Onboard] Loaded 2024-02-14T18:40:13.274Z,1707936013.274 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2024-02-14T18:40:13.274Z,1707936013.274 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4093F4E0 2024-02-14T18:40:13.275Z,1707936013.275 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 1424 2024-02-14T18:40:13.288Z,1707936013.288 [Power24vConverter] Loaded 2024-02-14T18:40:13.289Z,1707936013.289 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2024-02-14T18:40:13.302Z,1707936013.302 [Radio_Surface] Loaded 2024-02-14T18:40:13.302Z,1707936013.302 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2024-02-14T18:40:13.303Z,1707936013.303 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4096F4E0 2024-02-14T18:40:13.303Z,1707936013.303 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1425 2024-02-14T18:40:13.317Z,1707936013.317 [Sonardyne_Nano] Loaded 2024-02-14T18:40:13.317Z,1707936013.317 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread. 2024-02-14T18:40:13.318Z,1707936013.318 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2024-02-14T18:40:13.318Z,1707936013.318 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2024-02-14T18:40:13.369Z,1707936013.369 [DepthRateCalculator] Loaded 2024-02-14T18:40:13.369Z,1707936013.369 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2024-02-14T18:40:13.374Z,1707936013.374 [PitchRateCalculator] Loaded 2024-02-14T18:40:13.375Z,1707936013.375 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2024-02-14T18:40:13.383Z,1707936013.383 [SpeedCalculator] Loaded 2024-02-14T18:40:13.384Z,1707936013.384 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2024-02-14T18:40:13.388Z,1707936013.388 [YawRateCalculator] Loaded 2024-02-14T18:40:13.388Z,1707936013.388 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2024-02-14T18:40:13.407Z,1707936013.407 [ElevatorOffsetCalculator] Loaded 2024-02-14T18:40:13.407Z,1707936013.407 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2024-02-14T18:40:13.408Z,1707936013.408 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2024-02-14T18:40:13.409Z,1707936013.409 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2024-02-14T18:40:13.542Z,1707936013.542 [CANONSampler] Loaded 2024-02-14T18:40:13.542Z,1707936013.542 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread. 2024-02-14T18:40:13.603Z,1707936013.603 [CTD_Seabird] Loaded 2024-02-14T18:40:13.603Z,1707936013.603 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2024-02-14T18:40:13.604Z,1707936013.604 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A2A4E0 2024-02-14T18:40:13.604Z,1707936013.604 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1426 2024-02-14T18:40:13.624Z,1707936013.624 [PAR_Licor] Loaded 2024-02-14T18:40:13.625Z,1707936013.625 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2024-02-14T18:40:13.665Z,1707936013.665 [WetLabsBB2FL] Loaded 2024-02-14T18:40:13.665Z,1707936013.665 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2024-02-14T18:40:13.666Z,1707936013.666 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A5A4E0 2024-02-14T18:40:13.667Z,1707936013.667 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1427 2024-02-14T18:40:13.667Z,1707936013.667 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2024-02-14T18:40:13.668Z,1707936013.668 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2024-02-14T18:40:13.845Z,1707936013.845 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2024-02-14T18:40:13.845Z,1707936013.845 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2024-02-14T18:40:14.584Z,1707936014.584 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2024-02-14T18:40:14.585Z,1707936014.585 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2024-02-14T18:40:14.726Z,1707936014.726 [SBIT](DEBUG): Construct Startup Built In Test. 2024-02-14T18:40:14.735Z,1707936014.735 [SBIT] Loaded 2024-02-14T18:40:14.735Z,1707936014.735 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2024-02-14T18:40:14.739Z,1707936014.739 [IBIT](DEBUG): Construct Initiated Built In Test. 2024-02-14T18:40:14.753Z,1707936014.753 [IBIT] Loaded 2024-02-14T18:40:14.753Z,1707936014.753 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2024-02-14T18:40:14.759Z,1707936014.759 [CBIT](DEBUG): Construct Continuous Built In Test. 2024-02-14T18:40:14.863Z,1707936014.863 [CBIT] Loaded 2024-02-14T18:40:14.864Z,1707936014.864 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2024-02-14T18:40:14.864Z,1707936014.864 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2024-02-14T18:40:14.865Z,1707936014.865 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2024-02-14T18:40:14.977Z,1707936014.977 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2024-02-14T18:40:14.983Z,1707936014.983 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2024-02-14T18:40:14.986Z,1707936014.986 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2024-02-14T18:40:14.997Z,1707936014.997 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2024-02-14T18:40:14.998Z,1707936014.998 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BB14E0 2024-02-14T18:40:14.999Z,1707936014.999 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1428 2024-02-14T18:40:15.003Z,1707936015.003 [Supervisor](INFO): Main Thread ID is 831 2024-02-14T18:40:15.003Z,1707936015.003 [Supervisor](DEBUG): Running supervisor. 2024-02-14T18:40:15.004Z,1707936015.004 [CommandExec ThreadHandler](INFO): Handler Thread ID is 1429 2024-02-14T18:40:15.004Z,1707936015.004 [CommandExec](INFO): Initializing the command executive. 2024-02-14T18:40:15.006Z,1707936015.006 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1430 2024-02-14T18:40:15.009Z,1707936015.009 [controlThread ThreadHandler](INFO): Handler Thread ID is 1431 2024-02-14T18:40:15.010Z,1707936015.010 [controlThread](DEBUG): Initializing ControlThread 2024-02-14T18:40:15.010Z,1707936015.010 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2024-02-14T18:40:15.012Z,1707936015.012 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2024-02-14T18:40:15.013Z,1707936015.013 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2024-02-14T18:40:15.013Z,1707936015.013 [LoopControl](DEBUG): Initialize LoopControlComponent. 2024-02-14T18:40:15.015Z,1707936015.015 [NavChart](DEBUG): Initialize NavChart Navigation. 2024-02-14T18:40:15.016Z,1707936015.016 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2024-02-14T18:40:15.023Z,1707936015.023 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2024-02-14T18:40:15.023Z,1707936015.023 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2024-02-14T18:40:15.023Z,1707936015.023 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2024-02-14T18:40:15.023Z,1707936015.023 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2024-02-14T18:40:15.024Z,1707936015.024 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2024-02-14T18:40:15.029Z,1707936015.029 [SBIT](INFO): Initialize SBIT Component. 2024-02-14T18:40:15.029Z,1707936015.029 [SBIT](IMPORTANT): git: 2024-02-14 2024-02-14T18:40:15.029Z,1707936015.029 [SBIT](INFO): git hash: 8fc4e848ca047b5de9ae8a7c02f55958c6301ab2 2024-02-14T18:40:15.030Z,1707936015.030 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2024-02-14T18:40:15.031Z,1707936015.031 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018 Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021 2024-02-14T18:40:15.032Z,1707936015.032 [SBIT](INFO): Beginning SBIT in 64.000000 seconds. 2024-02-14T18:40:15.033Z,1707936015.033 [IBIT](INFO): Initialize IBIT Component. 2024-02-14T18:40:15.034Z,1707936015.034 [CBIT](DEBUG): Initialize CBIT Component. 2024-02-14T18:40:15.034Z,1707936015.034 [logger ThreadHandler](INFO): Handler Thread ID is 1432 2024-02-14T18:40:15.045Z,1707936015.045 [CBIT](DEBUG): Initialized mux pins. 2024-02-14T18:40:15.045Z,1707936015.045 [CBIT](DEBUG): Initializing the watchdog timer. 2024-02-14T18:40:15.053Z,1707936015.053 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1433 2024-02-14T18:40:15.055Z,1707936015.055 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2024-02-14T18:40:15.065Z,1707936015.065 [Onboard ThreadHandler](INFO): Handler Thread ID is 1434 2024-02-14T18:40:15.069Z,1707936015.069 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2024-02-14T18:40:15.070Z,1707936015.070 [CBIT](DEBUG): Initializing heartbeat. 2024-02-14T18:40:15.086Z,1707936015.086 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1435 2024-02-14T18:40:15.097Z,1707936015.097 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1436 2024-02-14T18:40:15.098Z,1707936015.098 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2024-02-14T18:40:15.102Z,1707936015.102 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1438 2024-02-14T18:40:15.105Z,1707936015.105 [WetLabsBB2FL](INFO): Powering up 2024-02-14T18:40:15.106Z,1707936015.106 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1440 2024-02-14T18:40:15.110Z,1707936015.110 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2024-02-14T18:40:15.110Z,1707936015.110 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2024-02-14T18:40:15.110Z,1707936015.110 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2024-02-14T18:40:15.111Z,1707936015.111 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2024-02-14T18:40:15.111Z,1707936015.111 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2024-02-14T18:40:15.111Z,1707936015.111 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2024-02-14T18:40:15.111Z,1707936015.111 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2024-02-14T18:40:15.111Z,1707936015.111 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2024-02-14T18:40:15.141Z,1707936015.141 [CBIT](DEBUG): Deactivating GF circuits. 2024-02-14T18:40:15.141Z,1707936015.141 [CBIT](DEBUG): Deactivating emergency mode. 2024-02-14T18:40:15.181Z,1707936015.181 [CBIT](DEBUG): Backplane powered. 2024-02-14T18:40:15.182Z,1707936015.182 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl 2024-02-14T18:40:15.182Z,1707936015.182 [MissionManager](IMPORTANT): Loading Compiled TethysL script from file Missions/Startup.tx 2024-02-14T18:40:15.194Z,1707936015.194 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2024-02-14T18:40:15.229Z,1707936015.229 [MissionManager](DEBUG): mission Startup { behavior Guidance:GoToSurface { run in progression } aggregate StartupSatComms { run in sequence readDatum { timeout duration=P1M Universal:latitude_fix } readDatum { timeout duration=P1M Universal:platform_communications } } } 2024-02-14T18:40:15.229Z,1707936015.229 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl 2024-02-14T18:40:15.230Z,1707936015.230 [MissionManager](IMPORTANT): Loading Compiled TethysL script from file Missions/Default.tx 2024-02-14T18:40:15.303Z,1707936015.303 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2024-02-14T18:40:15.305Z,1707936015.305 [Default:A.Wait](DEBUG): Construct Wait. 2024-02-14T18:40:15.307Z,1707936015.307 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2024-02-14T18:40:15.351Z,1707936015.351 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2024-02-14T18:40:15.353Z,1707936015.353 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2024-02-14T18:40:15.375Z,1707936015.375 [Default:E.Execute](DEBUG): Construct Execute. 2024-02-14T18:40:15.378Z,1707936015.378 [MissionManager](DEBUG): mission Default { arguments { ElapsedSinceDefaultStarted = 0 minute } behavior Guidance:Wait { """ Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. """ run in sequence set duration = 13 second } behavior Guidance:GoToSurface { run in progression } aggregate CheckIn { run in sequence repeat=288 readDatum id="Read_GPS" { timeout duration=P5M Universal:time_fix } readDatum id="Read_Iridium" { timeout duration=P4H { behavior Guidance:Execute { run in sequence set command = "Burn on" } syslog critical "Dropped weight due to communications timeout." } Universal:platform_communications } behavior Guidance:Wait { run in sequence set duration = 5 minute } assign in sequence ElapsedSinceDefaultStarted = elapsed ( Universal:mission_started ) syslog important "Default mission has been running for " + ElapsedSinceDefaultStarted~minute } syslog important "Restarting logs and Default mission." behavior Guidance:Execute { run in sequence set command = "restart logs" } } 2024-02-14T18:40:15.385Z,1707936015.385 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,Sonardyne_Nano,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2024-02-14T18:40:15.401Z,1707936015.401 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2024-02-14T18:40:15.483Z,1707936015.483 [Power24vConverter](INFO): Powering up. 2024-02-14T18:40:15.484Z,1707936015.484 [Sonardyne_Nano](INFO): Initializing. 2024-02-14T18:40:15.489Z,1707936015.489 [Radio_Surface](INFO): Powering up 2024-02-14T18:40:15.501Z,1707936015.501 [CANONSampler](INFO): Powering down 2024-02-14T18:40:15.571Z,1707936015.571 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2024-02-14T18:40:15.577Z,1707936015.577 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2024-02-14T18:40:15.578Z,1707936015.578 [ElevatorServo](DEBUG): Initializing EZServoServo. 2024-02-14T18:40:15.585Z,1707936015.585 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2024-02-14T18:40:15.586Z,1707936015.586 [MassServo](DEBUG): Initializing EZServoServo. 2024-02-14T18:40:15.593Z,1707936015.593 [MassServo](DEBUG): Initializing MassServo. 2024-02-14T18:40:15.594Z,1707936015.594 [RudderServo](DEBUG): Initializing EZServoServo. 2024-02-14T18:40:15.609Z,1707936015.609 [RudderServo](DEBUG): Initializing RudderServo. 2024-02-14T18:40:15.610Z,1707936015.610 [ThrusterHE](DEBUG): Initializing EZServoServo. 2024-02-14T18:40:15.617Z,1707936015.617 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2024-02-14T18:40:17.213Z,1707936017.213 [WetLabsBB2FL](INFO): Powering down 2024-02-14T18:40:17.415Z,1707936017.415 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART 2024-02-14T18:40:18.701Z,1707936018.701 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2109 2024-02-14T18:40:21.278Z,1707936021.278 [ThrusterHE](ERROR): Zero Speed Commanded. 2024-02-14T18:40:43.278Z,1707936043.278 [NAL9602](INFO): Powering up NAL9602 2024-02-14T18:40:54.194Z,1707936054.194 [NAL9602](INFO): NAL9602 initialized 2024-02-14T18:41:07.925Z,1707936067.925 [NAL9602](INFO): SBD MO Status=0, MOMSN=46940, MT Status=0, MTMSN=0 2024-02-14T18:41:07.925Z,1707936067.925 [NAL9602](INFO): No messages in MT queue 2024-02-14T18:41:19.666Z,1707936079.666 [SBIT](IMPORTANT): Beginning Startup BIT 2024-02-14T18:41:19.670Z,1707936079.670 [CBIT](IMPORTANT): Beginning ground fault scan 2024-02-14T18:41:20.854Z,1707936080.854 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184119.00,A,3648.14536,N,12147.22873,W,0.486,0.00,140224,,,A*72 2024-02-14T18:41:20.858Z,1707936080.858 [NAL9602](INFO): GPS fix at 20240214T184119: (36.802423, -121.787145) 2024-02-14T18:41:21.659Z,1707936081.659 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-02-14T18:41:30.588Z,1707936090.588 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.002786 CHAN A1 (24V): 0.000681 CHAN A2 (12V): -0.001803 CHAN A3 (5V): -0.001484 CHAN B0 (3.3V): -0.000060 CHAN B1 (3.15aV): -0.000316 CHAN B2 (3.15bV): -0.000588 CHAN B3 (GND): 0.000093 OPEN: -0.000633 Full Scale: +/- 1 mA 2024-02-14T18:41:34.583Z,1707936094.583 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-02-14T18:41:47.511Z,1707936107.511 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-02-14T18:41:53.573Z,1707936113.573 [NAL9602](INFO): Not Powering down - fast GPS 2024-02-14T18:42:00.843Z,1707936120.843 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-02-14T18:42:12.963Z,1707936132.963 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-02-14T18:42:13.799Z,1707936133.799 [SBIT](IMPORTANT): SBIT PASSED 2024-02-14T18:42:13.799Z,1707936133.799 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2024-02-14T18:42:13.800Z,1707936133.800 [SBIT](IMPORTANT): AMEcho.loadAtStartup=0 bool; 2024-02-14T18:42:13.800Z,1707936133.800 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=20 count; 2024-02-14T18:42:13.800Z,1707936133.800 [SBIT](IMPORTANT): CANONSampler.loadAtStartup=1 bool; 2024-02-14T18:42:13.800Z,1707936133.800 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool; 2024-02-14T18:42:13.801Z,1707936133.801 [SBIT](IMPORTANT): Sonardyne_Nano.loadAtStartup=1 bool; 2024-02-14T18:42:13.801Z,1707936133.801 [SBIT](IMPORTANT): ThrusterServo.currLimit=50 percent; 2024-02-14T18:42:13.801Z,1707936133.801 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=215.727710 cubic_centimeter; 2024-02-14T18:42:13.801Z,1707936133.801 [SBIT](IMPORTANT): VerticalControl.massDefault=-11.248903 millimeter; 2024-02-14T18:42:14.213Z,1707936134.213 [MissionManager](IMPORTANT): Started mission Startup 2024-02-14T18:42:14.214Z,1707936134.214 [Startup] Running Loop=1 2024-02-14T18:42:14.214Z,1707936134.214 [Startup](DEBUG): Aggregate::initialize Startup 2024-02-14T18:42:14.214Z,1707936134.214 [Startup:A.GoToSurface] Running Loop=1 2024-02-14T18:42:14.214Z,1707936134.214 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2024-02-14T18:42:14.214Z,1707936134.214 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2024-02-14T18:42:14.215Z,1707936134.215 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2024-02-14T18:42:14.215Z,1707936134.215 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2024-02-14T18:42:14.216Z,1707936134.216 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2024-02-14T18:42:14.216Z,1707936134.216 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2024-02-14T18:42:14.217Z,1707936134.217 [Startup:StartupSatComms] Running Loop=1 2024-02-14T18:42:14.218Z,1707936134.218 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2024-02-14T18:42:14.218Z,1707936134.218 [Startup:StartupSatComms:A] Running Loop=1 2024-02-14T18:42:14.619Z,1707936134.619 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2024-02-14T18:42:16.211Z,1707936136.211 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184214.00,A,3648.14569,N,12147.22893,W,0.019,0.00,140224,,,A*7A 2024-02-14T18:42:16.213Z,1707936136.213 [NAL9602](INFO): GPS fix at 20240214T184214: (36.802428, -121.787149) 2024-02-14T18:42:16.252Z,1707936136.252 [Startup:StartupSatComms:A] Stopped 2024-02-14T18:42:16.252Z,1707936136.252 [Startup:StartupSatComms:B] Running Loop=1 2024-02-14T18:42:16.658Z,1707936136.658 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2024-02-14T18:42:25.935Z,1707936145.935 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-02-14T18:42:38.865Z,1707936158.865 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-02-14T18:42:46.547Z,1707936166.547 [NAL9602](INFO): SBD MO Status=1, MOMSN=46941, MT Status=0, MTMSN=0 2024-02-14T18:42:46.593Z,1707936166.593 [NAL9602](INFO): Sent 39 bytes from file Logs/20240214T173622/Courier0039.lzma 2024-02-14T18:42:46.593Z,1707936166.593 [NAL9602](INFO): Packets left to send: 0 2024-02-14T18:42:59.939Z,1707936179.939 [NAL9602](INFO): SBD MO Status=1, MOMSN=46942, MT Status=0, MTMSN=0 2024-02-14T18:43:00.001Z,1707936180.001 [NAL9602](INFO): Sent 267 bytes from file Logs/20240214T184002/Courier0000.lzma 2024-02-14T18:43:00.001Z,1707936180.001 [NAL9602](INFO): Packets left to send: 0 2024-02-14T18:43:16.563Z,1707936196.563 [Startup:StartupSatComms:B](INFO): Timed out from 2024-02-14T18:42:16.3Z 2024-02-14T18:43:16.563Z,1707936196.563 [Startup:StartupSatComms:B] Stopped 2024-02-14T18:43:16.564Z,1707936196.564 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2024-02-14T18:43:16.564Z,1707936196.564 [Startup:StartupSatComms] Stopped 2024-02-14T18:43:16.564Z,1707936196.564 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2024-02-14T18:43:16.565Z,1707936196.565 [Startup](INFO): Completed Startup 2024-02-14T18:43:16.565Z,1707936196.565 [MissionManager](INFO): Startup is completed. 2024-02-14T18:43:16.565Z,1707936196.565 [MissionManager](INFO): Uninitializing Mission Startup 2024-02-14T18:43:16.565Z,1707936196.565 [Startup] Stopped 2024-02-14T18:43:16.565Z,1707936196.565 [Startup](DEBUG): Aggregate::uninitialize Startup 2024-02-14T18:43:16.565Z,1707936196.565 [Startup:A.GoToSurface] Stopped 2024-02-14T18:43:16.565Z,1707936196.565 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2024-02-14T18:43:16.957Z,1707936196.957 [MissionManager](IMPORTANT): Started mission Default 2024-02-14T18:43:16.957Z,1707936196.957 [Default] Running Loop=1 2024-02-14T18:43:16.957Z,1707936196.957 [Default](DEBUG): Aggregate::initialize Default 2024-02-14T18:43:16.958Z,1707936196.958 [Default:B.GoToSurface] Running Loop=1 2024-02-14T18:43:16.958Z,1707936196.958 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2024-02-14T18:43:16.958Z,1707936196.958 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2024-02-14T18:43:16.958Z,1707936196.958 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2024-02-14T18:43:16.958Z,1707936196.958 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2024-02-14T18:43:16.959Z,1707936196.959 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2024-02-14T18:43:16.959Z,1707936196.959 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2024-02-14T18:43:16.959Z,1707936196.959 [Default:A.Wait] Running Loop=1 2024-02-14T18:43:16.959Z,1707936196.959 [Default:A.Wait](DEBUG): Initialize Wait Component. 2024-02-14T18:43:18.152Z,1707936198.152 [NAL9602](INFO): SBD MO Status=2, MOMSN=46943, MT Status=2, MTMSN=0 2024-02-14T18:43:18.152Z,1707936198.152 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-02-14T18:43:30.295Z,1707936210.295 [Default:A.Wait](INFO): Done Waiting. 2024-02-14T18:43:30.295Z,1707936210.295 [Default:A.Wait] Stopped 2024-02-14T18:43:30.295Z,1707936210.295 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2024-02-14T18:43:30.698Z,1707936210.698 [Default:CheckIn] Running Loop=1 2024-02-14T18:43:30.698Z,1707936210.698 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-02-14T18:43:30.698Z,1707936210.698 [Default:CheckIn:Read_GPS] Running Loop=1 2024-02-14T18:43:31.089Z,1707936211.089 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2024-02-14T18:43:32.722Z,1707936212.722 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184330.00,A,3648.14949,N,12147.22616,W,0.544,27.40,140224,,,A*4C 2024-02-14T18:43:32.724Z,1707936212.724 [NAL9602](INFO): GPS fix at 20240214T184330: (36.802492, -121.787103) 2024-02-14T18:43:32.735Z,1707936212.735 [Default:CheckIn:Read_GPS] Stopped 2024-02-14T18:43:32.735Z,1707936212.735 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-02-14T18:43:33.154Z,1707936213.154 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2024-02-14T18:43:50.359Z,1707936230.359 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004396 2024-02-14T18:43:57.836Z,1707936237.836 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240214T184002/Courier0004.lzma 2024-02-14T18:43:58.838Z,1707936238.838 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Courier0004.lzma.bak 2024-02-14T18:43:58.839Z,1707936238.839 [DataOverHttps](INFO): SBD MOMSN=19278725 2024-02-14T18:44:14.818Z,1707936254.818 [DataOverHttps](INFO): Sending 126 bytes from file Logs/20240214T173622/Express0041.lzma 2024-02-14T18:44:15.819Z,1707936255.819 [DataOverHttps](INFO): Moved sent file to Logs/20240214T173622/Express0041.lzma.bak 2024-02-14T18:44:15.819Z,1707936255.819 [DataOverHttps](INFO): SBD MOMSN=19278730 2024-02-14T18:44:26.895Z,1707936266.895 [NAL9602](INFO): Not Powering down - fast GPS 2024-02-14T18:44:34.654Z,1707936274.654 [DataOverHttps](INFO): Sending 954 bytes from file Logs/20240214T184002/Express0001.lzma 2024-02-14T18:44:35.654Z,1707936275.654 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Express0001.lzma.bak 2024-02-14T18:44:35.654Z,1707936275.654 [DataOverHttps](INFO): SBD MOMSN=19278733 2024-02-14T18:44:54.576Z,1707936294.576 [DataOverHttps](INFO): Sending 104 bytes from file Logs/20240214T184002/Express0005.lzma 2024-02-14T18:44:55.579Z,1707936295.579 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Express0005.lzma.bak 2024-02-14T18:44:55.579Z,1707936295.579 [DataOverHttps](INFO): SBD MOMSN=19278755 2024-02-14T18:44:56.853Z,1707936296.853 [Default:CheckIn:Read_Iridium] Stopped 2024-02-14T18:44:56.853Z,1707936296.853 [Default:CheckIn:C.Wait] Running Loop=1 2024-02-14T18:44:56.853Z,1707936296.853 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-02-14T18:45:19.055Z,1707936319.055 [BPC1](INFO): Calculating totals. Valid battery stick count: 40. Valid reserve battery stick count: 6. 2024-02-14T18:45:19.077Z,1707936319.077 [BPC1](INFO): Received data from all battery sticks. 2024-02-14T18:49:57.432Z,1707936597.432 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-02-14T18:49:57.432Z,1707936597.432 [Default:CheckIn:C.Wait] Stopped 2024-02-14T18:49:57.432Z,1707936597.432 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-02-14T18:49:57.432Z,1707936597.432 [Default:CheckIn:D] Running Loop=1 2024-02-14T18:49:57.836Z,1707936597.836 [Default:CheckIn:D] Stopped 2024-02-14T18:49:57.836Z,1707936597.836 [Default:CheckIn:E] Running Loop=1 2024-02-14T18:49:58.253Z,1707936598.253 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 6.681310 min 2024-02-14T18:49:58.253Z,1707936598.253 [Default:CheckIn:E] Stopped 2024-02-14T18:49:58.253Z,1707936598.253 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-02-14T18:49:58.253Z,1707936598.253 [Default:CheckIn] Stopped 2024-02-14T18:49:58.253Z,1707936598.253 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-02-14T18:49:58.253Z,1707936598.253 [Default:CheckIn](INFO): Running loop #2 2024-02-14T18:49:58.253Z,1707936598.253 [Default:CheckIn] Running Loop=2 2024-02-14T18:49:58.253Z,1707936598.253 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-02-14T18:49:58.254Z,1707936598.254 [Default:CheckIn:Read_GPS] Running Loop=1 2024-02-14T18:50:00.256Z,1707936600.256 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184959.00,A,3648.15082,N,12147.22216,W,0.019,32.15,140224,,,A*4B 2024-02-14T18:50:00.259Z,1707936600.259 [NAL9602](INFO): GPS fix at 20240214T184959: (36.802514, -121.787036) 2024-02-14T18:50:00.294Z,1707936600.294 [Default:CheckIn:Read_GPS] Stopped 2024-02-14T18:50:00.294Z,1707936600.294 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-02-14T18:50:07.544Z,1707936607.544 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20240214T184002/Courier0007.lzma 2024-02-14T18:50:08.546Z,1707936608.546 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Courier0007.lzma.bak 2024-02-14T18:50:08.546Z,1707936608.546 [DataOverHttps](INFO): SBD MOMSN=19278776 2024-02-14T18:50:16.410Z,1707936616.410 [Power24vConverter](INFO): Powering down. 2024-02-14T18:50:27.337Z,1707936627.337 [DataOverHttps](INFO): Sending 160 bytes from file Logs/20240214T184002/Express0008.lzma 2024-02-14T18:50:28.340Z,1707936628.340 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Express0008.lzma.bak 2024-02-14T18:50:28.341Z,1707936628.341 [DataOverHttps](INFO): SBD MOMSN=19278779 2024-02-14T18:50:29.407Z,1707936629.407 [Default:CheckIn:Read_Iridium] Stopped 2024-02-14T18:50:29.407Z,1707936629.407 [Default:CheckIn:C.Wait] Running Loop=1 2024-02-14T18:50:29.407Z,1707936629.407 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-02-14T18:50:57.283Z,1707936657.283 [NAL9602](INFO): SBD MO Status=2, MOMSN=46943, MT Status=2, MTMSN=0 2024-02-14T18:50:57.283Z,1707936657.283 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-02-14T18:51:38.087Z,1707936698.087 [NAL9602](INFO): SBD MO Status=2, MOMSN=46943, MT Status=2, MTMSN=0 2024-02-14T18:51:38.087Z,1707936698.087 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-02-14T18:54:56.463Z,1707936896.463 [NAL9602](INFO): SBD MO Status=2, MOMSN=46943, MT Status=2, MTMSN=0 2024-02-14T18:54:56.463Z,1707936896.463 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-02-14T18:55:02.512Z,1707936902.512 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2024-02-14T18:55:30.011Z,1707936930.011 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-02-14T18:55:30.011Z,1707936930.011 [Default:CheckIn:C.Wait] Stopped 2024-02-14T18:55:30.011Z,1707936930.011 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-02-14T18:55:30.011Z,1707936930.011 [Default:CheckIn:D] Running Loop=1 2024-02-14T18:55:30.408Z,1707936930.408 [Default:CheckIn:D] Stopped 2024-02-14T18:55:30.408Z,1707936930.408 [Default:CheckIn:E] Running Loop=1 2024-02-14T18:55:30.808Z,1707936930.808 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.224177 min 2024-02-14T18:55:30.808Z,1707936930.808 [Default:CheckIn:E] Stopped 2024-02-14T18:55:30.808Z,1707936930.808 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-02-14T18:55:30.808Z,1707936930.808 [Default:CheckIn] Stopped 2024-02-14T18:55:30.808Z,1707936930.808 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-02-14T18:55:30.808Z,1707936930.808 [Default:CheckIn](INFO): Running loop #3 2024-02-14T18:55:30.809Z,1707936930.809 [Default:CheckIn] Running Loop=3 2024-02-14T18:55:30.809Z,1707936930.809 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-02-14T18:55:30.809Z,1707936930.809 [Default:CheckIn:Read_GPS] Running Loop=1 2024-02-14T18:55:32.825Z,1707936932.825 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185532.00,A,3648.15143,N,12147.22140,W,0.039,32.15,140224,,,D*40 2024-02-14T18:55:32.827Z,1707936932.827 [NAL9602](INFO): GPS fix at 20240214T185532: (36.802524, -121.787023) 2024-02-14T18:55:32.838Z,1707936932.838 [Default:CheckIn:Read_GPS] Stopped 2024-02-14T18:55:32.838Z,1707936932.838 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-02-14T18:55:40.385Z,1707936940.385 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240214T184002/Courier0010.lzma 2024-02-14T18:55:41.386Z,1707936941.386 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Courier0010.lzma.bak 2024-02-14T18:55:41.386Z,1707936941.386 [DataOverHttps](INFO): SBD MOMSN=19278791 2024-02-14T18:55:57.117Z,1707936957.117 [DataOverHttps](INFO): Sending 232 bytes from file Logs/20240214T184002/Express0011.lzma 2024-02-14T18:55:58.118Z,1707936958.118 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Express0011.lzma.bak 2024-02-14T18:55:58.119Z,1707936958.119 [DataOverHttps](INFO): SBD MOMSN=19278794 2024-02-14T18:55:59.491Z,1707936959.491 [Default:CheckIn:Read_Iridium] Stopped 2024-02-14T18:55:59.491Z,1707936959.491 [Default:CheckIn:C.Wait] Running Loop=1 2024-02-14T18:55:59.491Z,1707936959.491 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-02-14T18:56:05.542Z,1707936965.542 [NAL9602](INFO): Not Powering down - fast GPS 2024-02-14T19:01:00.075Z,1707937260.075 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-02-14T19:01:00.075Z,1707937260.075 [Default:CheckIn:C.Wait] Stopped 2024-02-14T19:01:00.075Z,1707937260.075 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-02-14T19:01:00.075Z,1707937260.075 [Default:CheckIn:D] Running Loop=1 2024-02-14T19:01:00.477Z,1707937260.477 [Default:CheckIn:D] Stopped 2024-02-14T19:01:00.477Z,1707937260.477 [Default:CheckIn:E] Running Loop=1 2024-02-14T19:01:00.876Z,1707937260.876 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 17.725317 min 2024-02-14T19:01:00.876Z,1707937260.876 [Default:CheckIn:E] Stopped 2024-02-14T19:01:00.876Z,1707937260.876 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-02-14T19:01:00.876Z,1707937260.876 [Default:CheckIn] Stopped 2024-02-14T19:01:00.885Z,1707937260.885 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-02-14T19:01:00.885Z,1707937260.885 [Default:CheckIn](INFO): Running loop #4 2024-02-14T19:01:00.885Z,1707937260.885 [Default:CheckIn] Running Loop=4 2024-02-14T19:01:00.885Z,1707937260.885 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-02-14T19:01:00.886Z,1707937260.886 [Default:CheckIn:Read_GPS] Running Loop=1 2024-02-14T19:01:02.888Z,1707937262.888 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190102.00,A,3648.15102,N,12147.22163,W,0.078,32.15,140224,,,D*42 2024-02-14T19:01:02.890Z,1707937262.890 [NAL9602](INFO): GPS fix at 20240214T190102: (36.802517, -121.787027) 2024-02-14T19:01:02.901Z,1707937262.901 [Default:CheckIn:Read_GPS] Stopped 2024-02-14T19:01:02.901Z,1707937262.901 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-02-14T19:01:10.372Z,1707937270.372 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240214T184002/Courier0013.lzma 2024-02-14T19:01:11.374Z,1707937271.374 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Courier0013.lzma.bak 2024-02-14T19:01:11.374Z,1707937271.374 [DataOverHttps](INFO): SBD MOMSN=19278817 2024-02-14T19:01:27.460Z,1707937287.460 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20240214T184002/Express0014.lzma 2024-02-14T19:01:28.463Z,1707937288.463 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Express0014.lzma.bak 2024-02-14T19:01:28.463Z,1707937288.463 [DataOverHttps](INFO): SBD MOMSN=19278820 2024-02-14T19:01:29.564Z,1707937289.564 [Default:CheckIn:Read_Iridium] Stopped 2024-02-14T19:01:29.564Z,1707937289.564 [Default:CheckIn:C.Wait] Running Loop=1 2024-02-14T19:01:29.564Z,1707937289.564 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-02-14T19:01:33.595Z,1707937293.595 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2024-02-14T19:01:33.669Z,1707937293.669 [NAL9602](ERROR): received: +CSQ:1 OK943, 2, 0, 0, 0 OK 2024-02-14T19:04:02.670Z,1707937442.670 [NAL9602](INFO): SBD MO Status=1, MOMSN=46943, MT Status=0, MTMSN=0 2024-02-14T19:04:02.670Z,1707937442.670 [NAL9602](INFO): No messages in MT queue 2024-02-14T19:04:33.379Z,1707937473.379 [NAL9602](INFO): Not Powering down - fast GPS 2024-02-14T19:06:30.143Z,1707937590.143 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-02-14T19:06:30.144Z,1707937590.144 [Default:CheckIn:C.Wait] Stopped 2024-02-14T19:06:30.144Z,1707937590.144 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-02-14T19:06:30.144Z,1707937590.144 [Default:CheckIn:D] Running Loop=1 2024-02-14T19:06:30.549Z,1707937590.549 [Default:CheckIn:D] Stopped 2024-02-14T19:06:30.549Z,1707937590.549 [Default:CheckIn:E] Running Loop=1 2024-02-14T19:06:30.960Z,1707937590.960 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 23.226522 min 2024-02-14T19:06:30.960Z,1707937590.960 [Default:CheckIn:E] Stopped 2024-02-14T19:06:30.960Z,1707937590.960 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-02-14T19:06:30.960Z,1707937590.960 [Default:CheckIn] Stopped 2024-02-14T19:06:30.960Z,1707937590.960 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-02-14T19:06:30.960Z,1707937590.960 [Default:CheckIn](INFO): Running loop #5 2024-02-14T19:06:30.960Z,1707937590.960 [Default:CheckIn] Running Loop=5 2024-02-14T19:06:30.960Z,1707937590.960 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-02-14T19:06:30.960Z,1707937590.960 [Default:CheckIn:Read_GPS] Running Loop=1 2024-02-14T19:06:32.964Z,1707937592.964 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190632.00,A,3648.15037,N,12147.22272,W,0.019,147.55,140224,,,A*77 2024-02-14T19:06:32.966Z,1707937592.966 [NAL9602](INFO): GPS fix at 20240214T190632: (36.802506, -121.787045) 2024-02-14T19:06:32.995Z,1707937592.995 [Default:CheckIn:Read_GPS] Stopped 2024-02-14T19:06:32.995Z,1707937592.995 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-02-14T19:06:40.392Z,1707937600.392 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240214T184002/Courier0016.lzma 2024-02-14T19:06:41.395Z,1707937601.395 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Courier0016.lzma.bak 2024-02-14T19:06:41.395Z,1707937601.395 [DataOverHttps](INFO): SBD MOMSN=19278840 2024-02-14T19:06:53.162Z,1707937613.162 [NAL9602](INFO): SBD MO Status=1, MOMSN=46944, MT Status=0, MTMSN=0 2024-02-14T19:06:53.162Z,1707937613.162 [NAL9602](INFO): No messages in MT queue 2024-02-14T19:07:00.412Z,1707937620.412 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20240214T184002/Express0017.lzma 2024-02-14T19:07:01.418Z,1707937621.418 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Express0017.lzma.bak 2024-02-14T19:07:01.419Z,1707937621.419 [DataOverHttps](INFO): SBD MOMSN=19278843 2024-02-14T19:07:02.500Z,1707937622.500 [Default:CheckIn:Read_Iridium] Stopped 2024-02-14T19:07:02.500Z,1707937622.500 [Default:CheckIn:C.Wait] Running Loop=1 2024-02-14T19:07:02.500Z,1707937622.500 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-02-14T19:07:23.894Z,1707937643.894 [NAL9602](INFO): Not Powering down - fast GPS 2024-02-14T19:12:03.071Z,1707937923.071 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-02-14T19:12:03.071Z,1707937923.071 [Default:CheckIn:C.Wait] Stopped 2024-02-14T19:12:03.071Z,1707937923.071 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-02-14T19:12:03.071Z,1707937923.071 [Default:CheckIn:D] Running Loop=1 2024-02-14T19:12:03.475Z,1707937923.475 [Default:CheckIn:D] Stopped 2024-02-14T19:12:03.475Z,1707937923.475 [Default:CheckIn:E] Running Loop=1 2024-02-14T19:12:03.880Z,1707937923.880 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 28.775297 min 2024-02-14T19:12:03.880Z,1707937923.880 [Default:CheckIn:E] Stopped 2024-02-14T19:12:03.880Z,1707937923.880 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-02-14T19:12:03.881Z,1707937923.881 [Default:CheckIn] Stopped 2024-02-14T19:12:03.881Z,1707937923.881 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-02-14T19:12:03.881Z,1707937923.881 [Default:CheckIn](INFO): Running loop #6 2024-02-14T19:12:03.881Z,1707937923.881 [Default:CheckIn] Running Loop=6 2024-02-14T19:12:03.881Z,1707937923.881 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-02-14T19:12:03.881Z,1707937923.881 [Default:CheckIn:Read_GPS] Running Loop=1 2024-02-14T19:12:05.895Z,1707937925.895 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191205.00,A,3648.40723,N,12147.11600,W,4.957,2.90,140224,,,D*7E 2024-02-14T19:12:05.898Z,1707937925.898 [NAL9602](INFO): GPS fix at 20240214T191205: (36.806787, -121.785267) 2024-02-14T19:12:05.909Z,1707937925.909 [Default:CheckIn:Read_GPS] Stopped 2024-02-14T19:12:05.909Z,1707937925.909 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-02-14T19:12:13.124Z,1707937933.124 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240214T184002/Courier0019.lzma 2024-02-14T19:12:14.127Z,1707937934.127 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Courier0019.lzma.bak 2024-02-14T19:12:14.127Z,1707937934.127 [DataOverHttps](INFO): SBD MOMSN=19278862 2024-02-14T19:12:33.296Z,1707937953.296 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20240214T184002/Express0020.lzma 2024-02-14T19:12:34.298Z,1707937954.298 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Express0020.lzma.bak 2024-02-14T19:12:34.299Z,1707937954.299 [DataOverHttps](INFO): SBD MOMSN=19278865 2024-02-14T19:12:35.440Z,1707937955.440 [Default:CheckIn:Read_Iridium] Stopped 2024-02-14T19:12:35.440Z,1707937955.440 [Default:CheckIn:C.Wait] Running Loop=1 2024-02-14T19:12:35.440Z,1707937955.440 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-02-14T19:12:57.651Z,1707937977.651 [NAL9602](INFO): SBD MO Status=2, MOMSN=46945, MT Status=2, MTMSN=0 2024-02-14T19:12:57.651Z,1707937977.651 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-02-14T19:13:16.644Z,1707937996.644 [NAL9602](INFO): SBD MO Status=1, MOMSN=46945, MT Status=0, MTMSN=0 2024-02-14T19:13:16.644Z,1707937996.644 [NAL9602](INFO): No messages in MT queue 2024-02-14T19:13:47.345Z,1707938027.345 [NAL9602](INFO): Not Powering down - fast GPS 2024-02-14T19:17:36.032Z,1707938256.032 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-02-14T19:17:36.032Z,1707938256.032 [Default:CheckIn:C.Wait] Stopped 2024-02-14T19:17:36.032Z,1707938256.032 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-02-14T19:17:36.032Z,1707938256.032 [Default:CheckIn:D] Running Loop=1 2024-02-14T19:17:36.428Z,1707938256.428 [Default:CheckIn:D] Stopped 2024-02-14T19:17:36.428Z,1707938256.428 [Default:CheckIn:E] Running Loop=1 2024-02-14T19:17:36.838Z,1707938256.838 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 34.324504 min 2024-02-14T19:17:36.838Z,1707938256.838 [Default:CheckIn:E] Stopped 2024-02-14T19:17:36.838Z,1707938256.838 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-02-14T19:17:36.838Z,1707938256.838 [Default:CheckIn] Stopped 2024-02-14T19:17:36.839Z,1707938256.839 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-02-14T19:17:36.839Z,1707938256.839 [Default:CheckIn](INFO): Running loop #7 2024-02-14T19:17:36.839Z,1707938256.839 [Default:CheckIn] Running Loop=7 2024-02-14T19:17:36.839Z,1707938256.839 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-02-14T19:17:36.839Z,1707938256.839 [Default:CheckIn:Read_GPS] Running Loop=1 2024-02-14T19:17:38.844Z,1707938258.843 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191738.00,A,3648.34424,N,12147.85119,W,17.708,293.62,140224,,,D*41 2024-02-14T19:17:38.855Z,1707938258.855 [NAL9602](INFO): GPS fix at 20240214T191738: (36.805737, -121.797520) 2024-02-14T19:17:38.866Z,1707938258.866 [Default:CheckIn:Read_GPS] Stopped 2024-02-14T19:17:38.866Z,1707938258.866 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-02-14T19:17:46.252Z,1707938266.252 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240214T184002/Courier0022.lzma 2024-02-14T19:17:47.254Z,1707938267.254 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Courier0022.lzma.bak 2024-02-14T19:17:47.254Z,1707938267.254 [DataOverHttps](INFO): SBD MOMSN=19278884 2024-02-14T19:18:02.674Z,1707938282.674 [NAL9602](INFO): SBD MO Status=1, MOMSN=46946, MT Status=0, MTMSN=0 2024-02-14T19:18:02.674Z,1707938282.674 [NAL9602](INFO): No messages in MT queue 2024-02-14T19:18:03.080Z,1707938283.080 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20240214T184002/Express0023.lzma 2024-02-14T19:18:04.082Z,1707938284.082 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Express0023.lzma.bak 2024-02-14T19:18:04.083Z,1707938284.083 [DataOverHttps](INFO): SBD MOMSN=19278887 2024-02-14T19:18:05.138Z,1707938285.138 [Default:CheckIn:Read_Iridium] Stopped 2024-02-14T19:18:05.138Z,1707938285.138 [Default:CheckIn:C.Wait] Running Loop=1 2024-02-14T19:18:05.138Z,1707938285.138 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-02-14T19:18:33.382Z,1707938313.382 [NAL9602](INFO): Not Powering down - fast GPS 2024-02-14T19:23:05.684Z,1707938585.684 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-02-14T19:23:05.684Z,1707938585.684 [Default:CheckIn:C.Wait] Stopped 2024-02-14T19:23:05.684Z,1707938585.684 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-02-14T19:23:05.684Z,1707938585.684 [Default:CheckIn:D] Running Loop=1 2024-02-14T19:23:06.093Z,1707938586.093 [Default:CheckIn:D] Stopped 2024-02-14T19:23:06.094Z,1707938586.094 [Default:CheckIn:E] Running Loop=1 2024-02-14T19:23:06.494Z,1707938586.494 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.818933 min 2024-02-14T19:23:06.494Z,1707938586.494 [Default:CheckIn:E] Stopped 2024-02-14T19:23:06.494Z,1707938586.494 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-02-14T19:23:06.494Z,1707938586.494 [Default:CheckIn] Stopped 2024-02-14T19:23:06.494Z,1707938586.494 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-02-14T19:23:06.495Z,1707938586.495 [Default:CheckIn](INFO): Running loop #8 2024-02-14T19:23:06.495Z,1707938586.495 [Default:CheckIn] Running Loop=8 2024-02-14T19:23:06.495Z,1707938586.495 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-02-14T19:23:06.495Z,1707938586.495 [Default:CheckIn:Read_GPS] Running Loop=1 2024-02-14T19:23:08.509Z,1707938588.509 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192307.00,A,3647.97215,N,12150.20597,W,22.238,252.38,140224,,,A*44 2024-02-14T19:23:08.511Z,1707938588.511 [NAL9602](INFO): GPS fix at 20240214T192307: (36.799536, -121.836766) 2024-02-14T19:23:08.522Z,1707938588.522 [Default:CheckIn:Read_GPS] Stopped 2024-02-14T19:23:08.522Z,1707938588.522 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-02-14T19:23:16.341Z,1707938596.341 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20240214T184002/Courier0025.lzma 2024-02-14T19:23:17.342Z,1707938597.342 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Courier0025.lzma.bak 2024-02-14T19:23:17.343Z,1707938597.343 [DataOverHttps](INFO): SBD MOMSN=19278906 2024-02-14T19:23:21.835Z,1707938601.835 [NAL9602](INFO): SBD MO Status=1, MOMSN=46947, MT Status=0, MTMSN=0 2024-02-14T19:23:21.835Z,1707938601.835 [NAL9602](INFO): No messages in MT queue 2024-02-14T19:23:33.084Z,1707938613.084 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20240214T184002/Express0026.lzma 2024-02-14T19:23:34.086Z,1707938614.086 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Express0026.lzma.bak 2024-02-14T19:23:34.087Z,1707938614.087 [DataOverHttps](INFO): SBD MOMSN=19278909 2024-02-14T19:23:35.182Z,1707938615.182 [Default:CheckIn:Read_Iridium] Stopped 2024-02-14T19:23:35.182Z,1707938615.182 [Default:CheckIn:C.Wait] Running Loop=1 2024-02-14T19:23:35.182Z,1707938615.182 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-02-14T19:23:52.545Z,1707938632.545 [NAL9602](INFO): Not Powering down - fast GPS 2024-02-14T19:28:35.792Z,1707938915.792 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-02-14T19:28:35.792Z,1707938915.792 [Default:CheckIn:C.Wait] Stopped 2024-02-14T19:28:35.792Z,1707938915.792 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-02-14T19:28:35.792Z,1707938915.792 [Default:CheckIn:D] Running Loop=1 2024-02-14T19:28:36.196Z,1707938916.196 [Default:CheckIn:D] Stopped 2024-02-14T19:28:36.196Z,1707938916.196 [Default:CheckIn:E] Running Loop=1 2024-02-14T19:28:36.604Z,1707938916.604 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.320638 min 2024-02-14T19:28:36.604Z,1707938916.604 [Default:CheckIn:E] Stopped 2024-02-14T19:28:36.604Z,1707938916.604 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-02-14T19:28:36.604Z,1707938916.604 [Default:CheckIn] Stopped 2024-02-14T19:28:36.605Z,1707938916.605 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-02-14T19:28:36.605Z,1707938916.605 [Default:CheckIn](INFO): Running loop #9 2024-02-14T19:28:36.605Z,1707938916.605 [Default:CheckIn] Running Loop=9 2024-02-14T19:28:36.605Z,1707938916.605 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-02-14T19:28:36.605Z,1707938916.605 [Default:CheckIn:Read_GPS] Running Loop=1 2024-02-14T19:28:38.612Z,1707938918.612 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192837.00,A,3647.89076,N,12150.76652,W,1.749,312.48,140224,,,D*78 2024-02-14T19:28:38.623Z,1707938918.623 [NAL9602](INFO): GPS fix at 20240214T192837: (36.798179, -121.846109) 2024-02-14T19:28:38.634Z,1707938918.634 [Default:CheckIn:Read_GPS] Stopped 2024-02-14T19:28:38.635Z,1707938918.635 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-02-14T19:28:46.292Z,1707938926.292 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240214T184002/Courier0028.lzma 2024-02-14T19:28:47.295Z,1707938927.295 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Courier0028.lzma.bak 2024-02-14T19:28:47.295Z,1707938927.295 [DataOverHttps](INFO): SBD MOMSN=19278928 2024-02-14T19:28:59.675Z,1707938939.675 [NAL9602](INFO): SBD MO Status=1, MOMSN=46948, MT Status=0, MTMSN=0 2024-02-14T19:28:59.675Z,1707938939.675 [NAL9602](INFO): No messages in MT queue 2024-02-14T19:29:06.148Z,1707938946.148 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20240214T184002/Express0029.lzma 2024-02-14T19:29:07.152Z,1707938947.152 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Express0029.lzma.bak 2024-02-14T19:29:07.152Z,1707938947.152 [DataOverHttps](INFO): SBD MOMSN=19278931 2024-02-14T19:29:08.188Z,1707938948.188 [Default:CheckIn:Read_Iridium] Stopped 2024-02-14T19:29:08.188Z,1707938948.188 [Default:CheckIn:C.Wait] Running Loop=1 2024-02-14T19:29:08.188Z,1707938948.188 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-02-14T19:29:30.381Z,1707938970.381 [NAL9602](INFO): Not Powering down - fast GPS 2024-02-14T19:34:08.824Z,1707939248.824 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-02-14T19:34:08.824Z,1707939248.824 [Default:CheckIn:C.Wait] Stopped 2024-02-14T19:34:08.824Z,1707939248.824 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-02-14T19:34:08.824Z,1707939248.824 [Default:CheckIn:D] Running Loop=1 2024-02-14T19:34:09.234Z,1707939249.234 [Default:CheckIn:D] Stopped 2024-02-14T19:34:09.234Z,1707939249.234 [Default:CheckIn:E] Running Loop=1 2024-02-14T19:34:09.650Z,1707939249.650 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 50.871273 min 2024-02-14T19:34:09.650Z,1707939249.650 [Default:CheckIn:E] Stopped 2024-02-14T19:34:09.650Z,1707939249.650 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-02-14T19:34:09.650Z,1707939249.650 [Default:CheckIn] Stopped 2024-02-14T19:34:09.650Z,1707939249.650 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-02-14T19:34:09.650Z,1707939249.650 [Default:CheckIn](INFO): Running loop #10 2024-02-14T19:34:09.650Z,1707939249.650 [Default:CheckIn] Running Loop=10 2024-02-14T19:34:09.651Z,1707939249.651 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-02-14T19:34:09.651Z,1707939249.651 [Default:CheckIn:Read_GPS] Running Loop=1 2024-02-14T19:34:11.647Z,1707939251.647 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193410.00,A,3647.94002,N,12150.88163,W,0.467,218.72,140224,,,D*77 2024-02-14T19:34:11.650Z,1707939251.650 [NAL9602](INFO): GPS fix at 20240214T193410: (36.799000, -121.848027) 2024-02-14T19:34:11.660Z,1707939251.660 [Default:CheckIn:Read_GPS] Stopped 2024-02-14T19:34:11.688Z,1707939251.688 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-02-14T19:34:27.807Z,1707939267.807 [NAL9602](INFO): SBD MO Status=1, MOMSN=46949, MT Status=0, MTMSN=0 2024-02-14T19:34:27.807Z,1707939267.807 [NAL9602](INFO): No messages in MT queue 2024-02-14T19:34:57.449Z,1707939297.449 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240214T184002/Courier0031.lzma 2024-02-14T19:34:58.451Z,1707939298.451 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Courier0031.lzma.bak 2024-02-14T19:34:58.451Z,1707939298.451 [DataOverHttps](INFO): SBD MOMSN=19278974 2024-02-14T19:34:58.562Z,1707939298.562 [NAL9602](INFO): Not Powering down - fast GPS 2024-02-14T19:35:43.521Z,1707939343.521 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20240214T184002/Express0032.lzma 2024-02-14T19:35:44.522Z,1707939344.522 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Express0032.lzma.bak 2024-02-14T19:35:44.523Z,1707939344.523 [DataOverHttps](INFO): SBD MOMSN=19278979 2024-02-14T19:35:45.845Z,1707939345.845 [Default:CheckIn:Read_Iridium] Stopped 2024-02-14T19:35:45.845Z,1707939345.845 [Default:CheckIn:C.Wait] Running Loop=1 2024-02-14T19:35:45.845Z,1707939345.845 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-02-14T19:40:46.570Z,1707939646.570 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-02-14T19:40:46.570Z,1707939646.570 [Default:CheckIn:C.Wait] Stopped 2024-02-14T19:40:46.570Z,1707939646.570 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-02-14T19:40:46.570Z,1707939646.570 [Default:CheckIn:D] Running Loop=1 2024-02-14T19:40:46.994Z,1707939646.994 [Default:CheckIn:D] Stopped 2024-02-14T19:40:46.994Z,1707939646.994 [Default:CheckIn:E] Running Loop=1 2024-02-14T19:40:47.371Z,1707939647.371 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 57.500606 min 2024-02-14T19:40:47.371Z,1707939647.371 [Default:CheckIn:E] Stopped 2024-02-14T19:40:47.371Z,1707939647.371 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-02-14T19:40:47.371Z,1707939647.371 [Default:CheckIn] Stopped 2024-02-14T19:40:47.371Z,1707939647.371 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-02-14T19:40:47.372Z,1707939647.372 [Default:CheckIn](INFO): Running loop #11 2024-02-14T19:40:47.372Z,1707939647.372 [Default:CheckIn] Running Loop=11 2024-02-14T19:40:47.372Z,1707939647.372 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-02-14T19:40:47.372Z,1707939647.372 [Default:CheckIn:Read_GPS] Running Loop=1 2024-02-14T19:40:49.384Z,1707939649.384 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194048.00,A,3647.97184,N,12150.98770,W,0.214,255.13,140224,,,A*79 2024-02-14T19:40:49.386Z,1707939649.386 [NAL9602](INFO): GPS fix at 20240214T194048: (36.799531, -121.849795) 2024-02-14T19:40:49.396Z,1707939649.396 [Default:CheckIn:Read_GPS] Stopped 2024-02-14T19:40:49.397Z,1707939649.397 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-02-14T19:40:52.961Z,1707939652.961 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T19:40:59.482Z,1707939659.482 [NAL9602](INFO): SBD MO Status=1, MOMSN=46950, MT Status=0, MTMSN=0 2024-02-14T19:40:59.482Z,1707939659.482 [NAL9602](INFO): No messages in MT queue 2024-02-14T19:41:24.085Z,1707939684.085 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T19:41:30.191Z,1707939690.191 [NAL9602](INFO): Not Powering down - fast GPS 2024-02-14T19:41:55.213Z,1707939715.213 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T19:42:26.337Z,1707939746.337 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T19:42:32.361Z,1707939752.361 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.735382 2024-02-14T19:42:46.587Z,1707939766.587 [NAL9602](INFO): SBD MO Status=1, MOMSN=46951, MT Status=0, MTMSN=0 2024-02-14T19:42:46.637Z,1707939766.637 [NAL9602](INFO): Sent 72 bytes from file Logs/20240214T184002/Courier0034.lzma 2024-02-14T19:42:46.637Z,1707939766.637 [NAL9602](INFO): Packets left to send: 0 2024-02-14T19:42:57.543Z,1707939777.543 [NAL9602](INFO): SBD MO Status=1, MOMSN=46952, MT Status=0, MTMSN=0 2024-02-14T19:42:57.593Z,1707939777.593 [NAL9602](INFO): Sent 141 bytes from file Logs/20240214T184002/Express0035.lzma 2024-02-14T19:42:57.593Z,1707939777.593 [NAL9602](INFO): Packets left to send: 0 2024-02-14T19:43:03.485Z,1707939783.485 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T19:43:07.243Z,1707939787.243 [NAL9602](INFO): SBD MO Status=0, MOMSN=46953, MT Status=0, MTMSN=0 2024-02-14T19:43:07.317Z,1707939787.317 [Default:CheckIn:Read_Iridium] Stopped 2024-02-14T19:43:07.317Z,1707939787.317 [Default:CheckIn:C.Wait] Running Loop=1 2024-02-14T19:43:07.317Z,1707939787.317 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-02-14T19:43:34.609Z,1707939814.609 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T19:43:37.936Z,1707939817.936 [NAL9602](INFO): Not Powering down - fast GPS 2024-02-14T19:44:05.733Z,1707939845.733 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T19:44:36.857Z,1707939876.857 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T19:45:08.005Z,1707939908.005 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T19:45:39.129Z,1707939939.129 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T19:46:10.273Z,1707939970.273 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T19:46:25.619Z,1707939985.619 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-02-14T19:46:38.549Z,1707939998.549 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-02-14T19:46:41.397Z,1707940001.397 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T19:46:51.486Z,1707940011.486 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-02-14T19:47:04.807Z,1707940024.807 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-02-14T19:47:12.521Z,1707940032.521 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T19:47:17.735Z,1707940037.735 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-02-14T19:47:30.259Z,1707940050.259 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-02-14T19:47:42.785Z,1707940062.785 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-02-14T19:47:43.645Z,1707940063.645 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T19:48:07.846Z,1707940087.846 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-02-14T19:48:07.846Z,1707940087.846 [Default:CheckIn:C.Wait] Stopped 2024-02-14T19:48:07.846Z,1707940087.846 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-02-14T19:48:07.847Z,1707940087.847 [Default:CheckIn:D] Running Loop=1 2024-02-14T19:48:08.261Z,1707940088.261 [Default:CheckIn:D] Stopped 2024-02-14T19:48:08.261Z,1707940088.261 [Default:CheckIn:E] Running Loop=1 2024-02-14T19:48:08.672Z,1707940088.672 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 64.855050 min 2024-02-14T19:48:08.672Z,1707940088.672 [Default:CheckIn:E] Stopped 2024-02-14T19:48:08.673Z,1707940088.673 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-02-14T19:48:08.673Z,1707940088.673 [Default:CheckIn] Stopped 2024-02-14T19:48:08.673Z,1707940088.673 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-02-14T19:48:08.673Z,1707940088.673 [Default:CheckIn](INFO): Running loop #12 2024-02-14T19:48:08.673Z,1707940088.673 [Default:CheckIn] Running Loop=12 2024-02-14T19:48:08.673Z,1707940088.673 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-02-14T19:48:08.673Z,1707940088.673 [Default:CheckIn:Read_GPS] Running Loop=1 2024-02-14T19:48:10.680Z,1707940090.680 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194809.00,A,3648.07273,N,12151.20918,W,3.596,306.95,140224,,,A*7C 2024-02-14T19:48:10.682Z,1707940090.682 [NAL9602](INFO): GPS fix at 20240214T194809: (36.801212, -121.853486) 2024-02-14T19:48:10.713Z,1707940090.713 [Default:CheckIn:Read_GPS] Stopped 2024-02-14T19:48:10.713Z,1707940090.713 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-02-14T19:48:14.769Z,1707940094.769 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T19:48:26.467Z,1707940106.467 [NAL9602](INFO): SBD MO Status=1, MOMSN=46954, MT Status=0, MTMSN=0 2024-02-14T19:48:26.521Z,1707940106.521 [NAL9602](INFO): Sent 72 bytes from file Logs/20240214T184002/Courier0037.lzma 2024-02-14T19:48:26.521Z,1707940106.521 [NAL9602](INFO): Packets left to send: 0 2024-02-14T19:48:34.199Z,1707940114.199 [NAL9602](INFO): SBD MO Status=1, MOMSN=46955, MT Status=0, MTMSN=0 2024-02-14T19:48:34.257Z,1707940114.257 [NAL9602](INFO): Sent 143 bytes from file Logs/20240214T184002/Express0038.lzma 2024-02-14T19:48:34.257Z,1707940114.257 [NAL9602](INFO): Packets left to send: 0 2024-02-14T19:48:41.871Z,1707940121.871 [NAL9602](INFO): SBD MO Status=0, MOMSN=46956, MT Status=0, MTMSN=0 2024-02-14T19:48:41.965Z,1707940121.965 [Default:CheckIn:Read_Iridium] Stopped 2024-02-14T19:48:41.965Z,1707940121.965 [Default:CheckIn:C.Wait] Running Loop=1 2024-02-14T19:48:41.965Z,1707940121.965 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-02-14T19:48:45.905Z,1707940125.905 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T19:49:12.578Z,1707940152.578 [NAL9602](INFO): Not Powering down - fast GPS 2024-02-14T19:49:17.041Z,1707940157.041 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T19:49:48.165Z,1707940188.165 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T19:50:19.289Z,1707940219.289 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T19:50:23.279Z,1707940223.279 [BPC1](INFO): Calculating totals. Valid battery stick count: 40. Valid reserve battery stick count: 6. 2024-02-14T19:50:23.281Z,1707940223.281 [BPC1](INFO): Received data from all battery sticks. 2024-02-14T19:50:50.413Z,1707940250.413 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T19:51:21.537Z,1707940281.537 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T19:51:52.661Z,1707940312.661 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T19:52:23.785Z,1707940343.785 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T19:52:54.925Z,1707940374.925 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T19:53:26.081Z,1707940406.081 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T19:53:42.460Z,1707940422.460 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-02-14T19:53:42.460Z,1707940422.460 [Default:CheckIn:C.Wait] Stopped 2024-02-14T19:53:42.460Z,1707940422.460 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-02-14T19:53:42.460Z,1707940422.460 [Default:CheckIn:D] Running Loop=1 2024-02-14T19:53:42.860Z,1707940422.860 [Default:CheckIn:D] Stopped 2024-02-14T19:53:42.860Z,1707940422.860 [Default:CheckIn:E] Running Loop=1 2024-02-14T19:53:43.272Z,1707940423.272 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 70.431706 min 2024-02-14T19:53:43.272Z,1707940423.272 [Default:CheckIn:E] Stopped 2024-02-14T19:53:43.272Z,1707940423.272 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-02-14T19:53:43.273Z,1707940423.273 [Default:CheckIn] Stopped 2024-02-14T19:53:43.273Z,1707940423.273 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-02-14T19:53:43.273Z,1707940423.273 [Default:CheckIn](INFO): Running loop #13 2024-02-14T19:53:43.273Z,1707940423.273 [Default:CheckIn] Running Loop=13 2024-02-14T19:53:43.273Z,1707940423.273 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-02-14T19:53:43.273Z,1707940423.273 [Default:CheckIn:Read_GPS] Running Loop=1 2024-02-14T19:53:45.279Z,1707940425.279 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195344.00,A,3648.29858,N,12151.49793,W,3.441,319.43,140224,,,A*7C 2024-02-14T19:53:45.291Z,1707940425.291 [NAL9602](INFO): GPS fix at 20240214T195344: (36.804976, -121.858299) 2024-02-14T19:53:45.302Z,1707940425.302 [Default:CheckIn:Read_GPS] Stopped 2024-02-14T19:53:45.302Z,1707940425.302 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-02-14T19:53:57.205Z,1707940437.205 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T19:54:12.391Z,1707940452.391 [NAL9602](INFO): SBD MO Status=1, MOMSN=46957, MT Status=0, MTMSN=0 2024-02-14T19:54:12.441Z,1707940452.441 [NAL9602](INFO): Sent 84 bytes from file Logs/20240214T184002/Courier0040.lzma 2024-02-14T19:54:12.441Z,1707940452.441 [NAL9602](INFO): Packets left to send: 0 2024-02-14T19:54:22.527Z,1707940462.527 [NAL9602](INFO): SBD MO Status=1, MOMSN=46958, MT Status=0, MTMSN=0 2024-02-14T19:54:22.577Z,1707940462.577 [NAL9602](INFO): Sent 143 bytes from file Logs/20240214T184002/Express0041.lzma 2024-02-14T19:54:22.577Z,1707940462.577 [NAL9602](INFO): Packets left to send: 0 2024-02-14T19:54:28.329Z,1707940468.329 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T19:54:33.035Z,1707940473.035 [NAL9602](INFO): SBD MO Status=0, MOMSN=46959, MT Status=0, MTMSN=0 2024-02-14T19:54:33.117Z,1707940473.117 [Default:CheckIn:Read_Iridium] Stopped 2024-02-14T19:54:33.117Z,1707940473.117 [Default:CheckIn:C.Wait] Running Loop=1 2024-02-14T19:54:33.117Z,1707940473.117 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-02-14T19:54:59.453Z,1707940499.453 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T19:55:03.739Z,1707940503.739 [NAL9602](INFO): Not Powering down - fast GPS 2024-02-14T19:55:30.577Z,1707940530.577 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T19:56:01.721Z,1707940561.721 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T19:56:32.857Z,1707940592.857 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T19:57:03.981Z,1707940623.981 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T19:57:35.105Z,1707940655.105 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T19:58:06.241Z,1707940686.241 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T19:58:37.365Z,1707940717.365 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T19:59:08.489Z,1707940748.489 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T19:59:33.620Z,1707940773.620 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-02-14T19:59:33.620Z,1707940773.620 [Default:CheckIn:C.Wait] Stopped 2024-02-14T19:59:33.620Z,1707940773.620 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-02-14T19:59:33.620Z,1707940773.620 [Default:CheckIn:D] Running Loop=1 2024-02-14T19:59:34.018Z,1707940774.018 [Default:CheckIn:D] Stopped 2024-02-14T19:59:34.018Z,1707940774.018 [Default:CheckIn:E] Running Loop=1 2024-02-14T19:59:34.434Z,1707940774.434 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 76.284351 min 2024-02-14T19:59:34.434Z,1707940774.434 [Default:CheckIn:E] Stopped 2024-02-14T19:59:34.434Z,1707940774.434 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-02-14T19:59:34.434Z,1707940774.434 [Default:CheckIn] Stopped 2024-02-14T19:59:34.434Z,1707940774.434 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-02-14T19:59:34.434Z,1707940774.434 [Default:CheckIn](INFO): Running loop #14 2024-02-14T19:59:34.434Z,1707940774.434 [Default:CheckIn] Running Loop=14 2024-02-14T19:59:34.434Z,1707940774.434 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-02-14T19:59:34.434Z,1707940774.434 [Default:CheckIn:Read_GPS] Running Loop=1 2024-02-14T19:59:36.435Z,1707940776.435 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195935.00,A,3648.42468,N,12150.68727,W,15.337,89.61,140224,,,D*71 2024-02-14T19:59:36.438Z,1707940776.438 [NAL9602](INFO): GPS fix at 20240214T195935: (36.807078, -121.844788) 2024-02-14T19:59:36.449Z,1707940776.449 [Default:CheckIn:Read_GPS] Stopped 2024-02-14T19:59:36.450Z,1707940776.450 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-02-14T19:59:39.613Z,1707940779.613 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T19:59:56.271Z,1707940796.271 [NAL9602](INFO): SBD MO Status=1, MOMSN=46960, MT Status=0, MTMSN=0 2024-02-14T19:59:56.325Z,1707940796.325 [NAL9602](INFO): Sent 72 bytes from file Logs/20240214T184002/Courier0043.lzma 2024-02-14T19:59:56.325Z,1707940796.325 [NAL9602](INFO): Packets left to send: 0 2024-02-14T20:00:07.641Z,1707940807.641 [NAL9602](INFO): SBD MO Status=1, MOMSN=46961, MT Status=0, MTMSN=0 2024-02-14T20:00:07.688Z,1707940807.688 [NAL9602](INFO): Sent 142 bytes from file Logs/20240214T184002/Express0044.lzma 2024-02-14T20:00:07.688Z,1707940807.688 [NAL9602](INFO): Packets left to send: 0 2024-02-14T20:00:10.737Z,1707940810.737 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T20:00:16.523Z,1707940816.523 [NAL9602](INFO): SBD MO Status=0, MOMSN=46962, MT Status=0, MTMSN=0 2024-02-14T20:00:16.609Z,1707940816.609 [Default:CheckIn:Read_Iridium] Stopped 2024-02-14T20:00:16.609Z,1707940816.609 [Default:CheckIn:C.Wait] Running Loop=1 2024-02-14T20:00:16.609Z,1707940816.609 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-02-14T20:00:41.869Z,1707940841.869 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T20:00:47.221Z,1707940847.221 [NAL9602](INFO): Not Powering down - fast GPS 2024-02-14T20:01:13.005Z,1707940873.005 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T20:01:44.129Z,1707940904.129 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T20:02:15.265Z,1707940935.265 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T20:02:46.401Z,1707940966.401 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T20:03:17.525Z,1707940997.525 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T20:03:48.650Z,1707941028.650 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T20:04:19.773Z,1707941059.773 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T20:04:50.905Z,1707941090.905 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T20:05:17.104Z,1707941117.104 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-02-14T20:05:17.104Z,1707941117.104 [Default:CheckIn:C.Wait] Stopped 2024-02-14T20:05:17.104Z,1707941117.104 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-02-14T20:05:17.104Z,1707941117.104 [Default:CheckIn:D] Running Loop=1 2024-02-14T20:05:17.514Z,1707941117.514 [Default:CheckIn:D] Stopped 2024-02-14T20:05:17.514Z,1707941117.514 [Default:CheckIn:E] Running Loop=1 2024-02-14T20:05:17.931Z,1707941117.931 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 82.009269 min 2024-02-14T20:05:17.931Z,1707941117.931 [Default:CheckIn:E] Stopped 2024-02-14T20:05:17.931Z,1707941117.931 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-02-14T20:05:17.931Z,1707941117.931 [Default:CheckIn] Stopped 2024-02-14T20:05:17.931Z,1707941117.931 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-02-14T20:05:17.931Z,1707941117.931 [Default:CheckIn](INFO): Running loop #15 2024-02-14T20:05:17.931Z,1707941117.931 [Default:CheckIn] Running Loop=15 2024-02-14T20:05:17.931Z,1707941117.931 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-02-14T20:05:17.931Z,1707941117.931 [Default:CheckIn:Read_GPS] Running Loop=1 2024-02-14T20:05:19.928Z,1707941119.928 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200519.00,A,3648.25774,N,12148.60396,W,17.747,91.86,140224,,,D*7D 2024-02-14T20:05:19.930Z,1707941119.930 [NAL9602](INFO): GPS fix at 20240214T200519: (36.804296, -121.810066) 2024-02-14T20:05:19.941Z,1707941119.941 [Default:CheckIn:Read_GPS] Stopped 2024-02-14T20:05:19.941Z,1707941119.941 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-02-14T20:05:22.029Z,1707941122.029 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T20:05:53.153Z,1707941153.153 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T20:05:57.547Z,1707941157.547 [NAL9602](INFO): SBD MO Status=2, MOMSN=46963, MT Status=2, MTMSN=0 2024-02-14T20:05:57.547Z,1707941157.547 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-02-14T20:06:08.103Z,1707941168.103 [NAL9602](INFO): SBD MO Status=1, MOMSN=46963, MT Status=0, MTMSN=0 2024-02-14T20:06:08.153Z,1707941168.153 [NAL9602](INFO): Sent 72 bytes from file Logs/20240214T184002/Courier0046.lzma 2024-02-14T20:06:08.153Z,1707941168.153 [NAL9602](INFO): Packets left to send: 0 2024-02-14T20:06:17.055Z,1707941177.055 [NAL9602](INFO): SBD MO Status=1, MOMSN=46964, MT Status=0, MTMSN=0 2024-02-14T20:06:17.109Z,1707941177.109 [NAL9602](INFO): Sent 143 bytes from file Logs/20240214T184002/Express0047.lzma 2024-02-14T20:06:17.109Z,1707941177.109 [NAL9602](INFO): Packets left to send: 0 2024-02-14T20:06:24.285Z,1707941184.285 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T20:06:24.731Z,1707941184.731 [NAL9602](INFO): SBD MO Status=0, MOMSN=46965, MT Status=0, MTMSN=0 2024-02-14T20:06:24.824Z,1707941184.824 [Default:CheckIn:Read_Iridium] Stopped 2024-02-14T20:06:24.824Z,1707941184.824 [Default:CheckIn:C.Wait] Running Loop=1 2024-02-14T20:06:24.824Z,1707941184.824 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-02-14T20:06:55.417Z,1707941215.417 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T20:06:55.434Z,1707941215.434 [NAL9602](INFO): Not Powering down - fast GPS 2024-02-14T20:07:26.541Z,1707941246.541 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-02-14T20:07:38.105Z,1707941258.105 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002804 2024-02-14T20:11:25.319Z,1707941485.319 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-02-14T20:11:25.319Z,1707941485.319 [Default:CheckIn:C.Wait] Stopped 2024-02-14T20:11:25.319Z,1707941485.319 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-02-14T20:11:25.319Z,1707941485.319 [Default:CheckIn:D] Running Loop=1 2024-02-14T20:11:25.728Z,1707941485.728 [Default:CheckIn:D] Stopped 2024-02-14T20:11:25.728Z,1707941485.728 [Default:CheckIn:E] Running Loop=1 2024-02-14T20:11:26.141Z,1707941486.141 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 88.146175 min 2024-02-14T20:11:26.141Z,1707941486.141 [Default:CheckIn:E] Stopped 2024-02-14T20:11:26.141Z,1707941486.141 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-02-14T20:11:26.141Z,1707941486.141 [Default:CheckIn] Stopped 2024-02-14T20:11:26.141Z,1707941486.141 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-02-14T20:11:26.141Z,1707941486.141 [Default:CheckIn](INFO): Running loop #16 2024-02-14T20:11:26.141Z,1707941486.141 [Default:CheckIn] Running Loop=16 2024-02-14T20:11:26.141Z,1707941486.141 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-02-14T20:11:26.142Z,1707941486.142 [Default:CheckIn:Read_GPS] Running Loop=1 2024-02-14T20:11:28.144Z,1707941488.144 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201127.00,A,3648.50751,N,12147.13958,W,4.121,145.50,140224,,,D*74 2024-02-14T20:11:28.146Z,1707941488.146 [NAL9602](INFO): GPS fix at 20240214T201127: (36.808459, -121.785660) 2024-02-14T20:11:28.181Z,1707941488.181 [Default:CheckIn:Read_GPS] Stopped 2024-02-14T20:11:28.181Z,1707941488.181 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-02-14T20:11:35.824Z,1707941495.824 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240214T184002/Courier0049.lzma 2024-02-14T20:11:36.827Z,1707941496.827 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Courier0049.lzma.bak 2024-02-14T20:11:36.827Z,1707941496.827 [DataOverHttps](INFO): SBD MOMSN=19279102 2024-02-14T20:11:46.340Z,1707941506.340 [NAL9602](INFO): SBD MO Status=0, MOMSN=46966, MT Status=0, MTMSN=0 2024-02-14T20:11:46.340Z,1707941506.340 [NAL9602](INFO): No messages in MT queue 2024-02-14T20:11:52.781Z,1707941512.781 [DataOverHttps](INFO): Sending 143 bytes from file Logs/20240214T184002/Express0050.lzma 2024-02-14T20:11:53.779Z,1707941513.779 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Express0050.lzma.bak 2024-02-14T20:11:53.779Z,1707941513.779 [DataOverHttps](INFO): SBD MOMSN=19279105 2024-02-14T20:11:54.841Z,1707941514.841 [Default:CheckIn:Read_Iridium] Stopped 2024-02-14T20:11:54.841Z,1707941514.841 [Default:CheckIn:C.Wait] Running Loop=1 2024-02-14T20:11:54.841Z,1707941514.841 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-02-14T20:12:17.022Z,1707941537.022 [NAL9602](INFO): Not Powering down - fast GPS 2024-02-14T20:16:55.432Z,1707941815.432 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-02-14T20:16:55.432Z,1707941815.432 [Default:CheckIn:C.Wait] Stopped 2024-02-14T20:16:55.432Z,1707941815.432 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-02-14T20:16:55.432Z,1707941815.432 [Default:CheckIn:D] Running Loop=1 2024-02-14T20:16:55.889Z,1707941815.889 [Default:CheckIn:D] Stopped 2024-02-14T20:16:55.889Z,1707941815.889 [Default:CheckIn:E] Running Loop=1 2024-02-14T20:16:56.253Z,1707941816.253 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 93.648853 min 2024-02-14T20:16:56.253Z,1707941816.253 [Default:CheckIn:E] Stopped 2024-02-14T20:16:56.253Z,1707941816.253 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-02-14T20:16:56.253Z,1707941816.253 [Default:CheckIn] Stopped 2024-02-14T20:16:56.253Z,1707941816.253 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-02-14T20:16:56.254Z,1707941816.254 [Default:CheckIn](INFO): Running loop #17 2024-02-14T20:16:56.254Z,1707941816.254 [Default:CheckIn] Running Loop=17 2024-02-14T20:16:56.254Z,1707941816.254 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-02-14T20:16:56.254Z,1707941816.254 [Default:CheckIn:Read_GPS] Running Loop=1 2024-02-14T20:16:58.252Z,1707941818.252 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201657.00,A,3648.14972,N,12147.22133,W,0.778,226.55,140224,,,D*71 2024-02-14T20:16:58.254Z,1707941818.254 [NAL9602](INFO): GPS fix at 20240214T201657: (36.802495, -121.787022) 2024-02-14T20:16:58.285Z,1707941818.285 [Default:CheckIn:Read_GPS] Stopped 2024-02-14T20:16:58.285Z,1707941818.285 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-02-14T20:17:06.268Z,1707941826.268 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240214T184002/Courier0052.lzma 2024-02-14T20:17:07.271Z,1707941827.271 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Courier0052.lzma.bak 2024-02-14T20:17:07.271Z,1707941827.271 [DataOverHttps](INFO): SBD MOMSN=19279152 2024-02-14T20:17:12.388Z,1707941832.388 [NAL9602](INFO): SBD MO Status=0, MOMSN=46967, MT Status=0, MTMSN=0 2024-02-14T20:17:12.388Z,1707941832.388 [NAL9602](INFO): No messages in MT queue 2024-02-14T20:17:23.273Z,1707941843.273 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20240214T184002/Express0053.lzma 2024-02-14T20:17:24.275Z,1707941844.275 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Express0053.lzma.bak 2024-02-14T20:17:24.275Z,1707941844.275 [DataOverHttps](INFO): SBD MOMSN=19279155 2024-02-14T20:17:25.333Z,1707941845.333 [Default:CheckIn:Read_Iridium] Stopped 2024-02-14T20:17:25.333Z,1707941845.333 [Default:CheckIn:C.Wait] Running Loop=1 2024-02-14T20:17:25.333Z,1707941845.333 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-02-14T20:17:43.089Z,1707941863.089 [NAL9602](INFO): Not Powering down - fast GPS 2024-02-14T20:22:25.941Z,1707942145.941 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-02-14T20:22:25.941Z,1707942145.941 [Default:CheckIn:C.Wait] Stopped 2024-02-14T20:22:25.941Z,1707942145.941 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-02-14T20:22:25.941Z,1707942145.941 [Default:CheckIn:D] Running Loop=1 2024-02-14T20:22:26.343Z,1707942146.343 [Default:CheckIn:D] Stopped 2024-02-14T20:22:26.343Z,1707942146.343 [Default:CheckIn:E] Running Loop=1 2024-02-14T20:22:26.739Z,1707942146.739 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 99.156421 min 2024-02-14T20:22:26.739Z,1707942146.739 [Default:CheckIn:E] Stopped 2024-02-14T20:22:26.739Z,1707942146.739 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-02-14T20:22:26.739Z,1707942146.739 [Default:CheckIn] Stopped 2024-02-14T20:22:26.739Z,1707942146.739 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-02-14T20:22:26.740Z,1707942146.740 [Default:CheckIn](INFO): Running loop #18 2024-02-14T20:22:26.740Z,1707942146.740 [Default:CheckIn] Running Loop=18 2024-02-14T20:22:26.740Z,1707942146.740 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-02-14T20:22:26.740Z,1707942146.740 [Default:CheckIn:Read_GPS] Running Loop=1 2024-02-14T20:22:28.744Z,1707942148.744 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202227.00,A,3648.15035,N,12147.22154,W,0.019,225.67,140224,,,A*7C 2024-02-14T20:22:28.746Z,1707942148.746 [NAL9602](INFO): GPS fix at 20240214T202227: (36.802506, -121.787026) 2024-02-14T20:22:28.757Z,1707942148.757 [Default:CheckIn:Read_GPS] Stopped 2024-02-14T20:22:28.758Z,1707942148.758 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-02-14T20:22:36.380Z,1707942156.380 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240214T184002/Courier0055.lzma 2024-02-14T20:22:37.383Z,1707942157.383 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Courier0055.lzma.bak 2024-02-14T20:22:37.383Z,1707942157.383 [DataOverHttps](INFO): SBD MOMSN=19279165 2024-02-14T20:22:46.527Z,1707942166.527 [NAL9602](INFO): SBD MO Status=2, MOMSN=46968, MT Status=2, MTMSN=0 2024-02-14T20:22:46.527Z,1707942166.527 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-02-14T20:22:56.336Z,1707942176.336 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20240214T184002/Express0056.lzma 2024-02-14T20:22:57.339Z,1707942177.339 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Express0056.lzma.bak 2024-02-14T20:22:57.339Z,1707942177.339 [DataOverHttps](INFO): SBD MOMSN=19279168 2024-02-14T20:22:58.705Z,1707942178.705 [Default:CheckIn:Read_Iridium] Stopped 2024-02-14T20:22:58.705Z,1707942178.705 [Default:CheckIn:C.Wait] Running Loop=1 2024-02-14T20:22:58.705Z,1707942178.705 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-02-14T20:23:42.731Z,1707942222.731 [NAL9602](INFO): SBD MO Status=2, MOMSN=46968, MT Status=2, MTMSN=0 2024-02-14T20:23:42.731Z,1707942222.731 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-02-14T20:24:04.139Z,1707942244.139 [NAL9602](INFO): SBD MO Status=2, MOMSN=46968, MT Status=2, MTMSN=0 2024-02-14T20:24:04.139Z,1707942244.139 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-02-14T20:24:15.455Z,1707942255.455 [NAL9602](INFO): SBD MO Status=0, MOMSN=46968, MT Status=0, MTMSN=0 2024-02-14T20:24:15.455Z,1707942255.455 [NAL9602](INFO): No messages in MT queue 2024-02-14T20:24:46.154Z,1707942286.154 [NAL9602](INFO): Not Powering down - fast GPS 2024-02-14T20:27:59.292Z,1707942479.292 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-02-14T20:27:59.293Z,1707942479.293 [Default:CheckIn:C.Wait] Stopped 2024-02-14T20:27:59.293Z,1707942479.293 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-02-14T20:27:59.293Z,1707942479.293 [Default:CheckIn:D] Running Loop=1 2024-02-14T20:27:59.690Z,1707942479.690 [Default:CheckIn:D] Stopped 2024-02-14T20:27:59.690Z,1707942479.690 [Default:CheckIn:E] Running Loop=1 2024-02-14T20:28:00.093Z,1707942480.093 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 104.712207 min 2024-02-14T20:28:00.093Z,1707942480.093 [Default:CheckIn:E] Stopped 2024-02-14T20:28:00.094Z,1707942480.094 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-02-14T20:28:00.094Z,1707942480.094 [Default:CheckIn] Stopped 2024-02-14T20:28:00.094Z,1707942480.094 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-02-14T20:28:00.094Z,1707942480.094 [Default:CheckIn](INFO): Running loop #19 2024-02-14T20:28:00.094Z,1707942480.094 [Default:CheckIn] Running Loop=19 2024-02-14T20:28:00.094Z,1707942480.094 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-02-14T20:28:00.094Z,1707942480.094 [Default:CheckIn:Read_GPS] Running Loop=1 2024-02-14T20:28:02.108Z,1707942482.108 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202801.00,A,3648.15005,N,12147.22105,W,0.039,225.67,140224,,,A*77 2024-02-14T20:28:02.110Z,1707942482.110 [NAL9602](INFO): GPS fix at 20240214T202801: (36.802501, -121.787018) 2024-02-14T20:28:02.139Z,1707942482.139 [Default:CheckIn:Read_GPS] Stopped 2024-02-14T20:28:02.139Z,1707942482.139 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-02-14T20:28:09.462Z,1707942489.462 [NAL9602](INFO): SBD MO Status=0, MOMSN=46969, MT Status=0, MTMSN=0 2024-02-14T20:28:09.462Z,1707942489.462 [NAL9602](INFO): No messages in MT queue 2024-02-14T20:28:09.696Z,1707942489.696 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240214T184002/Courier0058.lzma 2024-02-14T20:28:10.707Z,1707942490.707 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Courier0058.lzma.bak 2024-02-14T20:28:10.707Z,1707942490.707 [DataOverHttps](INFO): SBD MOMSN=19279180 2024-02-14T20:28:29.180Z,1707942509.180 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20240214T184002/Express0059.lzma 2024-02-14T20:28:30.183Z,1707942510.183 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Express0059.lzma.bak 2024-02-14T20:28:30.183Z,1707942510.183 [DataOverHttps](INFO): SBD MOMSN=19279184 2024-02-14T20:28:31.338Z,1707942511.338 [Default:CheckIn:Read_Iridium] Stopped 2024-02-14T20:28:31.338Z,1707942511.338 [Default:CheckIn:C.Wait] Running Loop=1 2024-02-14T20:28:31.338Z,1707942511.338 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-02-14T20:28:40.210Z,1707942520.210 [NAL9602](INFO): Not Powering down - fast GPS 2024-02-14T20:33:31.960Z,1707942811.960 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-02-14T20:33:31.969Z,1707942811.969 [Default:CheckIn:C.Wait] Stopped 2024-02-14T20:33:31.969Z,1707942811.969 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-02-14T20:33:31.969Z,1707942811.969 [Default:CheckIn:D] Running Loop=1 2024-02-14T20:33:32.359Z,1707942812.359 [Default:CheckIn:D] Stopped 2024-02-14T20:33:32.359Z,1707942812.359 [Default:CheckIn:E] Running Loop=1 2024-02-14T20:33:32.759Z,1707942812.759 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 110.256698 min 2024-02-14T20:33:32.760Z,1707942812.760 [Default:CheckIn:E] Stopped 2024-02-14T20:33:32.760Z,1707942812.760 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-02-14T20:33:32.760Z,1707942812.760 [Default:CheckIn] Stopped 2024-02-14T20:33:32.760Z,1707942812.760 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-02-14T20:33:32.760Z,1707942812.760 [Default:CheckIn](INFO): Running loop #20 2024-02-14T20:33:32.760Z,1707942812.760 [Default:CheckIn] Running Loop=20 2024-02-14T20:33:32.760Z,1707942812.760 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-02-14T20:33:32.760Z,1707942812.760 [Default:CheckIn:Read_GPS] Running Loop=1 2024-02-14T20:33:34.774Z,1707942814.774 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203333.00,A,3648.14981,N,12147.22163,W,0.019,225.67,140224,,,A*7A 2024-02-14T20:33:34.776Z,1707942814.776 [NAL9602](INFO): GPS fix at 20240214T203333: (36.802497, -121.787027) 2024-02-14T20:33:34.787Z,1707942814.787 [Default:CheckIn:Read_GPS] Stopped 2024-02-14T20:33:34.787Z,1707942814.787 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-02-14T20:33:42.416Z,1707942822.416 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20240214T184002/Courier0061.lzma 2024-02-14T20:33:43.419Z,1707942823.419 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Courier0061.lzma.bak 2024-02-14T20:33:43.419Z,1707942823.419 [DataOverHttps](INFO): SBD MOMSN=19279210 2024-02-14T20:33:59.164Z,1707942839.164 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20240214T184002/Express0062.lzma 2024-02-14T20:34:00.167Z,1707942840.167 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Express0062.lzma.bak 2024-02-14T20:34:00.167Z,1707942840.167 [DataOverHttps](INFO): SBD MOMSN=19279213 2024-02-14T20:34:00.227Z,1707942840.227 [NAL9602](INFO): SBD MO Status=2, MOMSN=46970, MT Status=2, MTMSN=0 2024-02-14T20:34:00.227Z,1707942840.227 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-02-14T20:34:01.463Z,1707942841.463 [Default:CheckIn:Read_Iridium] Stopped 2024-02-14T20:34:01.463Z,1707942841.463 [Default:CheckIn:C.Wait] Running Loop=1 2024-02-14T20:34:01.463Z,1707942841.463 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-02-14T20:34:24.467Z,1707942864.467 [NAL9602](INFO): SBD MO Status=2, MOMSN=46970, MT Status=2, MTMSN=0 2024-02-14T20:34:24.467Z,1707942864.467 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-02-14T20:34:43.859Z,1707942883.859 [NAL9602](INFO): SBD MO Status=0, MOMSN=46970, MT Status=0, MTMSN=0 2024-02-14T20:34:43.860Z,1707942883.860 [NAL9602](INFO): No messages in MT queue 2024-02-14T20:35:14.594Z,1707942914.594 [NAL9602](INFO): Not Powering down - fast GPS 2024-02-14T20:39:02.064Z,1707943142.064 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-02-14T20:39:02.064Z,1707943142.064 [Default:CheckIn:C.Wait] Stopped 2024-02-14T20:39:02.064Z,1707943142.064 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-02-14T20:39:02.064Z,1707943142.064 [Default:CheckIn:D] Running Loop=1 2024-02-14T20:39:02.459Z,1707943142.459 [Default:CheckIn:D] Stopped 2024-02-14T20:39:02.460Z,1707943142.460 [Default:CheckIn:E] Running Loop=1 2024-02-14T20:39:02.870Z,1707943142.870 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 115.758366 min 2024-02-14T20:39:02.870Z,1707943142.870 [Default:CheckIn:E] Stopped 2024-02-14T20:39:02.870Z,1707943142.870 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-02-14T20:39:02.870Z,1707943142.870 [Default:CheckIn] Stopped 2024-02-14T20:39:02.871Z,1707943142.871 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-02-14T20:39:02.871Z,1707943142.871 [Default:CheckIn](INFO): Running loop #21 2024-02-14T20:39:02.871Z,1707943142.871 [Default:CheckIn] Running Loop=21 2024-02-14T20:39:02.871Z,1707943142.871 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-02-14T20:39:02.871Z,1707943142.871 [Default:CheckIn:Read_GPS] Running Loop=1 2024-02-14T20:39:04.880Z,1707943144.880 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203904.00,A,3648.15029,N,12147.22155,W,0.078,258.79,140224,,,A*79 2024-02-14T20:39:04.891Z,1707943144.891 [NAL9602](INFO): GPS fix at 20240214T203904: (36.802505, -121.787026) 2024-02-14T20:39:04.902Z,1707943144.902 [Default:CheckIn:Read_GPS] Stopped 2024-02-14T20:39:04.902Z,1707943144.902 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-02-14T20:39:12.192Z,1707943152.192 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240214T184002/Courier0064.lzma 2024-02-14T20:39:13.194Z,1707943153.194 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Courier0064.lzma.bak 2024-02-14T20:39:13.195Z,1707943153.195 [DataOverHttps](INFO): SBD MOMSN=19279217 2024-02-14T20:39:29.060Z,1707943169.060 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20240214T184002/Express0065.lzma 2024-02-14T20:39:30.067Z,1707943170.067 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Express0065.lzma.bak 2024-02-14T20:39:30.067Z,1707943170.067 [DataOverHttps](INFO): SBD MOMSN=19279220 2024-02-14T20:39:31.160Z,1707943171.160 [Default:CheckIn:Read_Iridium] Stopped 2024-02-14T20:39:31.160Z,1707943171.160 [Default:CheckIn:C.Wait] Running Loop=1 2024-02-14T20:39:31.161Z,1707943171.161 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-02-14T20:40:15.583Z,1707943215.583 [NAL9602](INFO): SBD MO Status=0, MOMSN=46971, MT Status=0, MTMSN=0 2024-02-14T20:40:15.583Z,1707943215.583 [NAL9602](INFO): No messages in MT queue 2024-02-14T20:40:46.296Z,1707943246.296 [NAL9602](INFO): Not Powering down - fast GPS 2024-02-14T20:44:31.741Z,1707943471.741 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-02-14T20:44:31.741Z,1707943471.741 [Default:CheckIn:C.Wait] Stopped 2024-02-14T20:44:31.741Z,1707943471.741 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-02-14T20:44:31.741Z,1707943471.741 [Default:CheckIn:D] Running Loop=1 2024-02-14T20:44:32.139Z,1707943472.139 [Default:CheckIn:D] Stopped 2024-02-14T20:44:32.139Z,1707943472.139 [Default:CheckIn:E] Running Loop=1 2024-02-14T20:44:32.540Z,1707943472.540 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 121.253027 min 2024-02-14T20:44:32.540Z,1707943472.540 [Default:CheckIn:E] Stopped 2024-02-14T20:44:32.541Z,1707943472.541 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-02-14T20:44:32.541Z,1707943472.541 [Default:CheckIn] Stopped 2024-02-14T20:44:32.541Z,1707943472.541 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-02-14T20:44:32.541Z,1707943472.541 [Default:CheckIn](INFO): Running loop #22 2024-02-14T20:44:32.541Z,1707943472.541 [Default:CheckIn] Running Loop=22 2024-02-14T20:44:32.541Z,1707943472.541 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-02-14T20:44:32.541Z,1707943472.541 [Default:CheckIn:Read_GPS] Running Loop=1 2024-02-14T20:44:34.548Z,1707943474.548 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204433.00,A,3648.15286,N,12147.21540,W,1.438,52.38,140224,,,A*4F 2024-02-14T20:44:34.550Z,1707943474.550 [NAL9602](INFO): GPS fix at 20240214T204433: (36.802548, -121.786923) 2024-02-14T20:44:34.561Z,1707943474.561 [Default:CheckIn:Read_GPS] Stopped 2024-02-14T20:44:34.561Z,1707943474.561 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-02-14T20:44:42.236Z,1707943482.236 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240214T184002/Courier0067.lzma 2024-02-14T20:44:43.238Z,1707943483.238 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Courier0067.lzma.bak 2024-02-14T20:44:43.239Z,1707943483.239 [DataOverHttps](INFO): SBD MOMSN=19279224 2024-02-14T20:44:53.589Z,1707943493.589 [NAL9602](INFO): SBD MO Status=2, MOMSN=46972, MT Status=2, MTMSN=0 2024-02-14T20:44:53.589Z,1707943493.589 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-02-14T20:45:02.253Z,1707943502.253 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20240214T184002/Express0068.lzma 2024-02-14T20:45:03.255Z,1707943503.255 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Express0068.lzma.bak 2024-02-14T20:45:03.255Z,1707943503.255 [DataOverHttps](INFO): SBD MOMSN=19279227 2024-02-14T20:45:04.522Z,1707943504.522 [Default:CheckIn:Read_Iridium] Stopped 2024-02-14T20:45:04.522Z,1707943504.522 [Default:CheckIn:C.Wait] Running Loop=1 2024-02-14T20:45:04.522Z,1707943504.522 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-02-14T20:45:12.179Z,1707943512.179 [NAL9602](INFO): SBD MO Status=0, MOMSN=46972, MT Status=0, MTMSN=0 2024-02-14T20:45:12.179Z,1707943512.179 [NAL9602](INFO): No messages in MT queue 2024-02-14T20:45:42.878Z,1707943542.878 [NAL9602](INFO): Not Powering down - fast GPS 2024-02-14T20:50:05.087Z,1707943805.087 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-02-14T20:50:05.087Z,1707943805.087 [Default:CheckIn:C.Wait] Stopped 2024-02-14T20:50:05.087Z,1707943805.087 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-02-14T20:50:05.087Z,1707943805.087 [Default:CheckIn:D] Running Loop=1 2024-02-14T20:50:05.494Z,1707943805.494 [Default:CheckIn:D] Stopped 2024-02-14T20:50:05.494Z,1707943805.494 [Default:CheckIn:E] Running Loop=1 2024-02-14T20:50:05.910Z,1707943805.910 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 126.808944 min 2024-02-14T20:50:05.910Z,1707943805.910 [Default:CheckIn:E] Stopped 2024-02-14T20:50:05.910Z,1707943805.910 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-02-14T20:50:05.910Z,1707943805.910 [Default:CheckIn] Stopped 2024-02-14T20:50:05.910Z,1707943805.910 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-02-14T20:50:05.911Z,1707943805.911 [Default:CheckIn](INFO): Running loop #23 2024-02-14T20:50:05.911Z,1707943805.911 [Default:CheckIn] Running Loop=23 2024-02-14T20:50:05.911Z,1707943805.911 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-02-14T20:50:05.911Z,1707943805.911 [Default:CheckIn:Read_GPS] Running Loop=1 2024-02-14T20:50:07.904Z,1707943807.904 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205007.00,A,3648.51644,N,12147.13791,W,4.860,315.63,140224,,,A*72 2024-02-14T20:50:07.906Z,1707943807.906 [NAL9602](INFO): GPS fix at 20240214T205007: (36.808607, -121.785632) 2024-02-14T20:50:07.917Z,1707943807.917 [Default:CheckIn:Read_GPS] Stopped 2024-02-14T20:50:07.917Z,1707943807.917 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-02-14T20:50:15.976Z,1707943815.976 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240214T184002/Courier0070.lzma 2024-02-14T20:50:16.979Z,1707943816.979 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Courier0070.lzma.bak 2024-02-14T20:50:16.979Z,1707943816.979 [DataOverHttps](INFO): SBD MOMSN=19279231 2024-02-14T20:50:35.023Z,1707943835.023 [NAL9602](INFO): SBD MO Status=2, MOMSN=46973, MT Status=2, MTMSN=0 2024-02-14T20:50:35.024Z,1707943835.024 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-02-14T20:50:35.756Z,1707943835.756 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20240214T184002/Express0071.lzma 2024-02-14T20:50:36.759Z,1707943836.759 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Express0071.lzma.bak 2024-02-14T20:50:36.759Z,1707943836.759 [DataOverHttps](INFO): SBD MOMSN=19279234 2024-02-14T20:50:37.878Z,1707943837.878 [Default:CheckIn:Read_Iridium] Stopped 2024-02-14T20:50:37.878Z,1707943837.878 [Default:CheckIn:C.Wait] Running Loop=1 2024-02-14T20:50:37.879Z,1707943837.879 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-02-14T20:51:13.807Z,1707943873.807 [NAL9602](INFO): SBD MO Status=0, MOMSN=46973, MT Status=0, MTMSN=0 2024-02-14T20:51:13.807Z,1707943873.807 [NAL9602](INFO): No messages in MT queue 2024-02-14T20:51:30.367Z,1707943890.367 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-02-14T20:51:43.297Z,1707943903.297 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-02-14T20:51:44.510Z,1707943904.510 [NAL9602](INFO): Not Powering down - fast GPS 2024-02-14T20:51:56.224Z,1707943916.224 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-02-14T20:52:09.153Z,1707943929.153 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-02-14T20:52:21.275Z,1707943941.275 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-02-14T20:52:34.204Z,1707943954.204 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-02-14T20:52:46.323Z,1707943966.323 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-02-14T20:55:27.944Z,1707944127.944 [BPC1](INFO): Calculating totals. Valid battery stick count: 40. Valid reserve battery stick count: 6. 2024-02-14T20:55:27.946Z,1707944127.946 [BPC1](INFO): Received data from all battery sticks. 2024-02-14T20:55:38.460Z,1707944138.460 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-02-14T20:55:38.460Z,1707944138.460 [Default:CheckIn:C.Wait] Stopped 2024-02-14T20:55:38.460Z,1707944138.460 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-02-14T20:55:38.460Z,1707944138.460 [Default:CheckIn:D] Running Loop=1 2024-02-14T20:55:38.867Z,1707944138.867 [Default:CheckIn:D] Stopped 2024-02-14T20:55:38.867Z,1707944138.867 [Default:CheckIn:E] Running Loop=1 2024-02-14T20:55:39.262Z,1707944139.262 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 132.365169 min 2024-02-14T20:55:39.262Z,1707944139.262 [Default:CheckIn:E] Stopped 2024-02-14T20:55:39.262Z,1707944139.262 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-02-14T20:55:39.262Z,1707944139.262 [Default:CheckIn] Stopped 2024-02-14T20:55:39.262Z,1707944139.262 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-02-14T20:55:39.262Z,1707944139.262 [Default:CheckIn](INFO): Running loop #24 2024-02-14T20:55:39.262Z,1707944139.262 [Default:CheckIn] Running Loop=24 2024-02-14T20:55:39.262Z,1707944139.262 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-02-14T20:55:39.262Z,1707944139.262 [Default:CheckIn:Read_GPS] Running Loop=1 2024-02-14T20:55:41.276Z,1707944141.276 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205540.00,A,3648.18953,N,12148.57203,W,23.676,255.83,140224,,,D*43 2024-02-14T20:55:41.278Z,1707944141.278 [NAL9602](INFO): GPS fix at 20240214T205540: (36.803159, -121.809534) 2024-02-14T20:55:41.289Z,1707944141.289 [Default:CheckIn:Read_GPS] Stopped 2024-02-14T20:55:41.289Z,1707944141.289 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-02-14T20:55:48.796Z,1707944148.796 [DataOverHttps](INFO): Sending 82 bytes from file Logs/20240214T184002/Courier0073.lzma 2024-02-14T20:55:49.799Z,1707944149.799 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Courier0073.lzma.bak 2024-02-14T20:55:49.799Z,1707944149.799 [DataOverHttps](INFO): SBD MOMSN=19279260 2024-02-14T20:55:54.603Z,1707944154.603 [NAL9602](INFO): SBD MO Status=0, MOMSN=46974, MT Status=0, MTMSN=0 2024-02-14T20:55:54.603Z,1707944154.603 [NAL9602](INFO): No messages in MT queue 2024-02-14T20:56:05.548Z,1707944165.548 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20240214T184002/Express0074.lzma 2024-02-14T20:56:06.551Z,1707944166.551 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Express0074.lzma.bak 2024-02-14T20:56:06.551Z,1707944166.551 [DataOverHttps](INFO): SBD MOMSN=19279263 2024-02-14T20:56:07.942Z,1707944167.942 [Default:CheckIn:Read_Iridium] Stopped 2024-02-14T20:56:07.942Z,1707944167.942 [Default:CheckIn:C.Wait] Running Loop=1 2024-02-14T20:56:07.942Z,1707944167.942 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-02-14T20:56:25.306Z,1707944185.306 [NAL9602](INFO): Not Powering down - fast GPS 2024-02-14T21:01:08.536Z,1707944468.536 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-02-14T21:01:08.536Z,1707944468.536 [Default:CheckIn:C.Wait] Stopped 2024-02-14T21:01:08.536Z,1707944468.536 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-02-14T21:01:08.536Z,1707944468.536 [Default:CheckIn:D] Running Loop=1 2024-02-14T21:01:08.953Z,1707944468.953 [Default:CheckIn:D] Stopped 2024-02-14T21:01:08.953Z,1707944468.953 [Default:CheckIn:E] Running Loop=1 2024-02-14T21:01:09.335Z,1707944469.335 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 137.866602 min 2024-02-14T21:01:09.335Z,1707944469.335 [Default:CheckIn:E] Stopped 2024-02-14T21:01:09.335Z,1707944469.335 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-02-14T21:01:09.335Z,1707944469.335 [Default:CheckIn] Stopped 2024-02-14T21:01:09.335Z,1707944469.335 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-02-14T21:01:09.335Z,1707944469.335 [Default:CheckIn](INFO): Running loop #25 2024-02-14T21:01:09.335Z,1707944469.335 [Default:CheckIn] Running Loop=25 2024-02-14T21:01:09.335Z,1707944469.335 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-02-14T21:01:09.335Z,1707944469.335 [Default:CheckIn:Read_GPS] Running Loop=1 2024-02-14T21:01:11.355Z,1707944471.355 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210110.00,A,3647.83956,N,12150.80140,W,5.579,6.15,140224,,,D*7A 2024-02-14T21:01:11.358Z,1707944471.358 [NAL9602](INFO): GPS fix at 20240214T210110: (36.797326, -121.846690) 2024-02-14T21:01:11.368Z,1707944471.368 [Default:CheckIn:Read_GPS] Stopped 2024-02-14T21:01:11.369Z,1707944471.369 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-02-14T21:01:19.112Z,1707944479.112 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240214T184002/Courier0076.lzma 2024-02-14T21:01:20.115Z,1707944480.115 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Courier0076.lzma.bak 2024-02-14T21:01:20.115Z,1707944480.115 [DataOverHttps](INFO): SBD MOMSN=19279275 2024-02-14T21:01:26.703Z,1707944486.703 [NAL9602](INFO): SBD MO Status=0, MOMSN=46975, MT Status=0, MTMSN=0 2024-02-14T21:01:26.703Z,1707944486.703 [NAL9602](INFO): No messages in MT queue 2024-02-14T21:01:35.984Z,1707944495.984 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20240214T184002/Express0077.lzma 2024-02-14T21:01:36.987Z,1707944496.987 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Express0077.lzma.bak 2024-02-14T21:01:36.987Z,1707944496.987 [DataOverHttps](INFO): SBD MOMSN=19279278 2024-02-14T21:01:38.047Z,1707944498.047 [Default:CheckIn:Read_Iridium] Stopped 2024-02-14T21:01:38.047Z,1707944498.047 [Default:CheckIn:C.Wait] Running Loop=1 2024-02-14T21:01:38.047Z,1707944498.047 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-02-14T21:01:57.402Z,1707944517.402 [NAL9602](INFO): Not Powering down - fast GPS 2024-02-14T21:06:38.624Z,1707944798.624 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-02-14T21:06:38.624Z,1707944798.624 [Default:CheckIn:C.Wait] Stopped 2024-02-14T21:06:38.624Z,1707944798.624 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-02-14T21:06:38.624Z,1707944798.624 [Default:CheckIn:D] Running Loop=1 2024-02-14T21:06:39.027Z,1707944799.027 [Default:CheckIn:D] Stopped 2024-02-14T21:06:39.027Z,1707944799.027 [Default:CheckIn:E] Running Loop=1 2024-02-14T21:06:39.429Z,1707944799.429 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 143.367839 min 2024-02-14T21:06:39.429Z,1707944799.429 [Default:CheckIn:E] Stopped 2024-02-14T21:06:39.429Z,1707944799.429 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-02-14T21:06:39.429Z,1707944799.429 [Default:CheckIn] Stopped 2024-02-14T21:06:39.429Z,1707944799.429 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-02-14T21:06:39.429Z,1707944799.429 [Default:CheckIn](INFO): Running loop #26 2024-02-14T21:06:39.429Z,1707944799.429 [Default:CheckIn] Running Loop=26 2024-02-14T21:06:39.430Z,1707944799.430 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-02-14T21:06:39.430Z,1707944799.430 [Default:CheckIn:Read_GPS] Running Loop=1 2024-02-14T21:06:41.444Z,1707944801.444 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210640.00,A,3647.79913,N,12150.90035,W,1.924,238.52,140224,,,D*72 2024-02-14T21:06:41.446Z,1707944801.446 [NAL9602](INFO): GPS fix at 20240214T210640: (36.796652, -121.848339) 2024-02-14T21:06:41.475Z,1707944801.475 [Default:CheckIn:Read_GPS] Stopped 2024-02-14T21:06:41.476Z,1707944801.476 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-02-14T21:06:52.504Z,1707944812.504 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240214T184002/Courier0079.lzma 2024-02-14T21:06:53.507Z,1707944813.507 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Courier0079.lzma.bak 2024-02-14T21:06:53.507Z,1707944813.507 [DataOverHttps](INFO): SBD MOMSN=19279285 2024-02-14T21:07:02.871Z,1707944822.871 [NAL9602](INFO): SBD MO Status=0, MOMSN=46976, MT Status=0, MTMSN=0 2024-02-14T21:07:02.871Z,1707944822.871 [NAL9602](INFO): No messages in MT queue 2024-02-14T21:07:11.468Z,1707944831.468 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20240214T184002/Express0080.lzma 2024-02-14T21:07:12.471Z,1707944832.471 [DataOverHttps](INFO): Moved sent file to Logs/20240214T184002/Express0080.lzma.bak 2024-02-14T21:07:12.471Z,1707944832.471 [DataOverHttps](INFO): SBD MOMSN=19279288 2024-02-14T21:07:13.798Z,1707944833.798 [Default:CheckIn:Read_Iridium] Stopped 2024-02-14T21:07:13.798Z,1707944833.798 [Default:CheckIn:C.Wait] Running Loop=1 2024-02-14T21:07:13.798Z,1707944833.798 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-02-14T21:07:33.580Z,1707944853.580 [NAL9602](INFO): Not Powering down - fast GPS 2024-02-14T21:08:25.606Z,1707944905.606 [DataOverHttps](IMPORTANT): SBD MTMSN=20240214T210824