2023-03-16T20:55:37.716Z,1679000137.716 [Supervisor](DEBUG): Initializing supervisor. 2023-03-16T20:55:37.721Z,1679000137.721 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2023-03-16T20:55:37.721Z,1679000137.721 [SyncHandler](INFO): Protected caller Thread ID is 1053 2023-03-16T20:55:37.722Z,1679000137.722 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2023-03-16T20:55:37.723Z,1679000137.723 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2023-03-16T20:55:37.723Z,1679000137.723 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1054 2023-03-16T20:55:37.727Z,1679000137.727 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2023-03-16T20:55:37.744Z,1679000137.744 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2023-03-16T20:55:37.745Z,1679000137.745 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2023-03-16T20:55:37.745Z,1679000137.745 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 1055 2023-03-16T20:55:37.750Z,1679000137.750 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2023-03-16T20:55:37.751Z,1679000137.751 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2023-03-16T20:55:37.751Z,1679000137.751 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1056 2023-03-16T20:55:37.753Z,1679000137.753 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2023-03-16T20:55:37.754Z,1679000137.754 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2023-03-16T20:55:37.754Z,1679000137.754 [logger ThreadHandler](INFO): Protected caller Thread ID is 1057 2023-03-16T20:55:37.758Z,1679000137.758 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2023-03-16T20:55:37.758Z,1679000137.758 [Supervisor](INFO): Looking for Config files in directory: Config/ 2023-03-16T20:55:37.760Z,1679000137.760 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2023-03-16T20:55:37.855Z,1679000137.855 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2023-03-16T20:55:37.855Z,1679000137.855 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2023-03-16T20:55:38.483Z,1679000138.483 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2023-03-16T20:55:38.483Z,1679000138.483 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2023-03-16T20:55:38.702Z,1679000138.702 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2023-03-16T20:55:38.702Z,1679000138.702 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2023-03-16T20:55:38.779Z,1679000138.779 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2023-03-16T20:55:38.907Z,1679000138.907 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2023-03-16T20:55:38.907Z,1679000138.907 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2023-03-16T20:55:38.987Z,1679000138.987 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2023-03-16T20:55:39.092Z,1679000139.092 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2023-03-16T20:55:39.092Z,1679000139.092 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2023-03-16T20:55:39.464Z,1679000139.464 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2023-03-16T20:55:39.465Z,1679000139.465 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2023-03-16T20:55:39.930Z,1679000139.930 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2023-03-16T20:55:39.931Z,1679000139.931 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2023-03-16T20:55:40.146Z,1679000140.146 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2023-03-16T20:55:40.147Z,1679000140.147 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2023-03-16T20:55:40.326Z,1679000140.326 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2023-03-16T20:55:40.326Z,1679000140.326 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2023-03-16T20:55:40.815Z,1679000140.815 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2023-03-16T20:55:40.816Z,1679000140.816 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2023-03-16T20:55:41.098Z,1679000141.098 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2023-03-16T20:55:41.099Z,1679000141.099 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2023-03-16T20:55:41.307Z,1679000141.307 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2023-03-16T20:55:41.307Z,1679000141.307 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2023-03-16T20:55:41.658Z,1679000141.658 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2023-03-16T20:55:41.659Z,1679000141.659 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2023-03-16T20:55:42.063Z,1679000142.063 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2023-03-16T20:55:42.065Z,1679000142.065 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/ 2023-03-16T20:55:42.066Z,1679000142.066 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg 2023-03-16T20:55:42.216Z,1679000142.216 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg 2023-03-16T20:55:42.794Z,1679000142.794 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg 2023-03-16T20:55:42.908Z,1679000142.908 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg 2023-03-16T20:55:42.992Z,1679000142.992 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg 2023-03-16T20:55:43.084Z,1679000143.084 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg 2023-03-16T20:55:43.259Z,1679000143.259 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg 2023-03-16T20:55:43.518Z,1679000143.518 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2023-03-16T20:55:43.518Z,1679000143.518 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg 2023-03-16T20:55:43.610Z,1679000143.610 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg 2023-03-16T20:55:43.706Z,1679000143.706 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg 2023-03-16T20:55:43.840Z,1679000143.840 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg 2023-03-16T20:55:43.937Z,1679000143.937 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2023-03-16T20:55:43.955Z,1679000143.955 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2023-03-16T20:55:44.052Z,1679000144.052 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2023-03-16T20:55:44.053Z,1679000144.053 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2023-03-16T20:55:44.102Z,1679000144.102 [VerticalControl](DEBUG): Construct VerticalControl. 2023-03-16T20:55:44.163Z,1679000144.163 [VerticalControl] Loaded 2023-03-16T20:55:44.163Z,1679000144.163 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2023-03-16T20:55:44.165Z,1679000144.165 [HorizontalControl](DEBUG): Construct HorizontalControl. 2023-03-16T20:55:44.206Z,1679000144.206 [HorizontalControl] Loaded 2023-03-16T20:55:44.206Z,1679000144.206 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2023-03-16T20:55:44.209Z,1679000144.209 [SpeedControl](DEBUG): Construct SpeedControl. 2023-03-16T20:55:44.212Z,1679000144.212 [SpeedControl] Loaded 2023-03-16T20:55:44.212Z,1679000144.212 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2023-03-16T20:55:44.215Z,1679000144.215 [LoopControl](DEBUG): Construct LoopControl. 2023-03-16T20:55:44.215Z,1679000144.215 [LoopControl] Loaded 2023-03-16T20:55:44.215Z,1679000144.215 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2023-03-16T20:55:44.216Z,1679000144.216 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2023-03-16T20:55:44.216Z,1679000144.216 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2023-03-16T20:55:44.265Z,1679000144.265 [DepthRateCalculator] Loaded 2023-03-16T20:55:44.265Z,1679000144.265 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2023-03-16T20:55:44.270Z,1679000144.270 [PitchRateCalculator] Loaded 2023-03-16T20:55:44.270Z,1679000144.270 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2023-03-16T20:55:44.280Z,1679000144.280 [SpeedCalculator] Loaded 2023-03-16T20:55:44.280Z,1679000144.280 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2023-03-16T20:55:44.284Z,1679000144.284 [YawRateCalculator] Loaded 2023-03-16T20:55:44.284Z,1679000144.284 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2023-03-16T20:55:44.302Z,1679000144.302 [ElevatorOffsetCalculator] Loaded 2023-03-16T20:55:44.303Z,1679000144.303 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2023-03-16T20:55:44.303Z,1679000144.303 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2023-03-16T20:55:44.304Z,1679000144.304 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2023-03-16T20:55:44.329Z,1679000144.329 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2023-03-16T20:55:44.330Z,1679000144.330 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2023-03-16T20:55:44.386Z,1679000144.386 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2023-03-16T20:55:44.386Z,1679000144.386 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2023-03-16T20:55:44.683Z,1679000144.683 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2023-03-16T20:55:44.684Z,1679000144.684 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2023-03-16T20:55:44.832Z,1679000144.832 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2023-03-16T20:55:44.833Z,1679000144.833 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2023-03-16T20:55:45.268Z,1679000145.268 [AHRS_M2] Loaded 2023-03-16T20:55:45.268Z,1679000145.268 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2023-03-16T20:55:45.302Z,1679000145.302 [BackseatComponent] Loaded 2023-03-16T20:55:45.303Z,1679000145.303 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2023-03-16T20:55:45.304Z,1679000145.304 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 409764E0 2023-03-16T20:55:45.304Z,1679000145.304 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 1139 2023-03-16T20:55:45.307Z,1679000145.307 [LcmUniversalReporter] Loaded 2023-03-16T20:55:45.307Z,1679000145.307 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2023-03-16T20:55:46.101Z,1679000146.101 [BPC1] Loaded 2023-03-16T20:55:46.101Z,1679000146.101 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2023-03-16T20:55:46.173Z,1679000146.173 [DataOverHttps] Loaded 2023-03-16T20:55:46.174Z,1679000146.174 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2023-03-16T20:55:46.175Z,1679000146.175 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409A64E0 2023-03-16T20:55:46.175Z,1679000146.175 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1140 2023-03-16T20:55:46.195Z,1679000146.195 [Depth_Keller] Loaded 2023-03-16T20:55:46.196Z,1679000146.196 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2023-03-16T20:55:46.200Z,1679000146.200 [DropWeight] Loaded 2023-03-16T20:55:46.200Z,1679000146.200 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2023-03-16T20:55:46.218Z,1679000146.218 [MultiRay] Loaded 2023-03-16T20:55:46.219Z,1679000146.219 [ComponentRegistry](DEBUG): SyncComponent "MultiRay" handled in the control thread. 2023-03-16T20:55:46.280Z,1679000146.280 [NAL9602] Loaded 2023-03-16T20:55:46.280Z,1679000146.280 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2023-03-16T20:55:46.309Z,1679000146.309 [Onboard] Loaded 2023-03-16T20:55:46.310Z,1679000146.310 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2023-03-16T20:55:46.311Z,1679000146.311 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409D64E0 2023-03-16T20:55:46.311Z,1679000146.311 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 1141 2023-03-16T20:55:46.323Z,1679000146.323 [Power24vConverter] Loaded 2023-03-16T20:55:46.323Z,1679000146.323 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2023-03-16T20:55:46.336Z,1679000146.336 [Radio_Surface] Loaded 2023-03-16T20:55:46.336Z,1679000146.336 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2023-03-16T20:55:46.337Z,1679000146.337 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40A064E0 2023-03-16T20:55:46.338Z,1679000146.338 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1142 2023-03-16T20:55:46.382Z,1679000146.382 [RDI_Pathfinder] Loaded 2023-03-16T20:55:46.382Z,1679000146.382 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread. 2023-03-16T20:55:46.472Z,1679000146.472 [DAT] Loaded 2023-03-16T20:55:46.473Z,1679000146.473 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2023-03-16T20:55:46.474Z,1679000146.474 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40A364E0 2023-03-16T20:55:46.474Z,1679000146.474 [DAT ThreadHandler](INFO): Protected caller Thread ID is 1143 2023-03-16T20:55:46.475Z,1679000146.475 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2023-03-16T20:55:46.475Z,1679000146.475 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2023-03-16T20:55:46.584Z,1679000146.584 [DeadReckonUsingMultipleVelocitySources] Loaded 2023-03-16T20:55:46.584Z,1679000146.584 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2023-03-16T20:55:46.597Z,1679000146.597 [NavChart] Loaded 2023-03-16T20:55:46.598Z,1679000146.598 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2023-03-16T20:55:46.603Z,1679000146.603 [UniversalFixResidualReporter] Loaded 2023-03-16T20:55:46.604Z,1679000146.604 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2023-03-16T20:55:46.604Z,1679000146.604 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2023-03-16T20:55:46.604Z,1679000146.604 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2023-03-16T20:55:46.742Z,1679000146.742 [SBIT](DEBUG): Construct Startup Built In Test. 2023-03-16T20:55:46.751Z,1679000146.751 [SBIT] Loaded 2023-03-16T20:55:46.751Z,1679000146.751 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2023-03-16T20:55:46.754Z,1679000146.754 [IBIT](DEBUG): Construct Initiated Built In Test. 2023-03-16T20:55:46.767Z,1679000146.767 [IBIT] Loaded 2023-03-16T20:55:46.767Z,1679000146.767 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2023-03-16T20:55:46.773Z,1679000146.773 [CBIT](DEBUG): Construct Continuous Built In Test. 2023-03-16T20:55:46.967Z,1679000146.967 [CBIT] Loaded 2023-03-16T20:55:46.967Z,1679000146.967 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2023-03-16T20:55:46.968Z,1679000146.968 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2023-03-16T20:55:46.968Z,1679000146.968 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2023-03-16T20:55:47.224Z,1679000147.224 [BuoyancyServo] Loaded 2023-03-16T20:55:47.225Z,1679000147.225 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2023-03-16T20:55:47.245Z,1679000147.245 [ElevatorServo] Loaded 2023-03-16T20:55:47.245Z,1679000147.245 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2023-03-16T20:55:47.265Z,1679000147.265 [MassServo] Loaded 2023-03-16T20:55:47.265Z,1679000147.265 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2023-03-16T20:55:47.283Z,1679000147.283 [RudderServo] Loaded 2023-03-16T20:55:47.284Z,1679000147.284 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2023-03-16T20:55:47.301Z,1679000147.301 [ThrusterServo] Loaded 2023-03-16T20:55:47.301Z,1679000147.301 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2023-03-16T20:55:47.301Z,1679000147.301 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2023-03-16T20:55:47.302Z,1679000147.302 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2023-03-16T20:55:47.371Z,1679000147.371 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2023-03-16T20:55:47.372Z,1679000147.372 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2023-03-16T20:55:47.733Z,1679000147.733 [CTD_Seabird] Loaded 2023-03-16T20:55:47.733Z,1679000147.733 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2023-03-16T20:55:47.734Z,1679000147.734 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40B7E4E0 2023-03-16T20:55:47.734Z,1679000147.734 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1144 2023-03-16T20:55:47.784Z,1679000147.784 [ESPComponent] Loaded 2023-03-16T20:55:47.785Z,1679000147.785 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2023-03-16T20:55:47.805Z,1679000147.805 [PAR_Licor] Loaded 2023-03-16T20:55:47.805Z,1679000147.805 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2023-03-16T20:55:47.841Z,1679000147.841 [WetLabsBB2FL] Loaded 2023-03-16T20:55:47.841Z,1679000147.841 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2023-03-16T20:55:47.842Z,1679000147.842 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40BAE4E0 2023-03-16T20:55:47.843Z,1679000147.843 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1145 2023-03-16T20:55:47.862Z,1679000147.862 [WetLabsUBAT] Loaded 2023-03-16T20:55:47.862Z,1679000147.862 [ComponentRegistry](DEBUG): Component "WetLabsUBAT" handled in its own thread. 2023-03-16T20:55:47.863Z,1679000147.863 [WetLabsUBAT ThreadHandler](DEBUG): Created PCaller Thread at 40BDE4E0 2023-03-16T20:55:47.864Z,1679000147.864 [WetLabsUBAT ThreadHandler](INFO): Protected caller Thread ID is 1146 2023-03-16T20:55:47.864Z,1679000147.864 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2023-03-16T20:55:47.871Z,1679000147.871 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2023-03-16T20:55:47.873Z,1679000147.873 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2023-03-16T20:55:47.885Z,1679000147.885 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2023-03-16T20:55:47.885Z,1679000147.885 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C0E4E0 2023-03-16T20:55:47.886Z,1679000147.886 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1147 2023-03-16T20:55:47.890Z,1679000147.890 [Supervisor](INFO): Main Thread ID is 830 2023-03-16T20:55:47.890Z,1679000147.890 [Supervisor](DEBUG): Running supervisor. 2023-03-16T20:55:47.891Z,1679000147.891 [CommandExec ThreadHandler](INFO): Handler Thread ID is 1148 2023-03-16T20:55:47.891Z,1679000147.891 [CommandExec](INFO): Initializing the command executive. 2023-03-16T20:55:47.893Z,1679000147.893 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1149 2023-03-16T20:55:47.895Z,1679000147.895 [controlThread ThreadHandler](INFO): Handler Thread ID is 1150 2023-03-16T20:55:47.895Z,1679000147.895 [controlThread](DEBUG): Initializing ControlThread 2023-03-16T20:55:47.896Z,1679000147.896 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2023-03-16T20:55:47.898Z,1679000147.898 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2023-03-16T20:55:47.899Z,1679000147.899 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2023-03-16T20:55:47.899Z,1679000147.899 [LoopControl](DEBUG): Initialize LoopControlComponent. 2023-03-16T20:55:47.900Z,1679000147.900 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2023-03-16T20:55:47.900Z,1679000147.900 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2023-03-16T20:55:47.900Z,1679000147.900 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2023-03-16T20:55:47.901Z,1679000147.901 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2023-03-16T20:55:47.901Z,1679000147.901 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2023-03-16T20:55:47.905Z,1679000147.905 [NavChart](DEBUG): Initialize NavChart Navigation. 2023-03-16T20:55:47.906Z,1679000147.906 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2023-03-16T20:55:47.906Z,1679000147.906 [SBIT](INFO): Initialize SBIT Component. 2023-03-16T20:55:47.906Z,1679000147.906 [SBIT](IMPORTANT): git: 2023-03-15_B 2023-03-16T20:55:47.907Z,1679000147.907 [SBIT](INFO): git hash: 87a6ff4eaeacdea4d9575019210216310db4326f 2023-03-16T20:55:47.907Z,1679000147.907 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2023-03-16T20:55:47.908Z,1679000147.908 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019 Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021 2023-03-16T20:55:47.909Z,1679000147.909 [SBIT](INFO): Beginning SBIT in 52.000000 seconds. 2023-03-16T20:55:47.910Z,1679000147.910 [IBIT](INFO): Initialize IBIT Component. 2023-03-16T20:55:47.911Z,1679000147.911 [CBIT](DEBUG): Initialize CBIT Component. 2023-03-16T20:55:47.912Z,1679000147.912 [logger ThreadHandler](INFO): Handler Thread ID is 1151 2023-03-16T20:55:47.923Z,1679000147.923 [CBIT](DEBUG): Initialized mux pins. 2023-03-16T20:55:47.923Z,1679000147.923 [CBIT](DEBUG): Initializing the watchdog timer. 2023-03-16T20:55:47.931Z,1679000147.931 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 1152 2023-03-16T20:55:47.943Z,1679000147.943 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1153 2023-03-16T20:55:47.944Z,1679000147.944 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2023-03-16T20:55:47.947Z,1679000147.947 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2023-03-16T20:55:47.947Z,1679000147.947 [CBIT](DEBUG): Initializing heartbeat. 2023-03-16T20:55:47.955Z,1679000147.955 [Onboard ThreadHandler](INFO): Handler Thread ID is 1154 2023-03-16T20:55:47.972Z,1679000147.972 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1155 2023-03-16T20:55:47.991Z,1679000147.991 [DAT ThreadHandler](INFO): Handler Thread ID is 1156 2023-03-16T20:55:47.992Z,1679000147.992 [DAT](INFO): Powering up 2023-03-16T20:55:47.992Z,1679000147.992 [DAT](DEBUG): Initializing DAT. 2023-03-16T20:55:47.996Z,1679000147.996 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1158 2023-03-16T20:55:47.997Z,1679000147.997 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2023-03-16T20:55:47.000Z,1679000148.000 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1160 2023-03-16T20:55:48.003Z,1679000148.003 [WetLabsBB2FL](INFO): Powering up 2023-03-16T20:55:48.004Z,1679000148.004 [WetLabsUBAT ThreadHandler](INFO): Handler Thread ID is 1162 2023-03-16T20:55:48.007Z,1679000148.007 [WetLabsUBAT](INFO): Powering up 2023-03-16T20:55:48.008Z,1679000148.008 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1164 2023-03-16T20:55:48.012Z,1679000148.012 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2023-03-16T20:55:48.012Z,1679000148.012 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2023-03-16T20:55:48.012Z,1679000148.012 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2023-03-16T20:55:48.012Z,1679000148.012 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2023-03-16T20:55:48.012Z,1679000148.012 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2023-03-16T20:55:48.013Z,1679000148.013 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2023-03-16T20:55:48.013Z,1679000148.013 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2023-03-16T20:55:48.013Z,1679000148.013 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2023-03-16T20:55:48.019Z,1679000148.019 [CBIT](DEBUG): Deactivating GF circuits. 2023-03-16T20:55:48.019Z,1679000148.019 [CBIT](DEBUG): Deactivating emergency mode. 2023-03-16T20:55:48.059Z,1679000148.059 [CBIT](DEBUG): Backplane powered. 2023-03-16T20:55:48.064Z,1679000148.064 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml 2023-03-16T20:55:48.088Z,1679000148.088 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2023-03-16T20:55:48.116Z,1679000148.116 [MissionManager](DEBUG): 2023-03-16T20:55:48.117Z,1679000148.117 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml 2023-03-16T20:55:48.203Z,1679000148.203 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2023-03-16T20:55:48.205Z,1679000148.205 [Default:A.Wait](DEBUG): Construct Wait. 2023-03-16T20:55:48.207Z,1679000148.207 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2023-03-16T20:55:48.254Z,1679000148.254 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2023-03-16T20:55:48.257Z,1679000148.257 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2023-03-16T20:55:48.287Z,1679000148.287 [Default:E.Execute](DEBUG): Construct Execute. 2023-03-16T20:55:48.290Z,1679000148.290 [MissionManager](DEBUG): 0 Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. 13 Burn on Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2023-03-16T20:55:48.311Z,1679000148.311 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,MultiRay,NAL9602,Power24vConverter,RDI_Pathfinder,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter, 2023-03-16T20:55:48.317Z,1679000148.317 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2023-03-16T20:55:48.379Z,1679000148.379 [Radio_Surface](INFO): Powering up 2023-03-16T20:55:48.391Z,1679000148.391 [Depth_Keller](ERROR): Pressure reading out of range: 824.648376 decibar 2023-03-16T20:55:48.392Z,1679000148.392 [MultiRay](INFO): Powering up MultiRay Lights 2023-03-16T20:55:48.427Z,1679000148.427 [Power24vConverter](INFO): Powering up. 2023-03-16T20:55:48.428Z,1679000148.428 [RDI_Pathfinder](IMPORTANT): Expecting PD13 message format 2023-03-16T20:55:48.483Z,1679000148.483 [DepthRateCalculator](ERROR): Depth measurement is not active 2023-03-16T20:55:48.497Z,1679000148.497 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2023-03-16T20:55:48.507Z,1679000148.507 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2023-03-16T20:55:48.508Z,1679000148.508 [ElevatorServo](DEBUG): Initializing EZServoServo. 2023-03-16T20:55:48.515Z,1679000148.515 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2023-03-16T20:55:48.516Z,1679000148.516 [MassServo](DEBUG): Initializing EZServoServo. 2023-03-16T20:55:48.523Z,1679000148.523 [MassServo](DEBUG): Initializing MassServo. 2023-03-16T20:55:48.524Z,1679000148.524 [RudderServo](DEBUG): Initializing EZServoServo. 2023-03-16T20:55:48.531Z,1679000148.531 [RudderServo](DEBUG): Initializing RudderServo. 2023-03-16T20:55:48.532Z,1679000148.532 [ThrusterServo](DEBUG): Initializing EZServoServo. 2023-03-16T20:55:48.539Z,1679000148.539 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2023-03-16T20:55:49.475Z,1679000149.475 [RudderServo](ERROR): Rudder initialization uart error serial timeout 2023-03-16T20:55:49.475Z,1679000149.475 [RudderServo](FAULT): Rudder failed to initialize 2023-03-16T20:55:49.475Z,1679000149.475 [RudderServo] Communications Fault, FailCount= 1 2023-03-16T20:55:49.475Z,1679000149.475 [RudderServo](ERROR): Communications Fault 2023-03-16T20:55:49.575Z,1679000149.575 [CBIT](ERROR): Communications Fault in component: RudderServo 2023-03-16T20:55:49.864Z,1679000149.864 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2023-03-16T20:55:49.864Z,1679000149.864 [RudderServo](INFO): Powering down 2023-03-16T20:55:50.410Z,1679000150.410 [RudderServo](DEBUG): Initializing EZServoServo. 2023-03-16T20:55:50.531Z,1679000150.531 [RudderServo](DEBUG): Initializing RudderServo. 2023-03-16T20:55:50.536Z,1679000150.536 [CBIT](INFO): Clearing failed state for component RudderServo 2023-03-16T20:55:50.536Z,1679000150.536 [RudderServo] No Fault, FailCount= 1 2023-03-16T20:55:50.615Z,1679000150.615 [WetLabsBB2FL](INFO): Powering down 2023-03-16T20:55:55.027Z,1679000155.027 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit. 2023-03-16T20:56:00.087Z,1679000160.087 [DAT](INFO): DAT read: 2023-03-16T20:56:00.089Z,1679000160.089 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2023-03-16T20:56:01.603Z,1679000161.603 [DAT](INFO): DAT read: MF Frequency Band 2023-03-16T20:56:01.604Z,1679000161.604 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2023-03-16T20:56:01.605Z,1679000161.605 [DAT](INFO): DAT read: Mar 16 2023 20:55:56 2023-03-16T20:56:02.608Z,1679000162.608 [DAT](INFO): DAT read: Features enabled [Bearing] 2023-03-16T20:56:02.609Z,1679000162.609 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP 2023-03-16T20:56:02.609Z,1679000162.609 [DAT](INFO): commRate: 800 2023-03-16T20:56:04.675Z,1679000164.675 [DAT](INFO): entering command mode 2023-03-16T20:56:04.875Z,1679000164.875 [DAT](INFO): DAT read: 2023-03-16T20:56:04.876Z,1679000164.876 [DAT](INFO): DAT read: user:1> 2023-03-16T20:56:04.876Z,1679000164.876 [DAT](INFO): setting verbose to 3 2023-03-16T20:56:05.127Z,1679000165.127 [DAT](INFO): DAT read: user:1> 2023-03-16T20:56:05.128Z,1679000165.128 [DAT](INFO): DAT read: Verbose | 3 2023-03-16T20:56:05.129Z,1679000165.129 [DAT](INFO): set verbose to 3 2023-03-16T20:56:05.129Z,1679000165.129 [DAT](INFO): setting DatVerbose to 27440 2023-03-16T20:56:05.379Z,1679000165.379 [DAT](INFO): DAT read: user:2> 2023-03-16T20:56:05.380Z,1679000165.380 [DAT](INFO): DAT read: DatVerbose | 27440 2023-03-16T20:56:05.381Z,1679000165.381 [DAT](INFO): set DatVerbose to 27440 2023-03-16T20:56:05.381Z,1679000165.381 [DAT](INFO): setting transmit power to 8 2023-03-16T20:56:05.631Z,1679000165.631 [DAT](INFO): DAT read: user:3> 2023-03-16T20:56:05.632Z,1679000165.632 [DAT](INFO): DAT read: TxPower | 8 (Max) 2023-03-16T20:56:05.632Z,1679000165.632 [DAT](INFO): set transmit power to 8 2023-03-16T20:56:05.633Z,1679000165.633 [DAT](INFO): setting local address to 9 2023-03-16T20:56:05.883Z,1679000165.883 [DAT](INFO): DAT read: user:4> 2023-03-16T20:56:05.884Z,1679000165.884 [DAT](INFO): DAT read: LocalAddr | 9 2023-03-16T20:56:05.885Z,1679000165.885 [DAT](INFO): set local address to 9 2023-03-16T20:56:05.886Z,1679000165.886 [DAT](INFO): Setting time to: 20:56:5 And date to:3/16/2023 2023-03-16T20:56:06.135Z,1679000166.135 [DAT](INFO): DAT read: user:5> 2023-03-16T20:56:06.136Z,1679000166.136 [DAT](INFO): DAT read: Thu Mar 16, 2023 20:56:05 2023-03-16T20:56:06.136Z,1679000166.136 [DAT](INFO): Local DAT time set to Thu Mar 16, 2023 20:56:05 2023-03-16T20:56:16.657Z,1679000176.657 [NAL9602](INFO): Powering up NAL9602 2023-03-16T20:56:18.155Z,1679000178.155 [WetLabsUBAT](FAULT): Failed to acquire valid data within specified timeout upon startup. 2023-03-16T20:56:18.155Z,1679000178.155 [WetLabsUBAT] Communications Fault, FailCount= 1 2023-03-16T20:56:18.155Z,1679000178.155 [WetLabsUBAT](ERROR): Communications Fault 2023-03-16T20:56:18.363Z,1679000178.363 [CBIT](ERROR): Communications Fault in component: WetLabsUBAT 2023-03-16T20:56:18.679Z,1679000178.679 [WetLabsUBAT](INFO): Powering down 2023-03-16T20:56:19.533Z,1679000179.533 [CBIT](INFO): Clearing failed state for component WetLabsUBAT 2023-03-16T20:56:19.533Z,1679000179.533 [WetLabsUBAT] No Fault, FailCount= 1 2023-03-16T20:56:19.892Z,1679000179.892 [WetLabsUBAT](INFO): Powering up 2023-03-16T20:56:27.564Z,1679000187.564 [NAL9602](INFO): NAL9602 initialized 2023-03-16T20:56:29.139Z,1679000189.139 [WetLabsUBAT](INFO): Powering down 2023-03-16T20:56:40.524Z,1679000200.524 [SBIT](IMPORTANT): Beginning Startup BIT 2023-03-16T20:56:40.528Z,1679000200.528 [CBIT](IMPORTANT): Beginning ground fault scan 2023-03-16T20:56:42.926Z,1679000202.926 [NAL9602](INFO): SBD MO Status=0, MOMSN=22608, MT Status=0, MTMSN=0 2023-03-16T20:56:42.926Z,1679000202.926 [NAL9602](INFO): No messages in MT queue 2023-03-16T20:56:51.452Z,1679000211.452 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.010458 CHAN A1 (24V): 0.001098 CHAN A2 (12V): -0.006855 CHAN A3 (5V): -0.001498 CHAN B0 (3.3V): 0.000131 CHAN B1 (3.15aV): -0.000358 CHAN B2 (3.15bV): 0.000684 CHAN B3 (GND): 0.002319 OPEN: 0.005209 Full Scale: +/- 1 mA 2023-03-16T20:56:55.859Z,1679000215.859 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205654.00,A,3648.17683,N,12147.27815,W,0.039,0.00,160323,,,A*79 2023-03-16T20:56:55.862Z,1679000215.862 [NAL9602](INFO): GPS fix at 20230316T205654: (36.802947, -121.787969) 2023-03-16T20:57:28.177Z,1679000248.177 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-16T20:57:34.269Z,1679000254.269 [SBIT](IMPORTANT): SBIT PASSED 2023-03-16T20:57:34.269Z,1679000254.269 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2023-03-16T20:57:34.271Z,1679000254.271 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count; 2023-03-16T20:57:34.271Z,1679000254.271 [SBIT](IMPORTANT): CBIT.gf24Offset=143 microampere; 2023-03-16T20:57:34.271Z,1679000254.271 [SBIT](IMPORTANT): DAT.baud=115200 bit_per_second; 2023-03-16T20:57:34.271Z,1679000254.271 [SBIT](IMPORTANT): DAT.loadAtStartup=1 bool; 2023-03-16T20:57:34.271Z,1679000254.271 [SBIT](IMPORTANT): DAT.surfaceThreshold=0 meter; 2023-03-16T20:57:34.271Z,1679000254.271 [SBIT](IMPORTANT): DAT.verbosity=2 count; 2023-03-16T20:57:34.271Z,1679000254.271 [SBIT](IMPORTANT): ESPComponent.loadAtStartup=1 bool; 2023-03-16T20:57:34.271Z,1679000254.271 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=10 minute; 2023-03-16T20:57:34.272Z,1679000254.272 [SBIT](IMPORTANT): ESPComponent.simulateHardware=1 bool; 2023-03-16T20:57:34.272Z,1679000254.272 [SBIT](IMPORTANT): Express linearApproximation WetLabsUBAT.flow_rate 0.300000 liter_per_second; 2023-03-16T20:57:34.272Z,1679000254.272 [SBIT](IMPORTANT): Express none _.adinos; 2023-03-16T20:57:34.272Z,1679000254.272 [SBIT](IMPORTANT): Express none _.aother; 2023-03-16T20:57:34.272Z,1679000254.272 [SBIT](IMPORTANT): Express linearApproximation _.dinoflagellates 10000000000.000000 none; 2023-03-16T20:57:34.272Z,1679000254.272 [SBIT](IMPORTANT): Express linearApproximation _.jellies 99999997952.000000 none; 2023-03-16T20:57:34.272Z,1679000254.272 [SBIT](IMPORTANT): Express none _.larvaceans; 2023-03-16T20:57:34.272Z,1679000254.272 [SBIT](IMPORTANT): IBIT.batteryCapacityThreshold=24 ampere_hour; 2023-03-16T20:57:34.272Z,1679000254.272 [SBIT](IMPORTANT): IBIT.batteryVoltageThreshold=13 volt; 2023-03-16T20:57:34.273Z,1679000254.273 [SBIT](IMPORTANT): Power24vConverter.simulateHardware=0 bool; 2023-03-16T20:57:34.273Z,1679000254.273 [SBIT](IMPORTANT): RDI_Pathfinder.loadAtStartup=1 bool; 2023-03-16T20:57:34.273Z,1679000254.273 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=283.590738 cubic_centimeter; 2023-03-16T20:57:34.273Z,1679000254.273 [SBIT](IMPORTANT): VerticalControl.massDefault=0.8 centimeter; 2023-03-16T20:57:34.651Z,1679000254.651 [MissionManager](IMPORTANT): Started mission Startup 2023-03-16T20:57:34.652Z,1679000254.652 [Startup] Running Loop=1 2023-03-16T20:57:34.652Z,1679000254.652 [Startup](DEBUG): Aggregate::initialize Startup 2023-03-16T20:57:34.652Z,1679000254.652 [Startup:A.GoToSurface] Running Loop=1 2023-03-16T20:57:34.652Z,1679000254.652 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2023-03-16T20:57:34.653Z,1679000254.653 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2023-03-16T20:57:34.653Z,1679000254.653 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2023-03-16T20:57:34.653Z,1679000254.653 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2023-03-16T20:57:34.654Z,1679000254.654 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2023-03-16T20:57:34.654Z,1679000254.654 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2023-03-16T20:57:34.676Z,1679000254.676 [Startup:StartupSatComms] Running Loop=1 2023-03-16T20:57:34.676Z,1679000254.676 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2023-03-16T20:57:34.676Z,1679000254.676 [Startup:StartupSatComms:A] Running Loop=1 2023-03-16T20:57:35.111Z,1679000255.111 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2023-03-16T20:57:36.718Z,1679000256.718 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205734.00,A,3648.17489,N,12147.27925,W,0.175,0.00,160323,,,A*7D 2023-03-16T20:57:36.720Z,1679000256.720 [NAL9602](INFO): GPS fix at 20230316T205734: (36.802915, -121.787987) 2023-03-16T20:57:36.731Z,1679000256.731 [Startup:StartupSatComms:A] Stopped 2023-03-16T20:57:36.731Z,1679000256.731 [Startup:StartupSatComms:B] Running Loop=1 2023-03-16T20:57:37.104Z,1679000257.104 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2023-03-16T20:57:51.681Z,1679000271.681 [NAL9602](INFO): SBD MO Status=1, MOMSN=22609, MT Status=0, MTMSN=0 2023-03-16T20:57:51.735Z,1679000271.735 [NAL9602](INFO): Sent 39 bytes from file Logs/20230316T202312/Courier0019.lzma 2023-03-16T20:57:51.735Z,1679000271.735 [NAL9602](INFO): Packets left to send: 0 2023-03-16T20:58:09.997Z,1679000289.997 [NAL9602](INFO): SBD MO Status=2, MOMSN=22610, MT Status=2, MTMSN=0 2023-03-16T20:58:09.997Z,1679000289.997 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-16T20:58:12.018Z,1679000292.018 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2023-03-16T20:58:31.905Z,1679000311.905 [NAL9602](INFO): SBD MO Status=2, MOMSN=22610, MT Status=2, MTMSN=0 2023-03-16T20:58:31.905Z,1679000311.905 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-16T20:58:36.875Z,1679000316.875 [Startup:StartupSatComms:B](INFO): Timed out from 2023-03-16T20:57:36.7Z 2023-03-16T20:58:36.875Z,1679000316.875 [Startup:StartupSatComms:B] Stopped 2023-03-16T20:58:36.875Z,1679000316.875 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2023-03-16T20:58:36.875Z,1679000316.875 [Startup:StartupSatComms] Stopped 2023-03-16T20:58:36.875Z,1679000316.875 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2023-03-16T20:58:36.876Z,1679000316.876 [Startup](INFO): Completed Startup 2023-03-16T20:58:36.876Z,1679000316.876 [MissionManager](INFO): Startup is completed. 2023-03-16T20:58:36.876Z,1679000316.876 [MissionManager](INFO): Uninitializing Mission Startup 2023-03-16T20:58:36.876Z,1679000316.876 [Startup] Stopped 2023-03-16T20:58:36.876Z,1679000316.876 [Startup](DEBUG): Aggregate::uninitialize Startup 2023-03-16T20:58:36.877Z,1679000316.877 [Startup:A.GoToSurface] Stopped 2023-03-16T20:58:36.877Z,1679000316.877 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2023-03-16T20:58:37.138Z,1679000317.138 [MissionManager](IMPORTANT): Started mission Default 2023-03-16T20:58:37.139Z,1679000317.139 [Default] Running Loop=1 2023-03-16T20:58:37.139Z,1679000317.139 [Default](DEBUG): Aggregate::initialize Default 2023-03-16T20:58:37.139Z,1679000317.139 [Default:B.GoToSurface] Running Loop=1 2023-03-16T20:58:37.139Z,1679000317.139 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2023-03-16T20:58:37.140Z,1679000317.140 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2023-03-16T20:58:37.140Z,1679000317.140 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2023-03-16T20:58:37.140Z,1679000317.140 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2023-03-16T20:58:37.141Z,1679000317.141 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2023-03-16T20:58:37.141Z,1679000317.141 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2023-03-16T20:58:37.141Z,1679000317.141 [Default:A.Wait] Running Loop=1 2023-03-16T20:58:37.141Z,1679000317.141 [Default:A.Wait](DEBUG): Initialize Wait Component. 2023-03-16T20:58:50.474Z,1679000330.474 [Default:A.Wait](INFO): Done Waiting. 2023-03-16T20:58:50.474Z,1679000330.474 [Default:A.Wait] Stopped 2023-03-16T20:58:50.474Z,1679000330.474 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2023-03-16T20:58:50.871Z,1679000330.871 [Default:CheckIn] Running Loop=1 2023-03-16T20:58:50.872Z,1679000330.872 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-16T20:58:50.872Z,1679000330.872 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-16T20:58:51.270Z,1679000331.270 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2023-03-16T20:58:52.882Z,1679000332.882 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205851.00,A,3648.17168,N,12147.28163,W,0.097,0.00,160323,,,A*73 2023-03-16T20:58:52.884Z,1679000332.884 [NAL9602](INFO): GPS fix at 20230316T205851: (36.802861, -121.788027) 2023-03-16T20:58:52.895Z,1679000332.895 [Default:CheckIn:Read_GPS] Stopped 2023-03-16T20:58:52.895Z,1679000332.895 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-16T20:58:53.316Z,1679000333.316 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2023-03-16T20:59:11.697Z,1679000351.697 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004499 2023-03-16T20:59:17.998Z,1679000357.998 [NAL9602](INFO): SBD MO Status=2, MOMSN=22610, MT Status=2, MTMSN=0 2023-03-16T20:59:17.998Z,1679000357.998 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-16T20:59:19.482Z,1679000359.482 [DataOverHttps](INFO): Sending 268 bytes from file Logs/20230316T205537/Courier0000.lzma 2023-03-16T20:59:20.484Z,1679000360.484 [DataOverHttps](INFO): Moved sent file to Logs/20230316T205537/Courier0000.lzma.bak 2023-03-16T20:59:20.485Z,1679000360.485 [DataOverHttps](INFO): SBD MOMSN=17521676 2023-03-16T20:59:37.042Z,1679000377.042 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230316T205537/Courier0004.lzma 2023-03-16T20:59:38.044Z,1679000378.044 [DataOverHttps](INFO): Moved sent file to Logs/20230316T205537/Courier0004.lzma.bak 2023-03-16T20:59:38.045Z,1679000378.045 [DataOverHttps](INFO): SBD MOMSN=17521680 2023-03-16T20:59:48.698Z,1679000388.698 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-16T20:59:58.070Z,1679000398.070 [DataOverHttps](INFO): Sending 174 bytes from file Logs/20230316T202312/Express0020.lzma 2023-03-16T20:59:59.072Z,1679000399.072 [DataOverHttps](INFO): Moved sent file to Logs/20230316T202312/Express0020.lzma.bak 2023-03-16T20:59:59.073Z,1679000399.073 [DataOverHttps](INFO): SBD MOMSN=17521692 2023-03-16T21:00:20.797Z,1679000420.797 [DataOverHttps](INFO): Sending 1189 bytes from file Logs/20230316T205537/Express0001.lzma 2023-03-16T21:00:21.797Z,1679000421.797 [DataOverHttps](INFO): Moved sent file to Logs/20230316T205537/Express0001.lzma.bak 2023-03-16T21:00:21.797Z,1679000421.797 [DataOverHttps](INFO): SBD MOMSN=17521802 2023-03-16T21:00:38.725Z,1679000438.725 [DataOverHttps](INFO): Sending 224 bytes from file Logs/20230316T205537/Express0005.lzma 2023-03-16T21:00:39.721Z,1679000439.721 [DataOverHttps](INFO): Moved sent file to Logs/20230316T205537/Express0005.lzma.bak 2023-03-16T21:00:39.721Z,1679000439.721 [DataOverHttps](INFO): SBD MOMSN=17521839 2023-03-16T21:00:41.201Z,1679000441.201 [Default:CheckIn:Read_Iridium] Stopped 2023-03-16T21:00:41.201Z,1679000441.201 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-16T21:00:41.201Z,1679000441.201 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-16T21:03:13.504Z,1679000593.504 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2023-03-16T21:03:13.507Z,1679000593.507 [BPC1](INFO): Received data from all battery sticks. 2023-03-16T21:03:18.218Z,1679000598.218 [CommandExec](IMPORTANT): got command failComponent 2023-03-16T21:03:18.219Z,1679000598.219 [CommandExec](IMPORTANT): Failed components: 2023-03-16T21:03:18.219Z,1679000598.219 [CommandExec](IMPORTANT): No failed Components. 2023-03-16T21:05:41.807Z,1679000741.807 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-16T21:05:41.807Z,1679000741.807 [Default:CheckIn:C.Wait] Stopped 2023-03-16T21:05:41.807Z,1679000741.807 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-16T21:05:41.807Z,1679000741.807 [Default:CheckIn:D] Running Loop=1 2023-03-16T21:05:42.231Z,1679000742.231 [Default:CheckIn:D] Stopped 2023-03-16T21:05:42.231Z,1679000742.231 [Default:CheckIn:E] Running Loop=1 2023-03-16T21:05:42.627Z,1679000742.627 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 7.084864 min 2023-03-16T21:05:42.627Z,1679000742.627 [Default:CheckIn:E] Stopped 2023-03-16T21:05:42.627Z,1679000742.627 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-16T21:05:42.627Z,1679000742.627 [Default:CheckIn] Stopped 2023-03-16T21:05:42.627Z,1679000742.627 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-16T21:05:42.628Z,1679000742.628 [Default:CheckIn](INFO): Running loop #2 2023-03-16T21:05:42.628Z,1679000742.628 [Default:CheckIn] Running Loop=2 2023-03-16T21:05:42.628Z,1679000742.628 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-16T21:05:42.628Z,1679000742.628 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-16T21:05:44.630Z,1679000744.630 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210543.00,A,3648.17284,N,12147.28040,W,0.097,320.49,160323,,,A*74 2023-03-16T21:05:44.633Z,1679000744.633 [NAL9602](INFO): GPS fix at 20230316T210543: (36.802881, -121.788007) 2023-03-16T21:05:44.669Z,1679000744.669 [Default:CheckIn:Read_GPS] Stopped 2023-03-16T21:05:44.669Z,1679000744.669 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-16T21:05:51.961Z,1679000751.961 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20230316T205537/Courier0007.lzma 2023-03-16T21:05:52.957Z,1679000752.957 [DataOverHttps](INFO): Moved sent file to Logs/20230316T205537/Courier0007.lzma.bak 2023-03-16T21:05:52.957Z,1679000752.957 [DataOverHttps](INFO): SBD MOMSN=17521842 2023-03-16T21:06:02.886Z,1679000762.886 [NAL9602](INFO): SBD MO Status=1, MOMSN=22610, MT Status=0, MTMSN=0 2023-03-16T21:06:02.886Z,1679000762.886 [NAL9602](INFO): No messages in MT queue 2023-03-16T21:06:09.255Z,1679000769.255 [DataOverHttps](INFO): Sending 228 bytes from file Logs/20230316T205537/Express0008.lzma 2023-03-16T21:06:10.258Z,1679000770.258 [DataOverHttps](INFO): Moved sent file to Logs/20230316T205537/Express0008.lzma.bak 2023-03-16T21:06:10.259Z,1679000770.259 [DataOverHttps](IMPORTANT): SBD MOMSN=17521846, MTMSN=20230316T210609 2023-03-16T21:06:11.784Z,1679000771.784 [Default:CheckIn:Read_Iridium] Stopped 2023-03-16T21:06:11.784Z,1679000771.784 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-16T21:06:11.784Z,1679000771.784 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-16T21:06:18.912Z,1679000778.912 [CommandExec](IMPORTANT): got command burn on 2023-03-16T21:06:18.912Z,1679000778.912 [CommandExec](IMPORTANT): Activating dropweight wire 2023-03-16T21:06:21.361Z,1679000781.361 [DataOverHttps](INFO): Received command: ibit 2023-03-16T21:06:21.364Z,1679000781.364 [CommandExec](IMPORTANT): got command ibit 2023-03-16T21:06:21.562Z,1679000781.562 [IBIT](IMPORTANT): Beginning Initiated BIT 2023-03-16T21:06:21.562Z,1679000781.562 [IBIT](IMPORTANT): Beginning control surface checks. 2023-03-16T21:06:21.574Z,1679000781.574 [CBIT](IMPORTANT): Beginning ground fault scan 2023-03-16T21:06:23.151Z,1679000783.151 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210622.00,A,3648.17650,N,12147.28035,W,0.097,320.49,160323,,,A*7F 2023-03-16T21:06:23.153Z,1679000783.153 [NAL9602](INFO): GPS fix at 20230316T210622: (36.802942, -121.788006) 2023-03-16T21:06:25.987Z,1679000785.987 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210625.00,A,3648.17682,N,12147.28028,W,0.019,320.49,160323,,,A*7D 2023-03-16T21:06:25.989Z,1679000785.989 [NAL9602](INFO): GPS fix at 20230316T210625: (36.802947, -121.788005) 2023-03-16T21:06:28.830Z,1679000788.830 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210628.00,A,3648.17698,N,12147.28025,W,0.350,320.49,160323,,,A*78 2023-03-16T21:06:28.833Z,1679000788.833 [NAL9602](INFO): GPS fix at 20230316T210628: (36.802950, -121.788004) 2023-03-16T21:06:32.077Z,1679000792.077 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210631.00,A,3648.17713,N,12147.28009,W,0.272,320.49,160323,,,A*7D 2023-03-16T21:06:32.079Z,1679000792.079 [NAL9602](INFO): GPS fix at 20230316T210631: (36.802952, -121.788002) 2023-03-16T21:06:32.894Z,1679000792.894 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.010049 CHAN A1 (24V): 0.001016 CHAN A2 (12V): -0.006423 CHAN A3 (5V): -0.002098 CHAN B0 (3.3V): 0.000573 CHAN B1 (3.15aV): -0.000290 CHAN B2 (3.15bV): -0.000189 CHAN B3 (GND): 0.001927 OPEN: 0.005505 Full Scale: +/- 1 mA 2023-03-16T21:06:34.874Z,1679000794.874 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210634.00,A,3648.17716,N,12147.28007,W,0.214,320.49,160323,,,A*73 2023-03-16T21:06:34.876Z,1679000794.876 [NAL9602](INFO): GPS fix at 20230316T210634: (36.802953, -121.788001) 2023-03-16T21:06:37.702Z,1679000797.702 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210637.00,A,3648.17726,N,12147.28003,W,0.194,320.49,160323,,,A*7C 2023-03-16T21:06:37.704Z,1679000797.704 [NAL9602](INFO): GPS fix at 20230316T210637: (36.802954, -121.788000) 2023-03-16T21:06:40.933Z,1679000800.933 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210640.00,A,3648.17726,N,12147.27986,W,0.039,320.49,160323,,,A*71 2023-03-16T21:06:40.936Z,1679000800.936 [NAL9602](INFO): GPS fix at 20230316T210640: (36.802954, -121.787998) 2023-03-16T21:06:43.783Z,1679000803.783 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210643.00,A,3648.17726,N,12147.27987,W,0.117,320.49,160323,,,A*7E 2023-03-16T21:06:43.785Z,1679000803.785 [NAL9602](INFO): GPS fix at 20230316T210643: (36.802954, -121.787998) 2023-03-16T21:06:46.998Z,1679000806.998 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210646.00,A,3648.17717,N,12147.27990,W,0.194,320.49,160323,,,A*74 2023-03-16T21:06:47.001Z,1679000807.001 [NAL9602](INFO): GPS fix at 20230316T210646: (36.802953, -121.787998) 2023-03-16T21:06:49.823Z,1679000809.823 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210649.00,A,3648.17705,N,12147.27973,W,0.078,320.49,160323,,,A*76 2023-03-16T21:06:49.830Z,1679000809.830 [NAL9602](INFO): GPS fix at 20230316T210649: (36.802951, -121.787995) 2023-03-16T21:06:53.054Z,1679000813.054 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210652.00,A,3648.17701,N,12147.27961,W,0.097,320.49,160323,,,A*7A 2023-03-16T21:06:53.056Z,1679000813.056 [NAL9602](INFO): GPS fix at 20230316T210652: (36.802950, -121.787993) 2023-03-16T21:06:55.892Z,1679000815.892 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210655.00,A,3648.17689,N,12147.27948,W,0.156,320.49,160323,,,A*7B 2023-03-16T21:06:55.899Z,1679000815.899 [NAL9602](INFO): GPS fix at 20230316T210655: (36.802948, -121.787991) 2023-03-16T21:06:58.711Z,1679000818.711 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210658.00,A,3648.17681,N,12147.27939,W,0.039,320.49,160323,,,A*70 2023-03-16T21:06:58.713Z,1679000818.713 [NAL9602](INFO): GPS fix at 20230316T210658: (36.802947, -121.787990) 2023-03-16T21:07:01.962Z,1679000821.962 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210701.00,A,3648.17675,N,12147.27942,W,0.097,320.49,160323,,,A*7E 2023-03-16T21:07:01.965Z,1679000821.965 [NAL9602](INFO): GPS fix at 20230316T210701: (36.802946, -121.787990) 2023-03-16T21:07:04.780Z,1679000824.780 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210704.00,A,3648.17674,N,12147.27945,W,0.467,320.49,160323,,,A*76 2023-03-16T21:07:04.782Z,1679000824.782 [NAL9602](INFO): GPS fix at 20230316T210704: (36.802946, -121.787991) 2023-03-16T21:07:08.014Z,1679000828.014 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210707.00,A,3648.17651,N,12147.27946,W,0.019,320.49,160323,,,A*7C 2023-03-16T21:07:08.016Z,1679000828.016 [NAL9602](INFO): GPS fix at 20230316T210707: (36.802942, -121.787991) 2023-03-16T21:07:08.053Z,1679000828.053 [IBIT](IMPORTANT): Communications Status: Fix Status: 1 Iridium Signal Strength: 5 Latitude: 36.802940 Longitude: -121.787994 2023-03-16T21:07:08.450Z,1679000828.450 [IBIT](IMPORTANT): Battery Status: Battery Charge (AH): 0.000000 Voltage: 15.779000 2023-03-16T21:07:08.450Z,1679000828.450 [IBIT](IMPORTANT): batteryCapacityThreshold: 24.000000 Ah 2023-03-16T21:07:08.450Z,1679000828.450 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.000000 V 2023-03-16T21:07:08.834Z,1679000828.834 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2023-03-16T21:07:08.834Z,1679000828.834 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2023-03-16T21:07:08.834Z,1679000828.834 [IBIT](IMPORTANT): Pressure:7.716369 PSI 2023-03-16T21:07:08.835Z,1679000828.835 [IBIT](IMPORTANT): Humidity:23.434258 % 2023-03-16T21:07:09.258Z,1679000829.258 [IBIT](IMPORTANT): Vehicle Pitch:0.882924 degrees 2023-03-16T21:07:09.259Z,1679000829.259 [IBIT](IMPORTANT): Vehicle Roll:-3.681036 degrees 2023-03-16T21:07:09.259Z,1679000829.259 [IBIT](IMPORTANT): Vehicle Heading:221.069733 degrees 2023-03-16T21:07:09.645Z,1679000829.645 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m 2023-03-16T21:07:09.646Z,1679000829.646 [IBIT](IMPORTANT): buoyancyNeutral: 283.590729 cc 2023-03-16T21:07:09.646Z,1679000829.646 [IBIT](IMPORTANT): massDefault: 0.800000 cm 2023-03-16T21:07:09.646Z,1679000829.646 [IBIT](IMPORTANT): stopDepth: 215.000000 m 2023-03-16T21:07:09.646Z,1679000829.646 [IBIT](IMPORTANT): abortDepth: 255.000000 m 2023-03-16T21:07:09.646Z,1679000829.646 [IBIT](IMPORTANT): IBIT PASSED 2023-03-16T21:07:24.133Z,1679000844.133 [CommandExec](IMPORTANT): got command burn off 2023-03-16T21:07:24.133Z,1679000844.133 [CommandExec](IMPORTANT): Deactivating dropweight wire 2023-03-16T21:07:40.322Z,1679000860.322 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-16T21:07:51.464Z,1679000871.464 [CommandExec](IMPORTANT): got command burn on 2023-03-16T21:07:51.464Z,1679000871.464 [CommandExec](IMPORTANT): Activating dropweight wire 2023-03-16T21:08:15.420Z,1679000895.420 [CommandExec](IMPORTANT): got command burn off 2023-03-16T21:08:15.421Z,1679000895.421 [CommandExec](IMPORTANT): Deactivating dropweight wire 2023-03-16T21:09:28.989Z,1679000968.989 [CommandExec](IMPORTANT): got command burn on 2023-03-16T21:09:28.989Z,1679000968.989 [CommandExec](IMPORTANT): Activating dropweight wire 2023-03-16T21:11:12.459Z,1679001072.459 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-16T21:11:12.459Z,1679001072.459 [Default:CheckIn:C.Wait] Stopped 2023-03-16T21:11:12.459Z,1679001072.459 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-16T21:11:12.459Z,1679001072.459 [Default:CheckIn:D] Running Loop=1 2023-03-16T21:11:12.871Z,1679001072.871 [Default:CheckIn:D] Stopped 2023-03-16T21:11:12.871Z,1679001072.871 [Default:CheckIn:E] Running Loop=1 2023-03-16T21:11:13.290Z,1679001073.290 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.595524 min 2023-03-16T21:11:13.290Z,1679001073.290 [Default:CheckIn:E] Stopped 2023-03-16T21:11:13.290Z,1679001073.290 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-16T21:11:13.290Z,1679001073.290 [Default:CheckIn] Stopped 2023-03-16T21:11:13.290Z,1679001073.290 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-16T21:11:13.291Z,1679001073.291 [Default:CheckIn](INFO): Running loop #3 2023-03-16T21:11:13.291Z,1679001073.291 [Default:CheckIn] Running Loop=3 2023-03-16T21:11:13.291Z,1679001073.291 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-16T21:11:13.291Z,1679001073.291 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-16T21:11:15.279Z,1679001075.279 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211114.00,A,3648.17449,N,12147.27934,W,0.078,320.49,160323,,,A*70 2023-03-16T21:11:15.281Z,1679001075.281 [NAL9602](INFO): GPS fix at 20230316T211114: (36.802908, -121.787989) 2023-03-16T21:11:15.292Z,1679001075.292 [Default:CheckIn:Read_GPS] Stopped 2023-03-16T21:11:15.292Z,1679001075.292 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-16T21:11:22.563Z,1679001082.563 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230316T205537/Courier0010.lzma 2023-03-16T21:11:23.565Z,1679001083.565 [DataOverHttps](INFO): Moved sent file to Logs/20230316T205537/Courier0010.lzma.bak 2023-03-16T21:11:23.565Z,1679001083.565 [DataOverHttps](INFO): SBD MOMSN=17521986 2023-03-16T21:11:31.188Z,1679001091.188 [CommandExec](IMPORTANT): got command burn off 2023-03-16T21:11:31.188Z,1679001091.188 [CommandExec](IMPORTANT): Deactivating dropweight wire 2023-03-16T21:11:40.293Z,1679001100.293 [DataOverHttps](INFO): Sending 919 bytes from file Logs/20230316T205537/Express0011.lzma 2023-03-16T21:11:41.293Z,1679001101.293 [DataOverHttps](INFO): Moved sent file to Logs/20230316T205537/Express0011.lzma.bak 2023-03-16T21:11:41.294Z,1679001101.294 [DataOverHttps](INFO): SBD MOMSN=17521989 2023-03-16T21:11:42.772Z,1679001102.772 [Default:CheckIn:Read_Iridium] Stopped 2023-03-16T21:11:42.772Z,1679001102.772 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-16T21:11:42.772Z,1679001102.772 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-16T21:12:18.800Z,1679001138.800 [CommandExec](IMPORTANT): got command failComponent 2023-03-16T21:12:18.800Z,1679001138.800 [CommandExec](IMPORTANT): Failed components: 2023-03-16T21:12:18.800Z,1679001138.800 [CommandExec](IMPORTANT): No failed Components. 2023-03-16T21:12:38.914Z,1679001158.914 [NAL9602](INFO): SBD MO Status=2, MOMSN=22611, MT Status=2, MTMSN=0 2023-03-16T21:12:38.914Z,1679001158.914 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-16T21:13:00.731Z,1679001180.731 [NAL9602](INFO): SBD MO Status=1, MOMSN=22611, MT Status=0, MTMSN=0 2023-03-16T21:13:00.731Z,1679001180.731 [NAL9602](INFO): No messages in MT queue 2023-03-16T21:13:31.437Z,1679001211.437 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-16T21:16:43.359Z,1679001403.359 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-16T21:16:43.359Z,1679001403.359 [Default:CheckIn:C.Wait] Stopped 2023-03-16T21:16:43.379Z,1679001403.379 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-16T21:16:43.379Z,1679001403.379 [Default:CheckIn:D] Running Loop=1 2023-03-16T21:16:43.758Z,1679001403.758 [Default:CheckIn:D] Stopped 2023-03-16T21:16:43.758Z,1679001403.758 [Default:CheckIn:E] Running Loop=1 2023-03-16T21:16:44.218Z,1679001404.218 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 18.110311 min 2023-03-16T21:16:44.218Z,1679001404.218 [Default:CheckIn:E] Stopped 2023-03-16T21:16:44.218Z,1679001404.218 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-16T21:16:44.218Z,1679001404.218 [Default:CheckIn] Stopped 2023-03-16T21:16:44.218Z,1679001404.218 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-16T21:16:44.218Z,1679001404.218 [Default:CheckIn](INFO): Running loop #4 2023-03-16T21:16:44.218Z,1679001404.218 [Default:CheckIn] Running Loop=4 2023-03-16T21:16:44.219Z,1679001404.219 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-16T21:16:44.219Z,1679001404.219 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-16T21:16:46.174Z,1679001406.174 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211645.00,A,3648.17441,N,12147.27896,W,0.233,320.49,160323,,,A*7F 2023-03-16T21:16:46.188Z,1679001406.188 [NAL9602](INFO): GPS fix at 20230316T211645: (36.802907, -121.787983) 2023-03-16T21:16:46.226Z,1679001406.226 [Default:CheckIn:Read_GPS] Stopped 2023-03-16T21:16:46.226Z,1679001406.226 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-16T21:16:53.955Z,1679001413.955 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230316T205537/Courier0013.lzma 2023-03-16T21:16:54.953Z,1679001414.953 [DataOverHttps](INFO): Moved sent file to Logs/20230316T205537/Courier0013.lzma.bak 2023-03-16T21:16:54.953Z,1679001414.953 [DataOverHttps](INFO): SBD MOMSN=17522027 2023-03-16T21:17:11.240Z,1679001431.240 [DataOverHttps](INFO): Sending 226 bytes from file Logs/20230316T205537/Express0015.lzma 2023-03-16T21:17:12.241Z,1679001432.241 [DataOverHttps](INFO): Moved sent file to Logs/20230316T205537/Express0015.lzma.bak 2023-03-16T21:17:12.241Z,1679001432.241 [DataOverHttps](INFO): SBD MOMSN=17522030 2023-03-16T21:17:13.660Z,1679001433.660 [Default:CheckIn:Read_Iridium] Stopped 2023-03-16T21:17:13.660Z,1679001433.660 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-16T21:17:13.660Z,1679001433.660 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-16T21:17:14.458Z,1679001434.458 [NAL9602](INFO): SBD MO Status=2, MOMSN=22612, MT Status=2, MTMSN=0 2023-03-16T21:17:14.458Z,1679001434.458 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-16T21:18:12.237Z,1679001492.237 [NAL9602](INFO): SBD MO Status=2, MOMSN=22612, MT Status=2, MTMSN=0 2023-03-16T21:18:12.237Z,1679001492.237 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-16T21:18:26.376Z,1679001506.376 [NAL9602](INFO): SBD MO Status=1, MOMSN=22612, MT Status=0, MTMSN=0 2023-03-16T21:18:26.376Z,1679001506.376 [NAL9602](INFO): No messages in MT queue 2023-03-16T21:18:57.117Z,1679001537.117 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-16T21:22:14.370Z,1679001734.370 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-16T21:22:14.370Z,1679001734.370 [Default:CheckIn:C.Wait] Stopped 2023-03-16T21:22:14.370Z,1679001734.370 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-16T21:22:14.370Z,1679001734.370 [Default:CheckIn:D] Running Loop=1 2023-03-16T21:22:14.699Z,1679001734.699 [Default:CheckIn:D] Stopped 2023-03-16T21:22:14.699Z,1679001734.699 [Default:CheckIn:E] Running Loop=1 2023-03-16T21:22:15.104Z,1679001735.104 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 23.626003 min 2023-03-16T21:22:15.104Z,1679001735.104 [Default:CheckIn:E] Stopped 2023-03-16T21:22:15.104Z,1679001735.104 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-16T21:22:15.104Z,1679001735.104 [Default:CheckIn] Stopped 2023-03-16T21:22:15.105Z,1679001735.105 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-16T21:22:15.105Z,1679001735.105 [Default:CheckIn](INFO): Running loop #5 2023-03-16T21:22:15.105Z,1679001735.105 [Default:CheckIn] Running Loop=5 2023-03-16T21:22:15.105Z,1679001735.105 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-16T21:22:15.105Z,1679001735.105 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-16T21:22:17.106Z,1679001737.106 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212216.00,A,3648.14056,N,12147.22803,W,0.097,45.46,160323,,,D*40 2023-03-16T21:22:17.109Z,1679001737.109 [NAL9602](INFO): GPS fix at 20230316T212216: (36.802343, -121.787134) 2023-03-16T21:22:17.153Z,1679001737.153 [Default:CheckIn:Read_GPS] Stopped 2023-03-16T21:22:17.153Z,1679001737.153 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-16T21:22:27.762Z,1679001747.762 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230316T205537/Courier0019.lzma 2023-03-16T21:22:28.765Z,1679001748.765 [DataOverHttps](INFO): Moved sent file to Logs/20230316T205537/Courier0019.lzma.bak 2023-03-16T21:22:28.765Z,1679001748.765 [DataOverHttps](INFO): SBD MOMSN=17522171 2023-03-16T21:22:45.215Z,1679001765.215 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230316T205537/Express0020.lzma 2023-03-16T21:22:46.217Z,1679001766.217 [DataOverHttps](INFO): Moved sent file to Logs/20230316T205537/Express0020.lzma.bak 2023-03-16T21:22:46.217Z,1679001766.217 [DataOverHttps](INFO): SBD MOMSN=17522175 2023-03-16T21:22:47.547Z,1679001767.547 [Default:CheckIn:Read_Iridium] Stopped 2023-03-16T21:22:47.547Z,1679001767.547 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-16T21:22:47.547Z,1679001767.547 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-16T21:22:48.740Z,1679001768.740 [NAL9602](INFO): SBD MO Status=1, MOMSN=22613, MT Status=0, MTMSN=0 2023-03-16T21:22:48.740Z,1679001768.740 [NAL9602](INFO): No messages in MT queue 2023-03-16T21:23:19.441Z,1679001799.441 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-16T21:27:48.130Z,1679002068.130 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-16T21:27:48.130Z,1679002068.130 [Default:CheckIn:C.Wait] Stopped 2023-03-16T21:27:48.131Z,1679002068.131 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-16T21:27:48.131Z,1679002068.131 [Default:CheckIn:D] Running Loop=1 2023-03-16T21:27:48.519Z,1679002068.519 [Default:CheckIn:D] Stopped 2023-03-16T21:27:48.519Z,1679002068.519 [Default:CheckIn:E] Running Loop=1 2023-03-16T21:27:48.931Z,1679002068.931 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 29.189663 min 2023-03-16T21:27:48.931Z,1679002068.931 [Default:CheckIn:E] Stopped 2023-03-16T21:27:48.931Z,1679002068.931 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-16T21:27:48.931Z,1679002068.931 [Default:CheckIn] Stopped 2023-03-16T21:27:48.932Z,1679002068.932 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-16T21:27:48.932Z,1679002068.932 [Default:CheckIn](INFO): Running loop #6 2023-03-16T21:27:48.932Z,1679002068.932 [Default:CheckIn] Running Loop=6 2023-03-16T21:27:48.932Z,1679002068.932 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-16T21:27:48.932Z,1679002068.932 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-16T21:27:50.935Z,1679002070.935 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212750.00,A,3648.14033,N,12147.22728,W,0.019,45.46,160323,,,D*44 2023-03-16T21:27:50.937Z,1679002070.937 [NAL9602](INFO): GPS fix at 20230316T212750: (36.802339, -121.787121) 2023-03-16T21:27:50.968Z,1679002070.968 [Default:CheckIn:Read_GPS] Stopped 2023-03-16T21:27:50.968Z,1679002070.968 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-16T21:27:58.563Z,1679002078.563 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230316T205537/Courier0022.lzma 2023-03-16T21:27:59.565Z,1679002079.565 [DataOverHttps](INFO): Moved sent file to Logs/20230316T205537/Courier0022.lzma.bak 2023-03-16T21:27:59.565Z,1679002079.565 [DataOverHttps](INFO): SBD MOMSN=17522180 2023-03-16T21:28:08.706Z,1679002088.706 [NAL9602](INFO): SBD MO Status=1, MOMSN=22614, MT Status=0, MTMSN=0 2023-03-16T21:28:08.706Z,1679002088.706 [NAL9602](INFO): No messages in MT queue 2023-03-16T21:28:22.263Z,1679002102.263 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230316T205537/Express0023.lzma 2023-03-16T21:28:23.269Z,1679002103.269 [DataOverHttps](INFO): Moved sent file to Logs/20230316T205537/Express0023.lzma.bak 2023-03-16T21:28:23.269Z,1679002103.269 [DataOverHttps](INFO): SBD MOMSN=17522183 2023-03-16T21:28:25.497Z,1679002105.497 [Default:CheckIn:Read_Iridium] Stopped 2023-03-16T21:28:25.497Z,1679002105.497 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-16T21:28:25.497Z,1679002105.497 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-16T21:28:39.189Z,1679002119.189 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-16T21:33:26.070Z,1679002406.070 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-16T21:33:26.070Z,1679002406.070 [Default:CheckIn:C.Wait] Stopped 2023-03-16T21:33:26.070Z,1679002406.070 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-16T21:33:26.070Z,1679002406.070 [Default:CheckIn:D] Running Loop=1 2023-03-16T21:33:26.469Z,1679002406.469 [Default:CheckIn:D] Stopped 2023-03-16T21:33:26.469Z,1679002406.469 [Default:CheckIn:E] Running Loop=1 2023-03-16T21:33:26.864Z,1679002406.864 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 34.822164 min 2023-03-16T21:33:26.865Z,1679002406.865 [Default:CheckIn:E] Stopped 2023-03-16T21:33:26.865Z,1679002406.865 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-16T21:33:26.865Z,1679002406.865 [Default:CheckIn] Stopped 2023-03-16T21:33:26.865Z,1679002406.865 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-16T21:33:26.865Z,1679002406.865 [Default:CheckIn](INFO): Running loop #7 2023-03-16T21:33:26.865Z,1679002406.865 [Default:CheckIn] Running Loop=7 2023-03-16T21:33:26.865Z,1679002406.865 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-16T21:33:26.865Z,1679002406.865 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-16T21:33:28.871Z,1679002408.871 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213328.00,A,3648.14119,N,12147.20829,W,0.019,46.68,160323,,,D*44 2023-03-16T21:33:28.873Z,1679002408.873 [NAL9602](INFO): GPS fix at 20230316T213328: (36.802353, -121.786805) 2023-03-16T21:33:28.923Z,1679002408.923 [Default:CheckIn:Read_GPS] Stopped 2023-03-16T21:33:28.923Z,1679002408.923 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-16T21:33:32.769Z,1679002412.769 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230316T205537/Courier0025.lzma 2023-03-16T21:33:33.661Z,1679002413.661 [DataOverHttps](INFO): Moved sent file to Logs/20230316T205537/Courier0025.lzma.bak 2023-03-16T21:33:33.661Z,1679002413.661 [DataOverHttps](INFO): SBD MOMSN=17522306 2023-03-16T21:33:43.081Z,1679002423.081 [NAL9602](INFO): SBD MO Status=1, MOMSN=22615, MT Status=0, MTMSN=0 2023-03-16T21:33:43.081Z,1679002423.081 [NAL9602](INFO): No messages in MT queue 2023-03-16T21:33:50.007Z,1679002430.007 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230316T205537/Express0026.lzma 2023-03-16T21:33:51.009Z,1679002431.009 [DataOverHttps](INFO): Moved sent file to Logs/20230316T205537/Express0026.lzma.bak 2023-03-16T21:33:51.009Z,1679002431.009 [DataOverHttps](INFO): SBD MOMSN=17522309 2023-03-16T21:33:52.389Z,1679002432.389 [Default:CheckIn:Read_Iridium] Stopped 2023-03-16T21:33:52.389Z,1679002432.389 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-16T21:33:52.389Z,1679002432.389 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-16T21:34:13.784Z,1679002453.784 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-16T21:35:20.056Z,1679002520.056 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2023-03-16T21:38:52.978Z,1679002732.978 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-16T21:38:52.978Z,1679002732.978 [Default:CheckIn:C.Wait] Stopped 2023-03-16T21:38:52.978Z,1679002732.978 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-16T21:38:52.978Z,1679002732.978 [Default:CheckIn:D] Running Loop=1 2023-03-16T21:38:53.369Z,1679002733.369 [Default:CheckIn:D] Stopped 2023-03-16T21:38:53.370Z,1679002733.370 [Default:CheckIn:E] Running Loop=1 2023-03-16T21:38:53.779Z,1679002733.779 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 40.270504 min 2023-03-16T21:38:53.779Z,1679002733.779 [Default:CheckIn:E] Stopped 2023-03-16T21:38:53.779Z,1679002733.779 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-16T21:38:53.779Z,1679002733.779 [Default:CheckIn] Stopped 2023-03-16T21:38:53.780Z,1679002733.780 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-16T21:38:53.780Z,1679002733.780 [Default:CheckIn](INFO): Running loop #8 2023-03-16T21:38:53.780Z,1679002733.780 [Default:CheckIn] Running Loop=8 2023-03-16T21:38:53.780Z,1679002733.780 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-16T21:38:53.780Z,1679002733.780 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-16T21:38:55.790Z,1679002735.790 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213855.00,A,3648.13772,N,12147.20609,W,0.136,46.68,160323,,,D*49 2023-03-16T21:38:55.801Z,1679002735.801 [NAL9602](INFO): GPS fix at 20230316T213855: (36.802295, -121.786768) 2023-03-16T21:38:55.812Z,1679002735.812 [Default:CheckIn:Read_GPS] Stopped 2023-03-16T21:38:55.812Z,1679002735.812 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-16T21:39:03.488Z,1679002743.488 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230316T205537/Courier0028.lzma 2023-03-16T21:39:04.489Z,1679002744.489 [DataOverHttps](INFO): Moved sent file to Logs/20230316T205537/Courier0028.lzma.bak 2023-03-16T21:39:04.489Z,1679002744.489 [DataOverHttps](INFO): SBD MOMSN=17522314 2023-03-16T21:39:21.287Z,1679002761.287 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20230316T205537/Express0029.lzma 2023-03-16T21:39:22.290Z,1679002762.290 [DataOverHttps](INFO): Moved sent file to Logs/20230316T205537/Express0029.lzma.bak 2023-03-16T21:39:22.290Z,1679002762.290 [DataOverHttps](INFO): SBD MOMSN=17522317 2023-03-16T21:39:23.677Z,1679002763.677 [Default:CheckIn:Read_Iridium] Stopped 2023-03-16T21:39:23.677Z,1679002763.677 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-16T21:39:23.677Z,1679002763.677 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-16T21:39:40.634Z,1679002780.634 [NAL9602](INFO): SBD MO Status=2, MOMSN=22616, MT Status=2, MTMSN=0 2023-03-16T21:39:40.634Z,1679002780.634 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-16T21:39:58.006Z,1679002798.006 [NAL9602](INFO): SBD MO Status=1, MOMSN=22616, MT Status=0, MTMSN=0 2023-03-16T21:39:58.006Z,1679002798.006 [NAL9602](INFO): No messages in MT queue 2023-03-16T21:40:28.717Z,1679002828.717 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-16T21:41:53.516Z,1679002913.516 [DataOverHttps](IMPORTANT): SBD MTMSN=20230316T214152 2023-03-16T21:42:01.323Z,1679002921.323 [DataOverHttps](INFO): Received command: strobe off 2023-03-16T21:42:01.332Z,1679002921.332 [CommandExec](IMPORTANT): got command strobe off 2023-03-16T21:42:01.332Z,1679002921.332 [CommandExec](IMPORTANT): Deactivating strobe 2023-03-16T21:44:24.376Z,1679003064.376 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-16T21:44:24.376Z,1679003064.376 [Default:CheckIn:C.Wait] Stopped 2023-03-16T21:44:24.376Z,1679003064.376 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-16T21:44:24.376Z,1679003064.376 [Default:CheckIn:D] Running Loop=1 2023-03-16T21:44:24.708Z,1679003064.708 [Default:CheckIn:D] Stopped 2023-03-16T21:44:24.708Z,1679003064.708 [Default:CheckIn:E] Running Loop=1 2023-03-16T21:44:25.127Z,1679003065.127 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.792810 min 2023-03-16T21:44:25.128Z,1679003065.128 [Default:CheckIn:E] Stopped 2023-03-16T21:44:25.128Z,1679003065.128 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-16T21:44:25.128Z,1679003065.128 [Default:CheckIn] Stopped 2023-03-16T21:44:25.128Z,1679003065.128 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-16T21:44:25.128Z,1679003065.128 [Default:CheckIn](INFO): Running loop #9 2023-03-16T21:44:25.128Z,1679003065.128 [Default:CheckIn] Running Loop=9 2023-03-16T21:44:25.128Z,1679003065.128 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-16T21:44:25.128Z,1679003065.128 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-16T21:44:27.106Z,1679003067.106 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214426.00,A,3648.13731,N,12147.20472,W,0.097,46.68,160323,,,D*45 2023-03-16T21:44:27.109Z,1679003067.109 [NAL9602](INFO): GPS fix at 20230316T214426: (36.802289, -121.786745) 2023-03-16T21:44:27.120Z,1679003067.120 [Default:CheckIn:Read_GPS] Stopped 2023-03-16T21:44:27.120Z,1679003067.120 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-16T21:44:35.905Z,1679003075.905 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230316T205537/Courier0031.lzma 2023-03-16T21:44:36.901Z,1679003076.901 [DataOverHttps](INFO): Moved sent file to Logs/20230316T205537/Courier0031.lzma.bak 2023-03-16T21:44:36.901Z,1679003076.901 [DataOverHttps](INFO): SBD MOMSN=17522454 2023-03-16T21:44:43.666Z,1679003083.666 [NAL9602](INFO): SBD MO Status=1, MOMSN=22617, MT Status=0, MTMSN=0 2023-03-16T21:44:43.666Z,1679003083.666 [NAL9602](INFO): No messages in MT queue 2023-03-16T21:44:53.287Z,1679003093.287 [DataOverHttps](INFO): Sending 203 bytes from file Logs/20230316T205537/Express0032.lzma 2023-03-16T21:44:54.289Z,1679003094.289 [DataOverHttps](INFO): Moved sent file to Logs/20230316T205537/Express0032.lzma.bak 2023-03-16T21:44:54.289Z,1679003094.289 [DataOverHttps](INFO): SBD MOMSN=17522458 2023-03-16T21:45:10.451Z,1679003110.451 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20230316T205537/Express0035.lzma 2023-03-16T21:45:11.454Z,1679003111.454 [DataOverHttps](INFO): Moved sent file to Logs/20230316T205537/Express0035.lzma.bak 2023-03-16T21:45:11.454Z,1679003111.454 [DataOverHttps](IMPORTANT): SBD MOMSN=17522465, MTMSN=20230316T214510 2023-03-16T21:45:12.774Z,1679003112.774 [Default:CheckIn:Read_Iridium] Stopped 2023-03-16T21:45:12.774Z,1679003112.774 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-16T21:45:12.774Z,1679003112.774 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-16T21:45:14.368Z,1679003114.368 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-16T21:45:19.291Z,1679003119.291 [DataOverHttps](INFO): Received command: sched asap "sched asap "load Science/sci2.tl; set sci2.Lat1 -121.847 degree; set sci2.Lon1 36.797 degree; set sci2:StandardEnvelopes.MaxDepth 25 meter; set sci2.MissionTimeout 0.5 hour; set sci2.NeedCommsTime 20 minute" 1oxr5 1 2 2023-03-16T21:45:20.293Z,1679003120.293 [DataOverHttps](IMPORTANT): SBD MTMSN=20230316T214519 2023-03-16T21:45:31.567Z,1679003131.567 [DataOverHttps](INFO): Received command: sched asap " set sci2.YoYoMaxDepth 15 meter; set sci2:StandardEnvelopes.MaxDepth 25 meter; run"" 1oxr5 2 2 2023-03-16T21:45:39.608Z,1679003139.608 [CommandExec](IMPORTANT): got command schedule asap "sched asap " Science/sci2.tl 21 -inf 2023-03-16T21:45:39.609Z,1679003139.609 [CommandExec](IMPORTANT): Scheduling command #21 of -2147483648 with id=Science/sci2.tl 2023-03-16T21:45:39.609Z,1679003139.609 [CommandExec](FAULT): Failed to schedule command with id=Science/sci2.tl and idCount=-2147483648. idCount must be > 0. 2023-03-16T21:45:39.610Z,1679003139.610 [CommandExec](IMPORTANT): got command set 2023-03-16T21:45:39.610Z,1679003139.610 [CommandExec](FAULT): Incomplete syntax. Try: help set 2023-03-16T21:45:39.614Z,1679003139.614 [CommandExec](IMPORTANT): got command schedule asap " set sci2.YoYoMaxDepth 15 meter; set sci2:StandardEnvelopes.MaxDepth 25 meter; run" 1oxr5 2 2.000000 2023-03-16T21:45:39.614Z,1679003139.614 [CommandExec](IMPORTANT): Scheduling command #2 of 2 with id=1oxr5 2023-03-16T21:45:39.616Z,1679003139.616 [CommandExec](IMPORTANT): Scheduled #2 (#2 of 2 with id='1oxr5'): " set sci2.YoYoMaxDepth 15 meter; set sci2:StandardEnvelopes.MaxDepth 25 meter; run", ASAP 2023-03-16T21:50:13.357Z,1679003413.357 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-16T21:50:13.357Z,1679003413.357 [Default:CheckIn:C.Wait] Stopped 2023-03-16T21:50:13.357Z,1679003413.357 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-16T21:50:13.357Z,1679003413.357 [Default:CheckIn:D] Running Loop=1 2023-03-16T21:50:13.785Z,1679003413.785 [Default:CheckIn:D] Stopped 2023-03-16T21:50:13.785Z,1679003413.785 [Default:CheckIn:E] Running Loop=1 2023-03-16T21:50:14.218Z,1679003414.218 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 51.610763 min 2023-03-16T21:50:14.218Z,1679003414.218 [Default:CheckIn:E] Stopped 2023-03-16T21:50:14.218Z,1679003414.218 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-16T21:50:14.218Z,1679003414.218 [Default:CheckIn] Stopped 2023-03-16T21:50:14.218Z,1679003414.218 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-16T21:50:14.218Z,1679003414.218 [Default:CheckIn](INFO): Running loop #10 2023-03-16T21:50:14.218Z,1679003414.218 [Default:CheckIn] Running Loop=10 2023-03-16T21:50:14.218Z,1679003414.218 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-16T21:50:14.218Z,1679003414.218 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-16T21:50:16.187Z,1679003416.187 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215015.00,A,3648.22903,N,12147.14130,W,5.657,21.84,160323,,,D*45 2023-03-16T21:50:16.201Z,1679003416.201 [NAL9602](INFO): GPS fix at 20230316T215015: (36.803817, -121.785688) 2023-03-16T21:50:16.268Z,1679003416.268 [Default:CheckIn:Read_GPS] Stopped 2023-03-16T21:50:16.269Z,1679003416.269 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-16T21:50:28.170Z,1679003428.170 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230316T205537/Courier0037.lzma 2023-03-16T21:50:29.173Z,1679003429.173 [DataOverHttps](INFO): Moved sent file to Logs/20230316T205537/Courier0037.lzma.bak 2023-03-16T21:50:29.173Z,1679003429.173 [DataOverHttps](INFO): SBD MOMSN=17522478 2023-03-16T21:50:45.480Z,1679003445.480 [DataOverHttps](INFO): Sending 466 bytes from file Logs/20230316T205537/Express0038.lzma 2023-03-16T21:50:46.481Z,1679003446.481 [DataOverHttps](INFO): Moved sent file to Logs/20230316T205537/Express0038.lzma.bak 2023-03-16T21:50:46.481Z,1679003446.481 [DataOverHttps](INFO): SBD MOMSN=17522483 2023-03-16T21:51:01.957Z,1679003461.957 [NAL9602](INFO): SBD MO Status=2, MOMSN=22618, MT Status=2, MTMSN=0 2023-03-16T21:51:01.957Z,1679003461.957 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-16T21:51:02.879Z,1679003462.879 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20230316T205537/Express0041.lzma 2023-03-16T21:51:03.881Z,1679003463.881 [DataOverHttps](INFO): Moved sent file to Logs/20230316T205537/Express0041.lzma.bak 2023-03-16T21:51:03.881Z,1679003463.881 [DataOverHttps](INFO): SBD MOMSN=17522496 2023-03-16T21:51:05.184Z,1679003465.184 [Default:CheckIn:Read_Iridium] Stopped 2023-03-16T21:51:05.184Z,1679003465.184 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-16T21:51:05.184Z,1679003465.184 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-16T21:51:12.605Z,1679003472.605 [DataOverHttps](IMPORTANT): SBD MTMSN=20230316T215111 2023-03-16T21:51:20.271Z,1679003480.271 [DataOverHttps](INFO): Received command: stop 2023-03-16T21:51:20.320Z,1679003480.320 [CommandExec](IMPORTANT): got command stop 2023-03-16T21:51:20.320Z,1679003480.320 [CommandExec](IMPORTANT): Scheduling is paused for 1 commands 2023-03-16T21:51:20.320Z,1679003480.320 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop 2023-03-16T21:51:23.755Z,1679003483.755 [NAL9602](INFO): SBD MO Status=2, MOMSN=22618, MT Status=2, MTMSN=0 2023-03-16T21:51:23.755Z,1679003483.755 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-16T21:51:49.605Z,1679003509.605 [NAL9602](INFO): SBD MO Status=1, MOMSN=22618, MT Status=0, MTMSN=0 2023-03-16T21:51:49.606Z,1679003509.606 [NAL9602](INFO): No messages in MT queue 2023-03-16T21:52:20.313Z,1679003540.313 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-16T21:53:28.215Z,1679003608.215 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for water mass range. 2023-03-16T21:56:05.897Z,1679003765.897 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-16T21:56:05.898Z,1679003765.898 [Default:CheckIn:C.Wait] Stopped 2023-03-16T21:56:05.898Z,1679003765.898 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-16T21:56:05.898Z,1679003765.898 [Default:CheckIn:D] Running Loop=1 2023-03-16T21:56:06.308Z,1679003766.308 [Default:CheckIn:D] Stopped 2023-03-16T21:56:06.308Z,1679003766.308 [Default:CheckIn:E] Running Loop=1 2023-03-16T21:56:06.704Z,1679003766.704 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 57.486145 min 2023-03-16T21:56:06.704Z,1679003766.704 [Default:CheckIn:E] Stopped 2023-03-16T21:56:06.704Z,1679003766.704 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-16T21:56:06.704Z,1679003766.704 [Default:CheckIn] Stopped 2023-03-16T21:56:06.704Z,1679003766.704 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-16T21:56:06.705Z,1679003766.705 [Default:CheckIn](INFO): Running loop #11 2023-03-16T21:56:06.705Z,1679003766.705 [Default:CheckIn] Running Loop=11 2023-03-16T21:56:06.705Z,1679003766.705 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-16T21:56:06.705Z,1679003766.705 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-16T21:56:08.702Z,1679003768.702 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215608.00,A,3648.37714,N,12147.67725,W,14.423,291.45,160323,,,D*40 2023-03-16T21:56:08.705Z,1679003768.705 [NAL9602](INFO): GPS fix at 20230316T215608: (36.806286, -121.794621) 2023-03-16T21:56:08.736Z,1679003768.736 [Default:CheckIn:Read_GPS] Stopped 2023-03-16T21:56:08.736Z,1679003768.736 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-16T21:56:16.471Z,1679003776.471 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20230316T205537/Courier0043.lzma 2023-03-16T21:56:17.474Z,1679003777.474 [DataOverHttps](INFO): Moved sent file to Logs/20230316T205537/Courier0043.lzma.bak 2023-03-16T21:56:17.474Z,1679003777.474 [DataOverHttps](INFO): SBD MOMSN=17522629 2023-03-16T21:56:34.210Z,1679003794.210 [NAL9602](INFO): SBD MO Status=2, MOMSN=22619, MT Status=2, MTMSN=0 2023-03-16T21:56:34.210Z,1679003794.210 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-16T21:56:38.264Z,1679003798.264 [DataOverHttps](INFO): Sending 221 bytes from file Logs/20230316T205537/Express0044.lzma 2023-03-16T21:56:39.265Z,1679003799.265 [DataOverHttps](INFO): Moved sent file to Logs/20230316T205537/Express0044.lzma.bak 2023-03-16T21:56:39.265Z,1679003799.265 [DataOverHttps](INFO): SBD MOMSN=17522632 2023-03-16T21:56:51.177Z,1679003811.177 [NAL9602](INFO): SBD MO Status=2, MOMSN=22619, MT Status=2, MTMSN=0 2023-03-16T21:56:51.178Z,1679003811.178 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-16T21:56:55.747Z,1679003815.747 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20230316T205537/Express0047.lzma 2023-03-16T21:56:56.749Z,1679003816.749 [DataOverHttps](INFO): Moved sent file to Logs/20230316T205537/Express0047.lzma.bak 2023-03-16T21:56:56.749Z,1679003816.749 [DataOverHttps](INFO): SBD MOMSN=17522638 2023-03-16T21:56:58.099Z,1679003818.099 [Default:CheckIn:Read_Iridium] Stopped 2023-03-16T21:56:58.100Z,1679003818.100 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-16T21:56:58.100Z,1679003818.100 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-16T21:57:08.554Z,1679003828.554 [NAL9602](INFO): SBD MO Status=2, MOMSN=22619, MT Status=2, MTMSN=0 2023-03-16T21:57:08.554Z,1679003828.554 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-16T21:57:55.418Z,1679003875.418 [NAL9602](INFO): SBD MO Status=1, MOMSN=22619, MT Status=0, MTMSN=0 2023-03-16T21:57:55.418Z,1679003875.418 [NAL9602](INFO): No messages in MT queue 2023-03-16T21:58:05.800Z,1679003885.800 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.239269 2023-03-16T21:58:17.387Z,1679003897.387 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002777 2023-03-16T21:58:26.136Z,1679003906.136 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-16T22:01:58.643Z,1679004118.643 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-16T22:01:58.644Z,1679004118.644 [Default:CheckIn:C.Wait] Stopped 2023-03-16T22:01:58.644Z,1679004118.644 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-16T22:01:58.644Z,1679004118.644 [Default:CheckIn:D] Running Loop=1 2023-03-16T22:01:59.045Z,1679004119.045 [Default:CheckIn:D] Stopped 2023-03-16T22:01:59.045Z,1679004119.045 [Default:CheckIn:E] Running Loop=1 2023-03-16T22:01:59.455Z,1679004119.455 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 63.365096 min 2023-03-16T22:01:59.455Z,1679004119.455 [Default:CheckIn:E] Stopped 2023-03-16T22:01:59.459Z,1679004119.459 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-16T22:01:59.459Z,1679004119.459 [Default:CheckIn] Stopped 2023-03-16T22:01:59.459Z,1679004119.459 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-16T22:01:59.460Z,1679004119.460 [Default:CheckIn](INFO): Running loop #12 2023-03-16T22:01:59.460Z,1679004119.460 [Default:CheckIn] Running Loop=12 2023-03-16T22:01:59.460Z,1679004119.460 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-16T22:01:59.460Z,1679004119.460 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-16T22:02:01.463Z,1679004121.463 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220200.00,A,3648.28862,N,12148.46197,W,0.583,73.60,160323,,,D*4E 2023-03-16T22:02:01.465Z,1679004121.465 [NAL9602](INFO): GPS fix at 20230316T220200: (36.804810, -121.807699) 2023-03-16T22:02:01.497Z,1679004121.497 [Default:CheckIn:Read_GPS] Stopped 2023-03-16T22:02:01.497Z,1679004121.497 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-16T22:02:08.835Z,1679004128.835 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20230316T205537/Courier0049.lzma 2023-03-16T22:02:09.837Z,1679004129.837 [DataOverHttps](INFO): Moved sent file to Logs/20230316T205537/Courier0049.lzma.bak 2023-03-16T22:02:09.837Z,1679004129.837 [DataOverHttps](INFO): SBD MOMSN=17522642 2023-03-16T22:02:18.080Z,1679004138.080 [NAL9602](INFO): SBD MO Status=2, MOMSN=22620, MT Status=2, MTMSN=0 2023-03-16T22:02:18.080Z,1679004138.080 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-16T22:02:33.067Z,1679004153.067 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20230316T205537/Express0050.lzma 2023-03-16T22:02:34.069Z,1679004154.069 [DataOverHttps](INFO): Moved sent file to Logs/20230316T205537/Express0050.lzma.bak 2023-03-16T22:02:34.069Z,1679004154.069 [DataOverHttps](INFO): SBD MOMSN=17522645 2023-03-16T22:02:35.461Z,1679004155.461 [Default:CheckIn:Read_Iridium] Stopped 2023-03-16T22:02:35.461Z,1679004155.461 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-16T22:02:35.461Z,1679004155.461 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-16T22:02:40.698Z,1679004160.698 [NAL9602](INFO): SBD MO Status=2, MOMSN=22620, MT Status=2, MTMSN=0 2023-03-16T22:02:40.698Z,1679004160.698 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-16T22:03:29.985Z,1679004209.985 [NAL9602](INFO): SBD MO Status=1, MOMSN=22620, MT Status=0, MTMSN=0 2023-03-16T22:03:29.985Z,1679004209.985 [NAL9602](INFO): No messages in MT queue 2023-03-16T22:04:00.703Z,1679004240.703 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-16T22:05:05.529Z,1679004305.529 [DataOverHttps](IMPORTANT): SBD MTMSN=20230316T220504 2023-03-16T22:05:13.139Z,1679004313.139 [DataOverHttps](INFO): Received command: restart logs