2024-04-10T19:58:33.928Z,1712779113.928 [Supervisor](DEBUG): Initializing supervisor. 2024-04-10T19:58:33.932Z,1712779113.932 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2024-04-10T19:58:33.933Z,1712779113.933 [SyncHandler](INFO): Protected caller Thread ID is 3831 2024-04-10T19:58:33.933Z,1712779113.933 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2024-04-10T19:58:33.934Z,1712779113.934 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2024-04-10T19:58:33.934Z,1712779113.934 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 3832 2024-04-10T19:58:33.938Z,1712779113.938 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2024-04-10T19:58:33.958Z,1712779113.958 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2024-04-10T19:58:33.959Z,1712779113.959 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2024-04-10T19:58:33.959Z,1712779113.959 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 3833 2024-04-10T19:58:33.964Z,1712779113.964 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2024-04-10T19:58:33.965Z,1712779113.965 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2024-04-10T19:58:33.965Z,1712779113.965 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 3834 2024-04-10T19:58:33.967Z,1712779113.967 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2024-04-10T19:58:33.968Z,1712779113.968 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2024-04-10T19:58:33.968Z,1712779113.968 [logger ThreadHandler](INFO): Protected caller Thread ID is 3835 2024-04-10T19:58:33.972Z,1712779113.972 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2024-04-10T19:58:33.972Z,1712779113.972 [Supervisor](INFO): Looking for Config files in directory: Config/ 2024-04-10T19:58:33.977Z,1712779113.977 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2024-04-10T19:58:34.325Z,1712779114.325 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2024-04-10T19:58:34.327Z,1712779114.327 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2024-04-10T19:58:34.423Z,1712779114.423 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2024-04-10T19:58:35.033Z,1712779115.033 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2024-04-10T19:58:35.035Z,1712779115.035 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2024-04-10T19:58:35.395Z,1712779115.395 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2024-04-10T19:58:35.397Z,1712779115.397 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2024-04-10T19:58:35.497Z,1712779115.497 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2024-04-10T19:58:35.499Z,1712779115.499 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2024-04-10T19:58:35.927Z,1712779115.927 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2024-04-10T19:58:35.928Z,1712779115.928 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2024-04-10T19:58:36.153Z,1712779116.153 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2024-04-10T19:58:36.155Z,1712779116.155 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2024-04-10T19:58:36.710Z,1712779116.710 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2024-04-10T19:58:36.710Z,1712779116.710 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2024-04-10T19:58:36.855Z,1712779116.855 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2024-04-10T19:58:36.856Z,1712779116.856 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2024-04-10T19:58:36.940Z,1712779116.940 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2024-04-10T19:58:38.032Z,1712779118.032 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2024-04-10T19:58:38.033Z,1712779118.033 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2024-04-10T19:58:38.807Z,1712779118.807 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2024-04-10T19:58:38.808Z,1712779118.808 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2024-04-10T19:58:39.012Z,1712779119.012 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2024-04-10T19:58:39.013Z,1712779119.013 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2024-04-10T19:58:39.129Z,1712779119.129 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2024-04-10T19:58:39.130Z,1712779119.130 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2024-04-10T19:58:39.372Z,1712779119.372 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2024-04-10T19:58:39.372Z,1712779119.372 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2024-04-10T19:58:39.634Z,1712779119.634 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2024-04-10T19:58:39.636Z,1712779119.636 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2024-04-10T19:58:39.640Z,1712779119.640 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg 2024-04-10T19:58:39.739Z,1712779119.739 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2024-04-10T19:58:39.831Z,1712779119.831 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2024-04-10T19:58:39.939Z,1712779119.939 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2024-04-10T19:58:40.027Z,1712779120.027 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2024-04-10T19:58:40.137Z,1712779120.137 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2024-04-10T19:58:40.235Z,1712779120.235 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2024-04-10T19:58:40.355Z,1712779120.355 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2024-04-10T19:58:40.518Z,1712779120.518 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2024-04-10T19:58:40.670Z,1712779120.670 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2024-04-10T19:58:40.788Z,1712779120.788 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg 2024-04-10T19:58:41.062Z,1712779121.062 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2024-04-10T19:58:41.064Z,1712779121.064 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/ 2024-04-10T19:58:41.064Z,1712779121.064 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2024-04-10T19:58:41.086Z,1712779121.086 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2024-04-10T19:58:41.161Z,1712779121.161 [VerticalControl](DEBUG): Construct VerticalControl. 2024-04-10T19:58:41.221Z,1712779121.221 [VerticalControl] Loaded 2024-04-10T19:58:41.221Z,1712779121.221 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2024-04-10T19:58:41.224Z,1712779121.224 [HorizontalControl](DEBUG): Construct HorizontalControl. 2024-04-10T19:58:41.265Z,1712779121.265 [HorizontalControl] Loaded 2024-04-10T19:58:41.266Z,1712779121.266 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2024-04-10T19:58:41.268Z,1712779121.268 [SpeedControl](DEBUG): Construct SpeedControl. 2024-04-10T19:58:41.271Z,1712779121.271 [SpeedControl] Loaded 2024-04-10T19:58:41.272Z,1712779121.272 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2024-04-10T19:58:41.274Z,1712779121.274 [LoopControl](DEBUG): Construct LoopControl. 2024-04-10T19:58:41.275Z,1712779121.275 [LoopControl] Loaded 2024-04-10T19:58:41.275Z,1712779121.275 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2024-04-10T19:58:41.275Z,1712779121.275 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2024-04-10T19:58:41.276Z,1712779121.276 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2024-04-10T19:58:41.292Z,1712779121.292 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2024-04-10T19:58:41.294Z,1712779121.294 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2024-04-10T19:58:41.491Z,1712779121.491 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2024-04-10T19:58:41.491Z,1712779121.491 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2024-04-10T19:58:41.660Z,1712779121.660 [BuoyancyServo] Loaded 2024-04-10T19:58:41.661Z,1712779121.661 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2024-04-10T19:58:41.681Z,1712779121.681 [ElevatorServo] Loaded 2024-04-10T19:58:41.681Z,1712779121.681 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2024-04-10T19:58:41.700Z,1712779121.700 [MassServo] Loaded 2024-04-10T19:58:41.700Z,1712779121.700 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2024-04-10T19:58:41.719Z,1712779121.719 [RudderServo] Loaded 2024-04-10T19:58:41.720Z,1712779121.720 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2024-04-10T19:58:41.735Z,1712779121.735 [ThrusterHE] Loaded 2024-04-10T19:58:41.735Z,1712779121.735 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2024-04-10T19:58:41.735Z,1712779121.735 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2024-04-10T19:58:41.736Z,1712779121.736 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2024-04-10T19:58:41.880Z,1712779121.880 [DeadReckonUsingMultipleVelocitySources] Loaded 2024-04-10T19:58:41.880Z,1712779121.880 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2024-04-10T19:58:41.894Z,1712779121.894 [NavChart] Loaded 2024-04-10T19:58:41.894Z,1712779121.894 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2024-04-10T19:58:41.900Z,1712779121.900 [UniversalFixResidualReporter] Loaded 2024-04-10T19:58:41.900Z,1712779121.900 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2024-04-10T19:58:41.900Z,1712779121.900 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2024-04-10T19:58:41.901Z,1712779121.901 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2024-04-10T19:58:41.992Z,1712779121.992 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2024-04-10T19:58:41.992Z,1712779121.992 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2024-04-10T19:58:42.825Z,1712779122.825 [AHRS_M2] Loaded 2024-04-10T19:58:42.825Z,1712779122.825 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2024-04-10T19:58:43.654Z,1712779123.654 [BPC1] Loaded 2024-04-10T19:58:43.654Z,1712779123.654 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2024-04-10T19:58:44.058Z,1712779124.058 [DataOverHttps] Loaded 2024-04-10T19:58:44.058Z,1712779124.058 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2024-04-10T19:58:44.059Z,1712779124.059 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4091F4E0 2024-04-10T19:58:44.060Z,1712779124.059 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 3918 2024-04-10T19:58:44.080Z,1712779124.080 [Depth_Keller] Loaded 2024-04-10T19:58:44.080Z,1712779124.080 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2024-04-10T19:58:44.085Z,1712779124.085 [DropWeight] Loaded 2024-04-10T19:58:44.086Z,1712779124.086 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2024-04-10T19:58:44.345Z,1712779124.345 [NAL9602] Loaded 2024-04-10T19:58:44.345Z,1712779124.345 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2024-04-10T19:58:44.376Z,1712779124.376 [Onboard] Loaded 2024-04-10T19:58:44.376Z,1712779124.376 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2024-04-10T19:58:44.377Z,1712779124.377 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4094F4E0 2024-04-10T19:58:44.378Z,1712779124.378 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 3919 2024-04-10T19:58:44.414Z,1712779124.414 [PowerOnly](INFO): Adding load control power supply at /dev/loadC1 2024-04-10T19:58:44.429Z,1712779124.429 [PowerOnly] Loaded 2024-04-10T19:58:44.429Z,1712779124.429 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread. 2024-04-10T19:58:44.441Z,1712779124.441 [Power24vConverter] Loaded 2024-04-10T19:58:44.441Z,1712779124.441 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2024-04-10T19:58:44.542Z,1712779124.542 [Radio_Surface] Loaded 2024-04-10T19:58:44.543Z,1712779124.543 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2024-04-10T19:58:44.544Z,1712779124.544 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4097F4E0 2024-04-10T19:58:44.544Z,1712779124.544 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 3920 2024-04-10T19:58:44.545Z,1712779124.545 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2024-04-10T19:58:44.546Z,1712779124.546 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2024-04-10T19:58:44.830Z,1712779124.830 [DepthRateCalculator] Loaded 2024-04-10T19:58:44.831Z,1712779124.831 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2024-04-10T19:58:44.836Z,1712779124.836 [PitchRateCalculator] Loaded 2024-04-10T19:58:44.836Z,1712779124.836 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2024-04-10T19:58:44.844Z,1712779124.844 [SpeedCalculator] Loaded 2024-04-10T19:58:44.845Z,1712779124.845 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2024-04-10T19:58:44.849Z,1712779124.849 [YawRateCalculator] Loaded 2024-04-10T19:58:44.849Z,1712779124.849 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2024-04-10T19:58:44.868Z,1712779124.868 [ElevatorOffsetCalculator] Loaded 2024-04-10T19:58:44.868Z,1712779124.868 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2024-04-10T19:58:44.868Z,1712779124.868 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2024-04-10T19:58:44.869Z,1712779124.869 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2024-04-10T19:58:45.061Z,1712779125.061 [CANONSampler] Loaded 2024-04-10T19:58:45.061Z,1712779125.061 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread. 2024-04-10T19:58:45.123Z,1712779125.123 [CTD_Seabird] Loaded 2024-04-10T19:58:45.123Z,1712779125.123 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2024-04-10T19:58:45.124Z,1712779125.124 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A3B4E0 2024-04-10T19:58:45.124Z,1712779125.124 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 3921 2024-04-10T19:58:45.145Z,1712779125.145 [PAR_Licor] Loaded 2024-04-10T19:58:45.145Z,1712779125.145 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2024-04-10T19:58:45.146Z,1712779125.146 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2024-04-10T19:58:45.146Z,1712779125.146 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2024-04-10T19:58:45.192Z,1712779125.192 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2024-04-10T19:58:45.192Z,1712779125.192 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2024-04-10T19:58:45.631Z,1712779125.631 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2024-04-10T19:58:45.633Z,1712779125.633 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2024-04-10T19:58:45.822Z,1712779125.822 [SBIT](DEBUG): Construct Startup Built In Test. 2024-04-10T19:58:45.831Z,1712779125.831 [SBIT] Loaded 2024-04-10T19:58:45.832Z,1712779125.832 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2024-04-10T19:58:45.834Z,1712779125.834 [IBIT](DEBUG): Construct Initiated Built In Test. 2024-04-10T19:58:45.847Z,1712779125.847 [IBIT] Loaded 2024-04-10T19:58:45.847Z,1712779125.847 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2024-04-10T19:58:45.853Z,1712779125.853 [CBIT](DEBUG): Construct Continuous Built In Test. 2024-04-10T19:58:45.957Z,1712779125.957 [CBIT] Loaded 2024-04-10T19:58:45.957Z,1712779125.957 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2024-04-10T19:58:45.958Z,1712779125.958 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2024-04-10T19:58:45.958Z,1712779125.958 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2024-04-10T19:58:46.113Z,1712779126.113 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2024-04-10T19:58:46.120Z,1712779126.120 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2024-04-10T19:58:46.122Z,1712779126.122 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2024-04-10T19:58:46.133Z,1712779126.133 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2024-04-10T19:58:46.134Z,1712779126.134 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B934E0 2024-04-10T19:58:46.135Z,1712779126.135 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 3922 2024-04-10T19:58:46.139Z,1712779126.139 [Supervisor](INFO): Main Thread ID is 3830 2024-04-10T19:58:46.139Z,1712779126.139 [Supervisor](DEBUG): Running supervisor. 2024-04-10T19:58:46.140Z,1712779126.140 [CommandExec ThreadHandler](INFO): Handler Thread ID is 3923 2024-04-10T19:58:46.142Z,1712779126.142 [CommandExec](INFO): Initializing the command executive. 2024-04-10T19:58:46.144Z,1712779126.144 [CommandLine ThreadHandler](INFO): Handler Thread ID is 3924 2024-04-10T19:58:46.146Z,1712779126.146 [controlThread ThreadHandler](INFO): Handler Thread ID is 3925 2024-04-10T19:58:46.146Z,1712779126.146 [controlThread](DEBUG): Initializing ControlThread 2024-04-10T19:58:46.147Z,1712779126.147 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2024-04-10T19:58:46.149Z,1712779126.149 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2024-04-10T19:58:46.150Z,1712779126.150 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2024-04-10T19:58:46.150Z,1712779126.150 [LoopControl](DEBUG): Initialize LoopControlComponent. 2024-04-10T19:58:46.152Z,1712779126.152 [NavChart](DEBUG): Initialize NavChart Navigation. 2024-04-10T19:58:46.153Z,1712779126.153 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2024-04-10T19:58:46.157Z,1712779126.157 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2024-04-10T19:58:46.157Z,1712779126.157 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2024-04-10T19:58:46.158Z,1712779126.158 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2024-04-10T19:58:46.158Z,1712779126.158 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2024-04-10T19:58:46.158Z,1712779126.158 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2024-04-10T19:58:46.163Z,1712779126.163 [SBIT](INFO): Initialize SBIT Component. 2024-04-10T19:58:46.164Z,1712779126.164 [SBIT](IMPORTANT): git: 2024-03-26 2024-04-10T19:58:46.164Z,1712779126.164 [SBIT](INFO): git hash: ad310a373d447f5044d653e05ec2c3eb1a52d830 2024-04-10T19:58:46.164Z,1712779126.164 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2024-04-10T19:58:46.165Z,1712779126.165 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018 Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021 2024-04-10T19:58:46.166Z,1712779126.166 [SBIT](INFO): Beginning SBIT in 100.000000 seconds. 2024-04-10T19:58:46.167Z,1712779126.167 [IBIT](INFO): Initialize IBIT Component. 2024-04-10T19:58:46.168Z,1712779126.168 [CBIT](DEBUG): Initialize CBIT Component. 2024-04-10T19:58:46.169Z,1712779126.169 [logger ThreadHandler](INFO): Handler Thread ID is 3926 2024-04-10T19:58:46.179Z,1712779126.179 [CBIT](DEBUG): Initialized mux pins. 2024-04-10T19:58:46.179Z,1712779126.179 [CBIT](DEBUG): Initializing the watchdog timer. 2024-04-10T19:58:46.188Z,1712779126.188 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 3927 2024-04-10T19:58:46.189Z,1712779126.189 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2024-04-10T19:58:46.200Z,1712779126.200 [Onboard ThreadHandler](INFO): Handler Thread ID is 3928 2024-04-10T19:58:46.204Z,1712779126.204 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2024-04-10T19:58:46.204Z,1712779126.204 [CBIT](DEBUG): Initializing heartbeat. 2024-04-10T19:58:46.220Z,1712779126.220 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 3929 2024-04-10T19:58:46.232Z,1712779126.232 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 3930 2024-04-10T19:58:46.232Z,1712779126.232 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2024-04-10T19:58:46.237Z,1712779126.237 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 3932 2024-04-10T19:58:46.245Z,1712779126.245 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2024-04-10T19:58:46.246Z,1712779126.246 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2024-04-10T19:58:46.246Z,1712779126.246 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2024-04-10T19:58:46.246Z,1712779126.246 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2024-04-10T19:58:46.246Z,1712779126.246 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2024-04-10T19:58:46.246Z,1712779126.246 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2024-04-10T19:58:46.246Z,1712779126.246 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2024-04-10T19:58:46.247Z,1712779126.247 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2024-04-10T19:58:46.275Z,1712779126.275 [CBIT](DEBUG): Deactivating GF circuits. 2024-04-10T19:58:46.275Z,1712779126.275 [CBIT](DEBUG): Deactivating emergency mode. 2024-04-10T19:58:46.315Z,1712779126.315 [CBIT](DEBUG): Backplane powered. 2024-04-10T19:58:46.316Z,1712779126.316 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser 2024-04-10T19:58:46.317Z,1712779126.317 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl 2024-04-10T19:58:46.317Z,1712779126.317 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl 2024-04-10T19:58:46.321Z,1712779126.321 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl 2024-04-10T19:58:46.372Z,1712779126.372 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into: 2024-04-10T19:58:46.393Z,1712779126.393 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2024-04-10T19:58:46.423Z,1712779126.423 [MissionManager](DEBUG): mission Startup { behavior Guidance:GoToSurface { run in progression } aggregate StartupSatComms { run in sequence readDatum { timeout duration=P1M Universal:latitude_fix } readDatum { timeout duration=P1M Universal:platform_communications } } } 2024-04-10T19:58:46.424Z,1712779126.424 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl 2024-04-10T19:58:46.424Z,1712779126.424 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl 2024-04-10T19:58:46.441Z,1712779126.441 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl 2024-04-10T19:58:46.623Z,1712779126.623 [Radio_Surface](INFO): Powering up 2024-04-10T19:58:46.726Z,1712779126.726 [MissionManager](DEBUG): TethyslAPI: Missions/Default.tl translated into: 0 13 Burn on Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2024-04-10T19:58:46.775Z,1712779126.775 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2024-04-10T19:58:46.776Z,1712779126.776 [Default:A.Wait](DEBUG): Construct Wait. 2024-04-10T19:58:46.778Z,1712779126.778 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2024-04-10T19:58:46.813Z,1712779126.813 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2024-04-10T19:58:46.816Z,1712779126.816 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2024-04-10T19:58:46.838Z,1712779126.838 [Default:E.Execute](DEBUG): Construct Execute. 2024-04-10T19:58:46.841Z,1712779126.841 [MissionManager](DEBUG): mission Default { arguments { ElapsedSinceDefaultStarted = 0 minute } behavior Guidance:Wait { """ Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. """ run in sequence set duration = 13 second } behavior Guidance:GoToSurface { run in progression } aggregate CheckIn { run in sequence repeat=288 readDatum id="Read_GPS" { timeout duration=P5M Universal:time_fix } readDatum id="Read_Iridium" { timeout duration=P4H { behavior Guidance:Execute { run in sequence set command = "Burn on" } syslog critical "Dropped weight due to communications timeout." } Universal:platform_communications } behavior Guidance:Wait { run in sequence set duration = 5 minute } assign in sequence ElapsedSinceDefaultStarted = elapsed ( Universal:mission_started ) syslog important "Default mission has been running for " + ElapsedSinceDefaultStarted~minute } syslog important "Restarting logs and Default mission." behavior Guidance:Execute { run in sequence set command = "restart logs" } } 2024-04-10T19:58:46.847Z,1712779126.847 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,PowerOnly,Power24vConverter,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2024-04-10T19:58:46.871Z,1712779126.871 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2024-04-10T19:58:46.987Z,1712779126.987 [PowerOnly](INFO): Powering up loadControl 2024-04-10T19:58:47.004Z,1712779127.004 [Power24vConverter](INFO): Powering up. 2024-04-10T19:58:47.004Z,1712779127.004 [CANONSampler](INFO): Powering down 2024-04-10T19:58:47.032Z,1712779127.032 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2024-04-10T19:58:47.039Z,1712779127.039 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2024-04-10T19:58:47.041Z,1712779127.040 [ElevatorServo](DEBUG): Initializing EZServoServo. 2024-04-10T19:58:47.047Z,1712779127.047 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2024-04-10T19:58:47.048Z,1712779127.048 [MassServo](DEBUG): Initializing EZServoServo. 2024-04-10T19:58:47.056Z,1712779127.056 [MassServo](DEBUG): Initializing MassServo. 2024-04-10T19:58:47.056Z,1712779127.056 [RudderServo](DEBUG): Initializing EZServoServo. 2024-04-10T19:58:47.063Z,1712779127.063 [RudderServo](DEBUG): Initializing RudderServo. 2024-04-10T19:58:47.064Z,1712779127.064 [ThrusterHE](DEBUG): Initializing EZServoServo. 2024-04-10T19:58:47.071Z,1712779127.071 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2024-04-10T19:58:52.752Z,1712779132.752 [ThrusterHE](ERROR): Zero Speed Commanded. 2024-04-10T19:58:53.263Z,1712779133.263 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit. 2024-04-10T19:58:59.898Z,1712779139.898 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004814 2024-04-10T19:59:14.737Z,1712779154.737 [NAL9602](INFO): Powering up NAL9602 2024-04-10T19:59:20.919Z,1712779160.919 [MassServo](ERROR): getPosition uart error serial timeout 2024-04-10T19:59:20.920Z,1712779160.920 [MassServo](FAULT): Invalid EZ Servo response:"" 2024-04-10T19:59:20.920Z,1712779160.920 [MassServo] Communications Fault, FailCount= 1 2024-04-10T19:59:20.920Z,1712779160.920 [MassServo](ERROR): Communications Fault 2024-04-10T19:59:20.924Z,1712779160.924 [CBIT](ERROR): Communications Fault in component: MassServo 2024-04-10T19:59:21.272Z,1712779161.272 [MassServo](DEBUG): Uninitialize Mass Servo. 2024-04-10T19:59:21.272Z,1712779161.272 [MassServo](INFO): Powering down 2024-04-10T19:59:22.050Z,1712779162.050 [MassServo](DEBUG): Initializing EZServoServo. 2024-04-10T19:59:22.168Z,1712779162.168 [MassServo](DEBUG): Initializing MassServo. 2024-04-10T19:59:22.173Z,1712779162.173 [CBIT](INFO): Clearing failed state for component MassServo 2024-04-10T19:59:22.173Z,1712779162.173 [MassServo] No Fault, FailCount= 1 2024-04-10T19:59:25.645Z,1712779165.645 [NAL9602](INFO): NAL9602 initialized 2024-04-10T19:59:26.179Z,1712779166.179 [MassServo](ERROR): getPosition uart error serial timeout 2024-04-10T19:59:26.179Z,1712779166.179 [MassServo](FAULT): Invalid EZ Servo response:"\r" 2024-04-10T19:59:26.180Z,1712779166.180 [MassServo] Communications Fault, FailCount= 2 2024-04-10T19:59:26.180Z,1712779166.180 [MassServo](ERROR): Communications Fault 2024-04-10T19:59:26.207Z,1712779166.207 [CBIT](ERROR): Communications Fault in component: MassServo 2024-04-10T19:59:26.517Z,1712779166.517 [MassServo](DEBUG): Uninitialize Mass Servo. 2024-04-10T19:59:26.517Z,1712779166.517 [MassServo](INFO): Powering down 2024-04-10T19:59:27.313Z,1712779167.313 [MassServo](DEBUG): Initializing EZServoServo. 2024-04-10T19:59:27.429Z,1712779167.429 [MassServo](DEBUG): Initializing MassServo. 2024-04-10T19:59:27.433Z,1712779167.433 [CBIT](INFO): Clearing failed state for component MassServo 2024-04-10T19:59:27.433Z,1712779167.433 [MassServo] No Fault, FailCount= 2 2024-04-10T20:00:26.685Z,1712779226.685 [SBIT](IMPORTANT): Beginning Startup BIT 2024-04-10T20:00:26.689Z,1712779226.689 [CBIT](IMPORTANT): Beginning ground fault scan 2024-04-10T20:00:37.660Z,1712779237.660 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan. 2024-04-10T20:00:38.036Z,1712779238.036 [CBIT](IMPORTANT): Beginning ground fault scan 2024-04-10T20:00:48.000Z,1712779249.000 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan. 2024-04-10T20:00:49.376Z,1712779249.376 [CBIT](IMPORTANT): Beginning ground fault scan 2024-04-10T20:01:00.261Z,1712779260.261 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan. 2024-04-10T20:01:00.261Z,1712779260.261 [CBIT](IMPORTANT): Ground fault scan returned out of bounds value in succession 3 times. Will re-run scan on normal schedule. 2024-04-10T20:01:20.804Z,1712779280.804 [SBIT](IMPORTANT): SBIT PASSED 2024-04-10T20:01:20.804Z,1712779280.804 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2024-04-10T20:01:20.805Z,1712779280.805 [SBIT](IMPORTANT): AMEcho.loadAtStartup=0 bool; 2024-04-10T20:01:20.805Z,1712779280.805 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=20 count; 2024-04-10T20:01:20.805Z,1712779280.805 [SBIT](IMPORTANT): CANONSampler.loadAtStartup=1 bool; 2024-04-10T20:01:20.805Z,1712779280.805 [SBIT](IMPORTANT): CBIT.runNavErrorCritical=0 bool; 2024-04-10T20:01:20.806Z,1712779280.806 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool; 2024-04-10T20:01:20.806Z,1712779280.806 [SBIT](IMPORTANT): Express linearApproximation PowerOnly.component_avgCurrent_loadControl 50.000000 milliampere; 2024-04-10T20:01:20.806Z,1712779280.806 [SBIT](IMPORTANT): IBIT.batteryCapacityThreshold=50 ampere_hour; 2024-04-10T20:01:20.806Z,1712779280.806 [SBIT](IMPORTANT): IBIT.batteryVoltageThreshold=13.7 volt; 2024-04-10T20:01:20.806Z,1712779280.806 [SBIT](IMPORTANT): PowerOnly.loadAtStartup=1 bool; 2024-04-10T20:01:20.806Z,1712779280.806 [SBIT](IMPORTANT): PowerOnly.sampleTime1=0 second; 2024-04-10T20:01:20.806Z,1712779280.806 [SBIT](IMPORTANT): PowerOnly.simulateHardware=0 bool; 2024-04-10T20:01:20.806Z,1712779280.806 [SBIT](IMPORTANT): RDI_Pathfinder.loadAtStartup=0 bool; 2024-04-10T20:01:20.807Z,1712779280.807 [SBIT](IMPORTANT): Sonardyne_Nano.loadAtStartup=0 bool; 2024-04-10T20:01:20.807Z,1712779280.807 [SBIT](IMPORTANT): ThrusterServo.currLimit=50 percent; 2024-04-10T20:01:20.807Z,1712779280.807 [SBIT](IMPORTANT): Vehicle.useTlLoader=1 bool; 2024-04-10T20:01:20.807Z,1712779280.807 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=363.127377 cubic_centimeter; 2024-04-10T20:01:20.807Z,1712779280.807 [SBIT](IMPORTANT): VerticalControl.massDefault=-20.191686 millimeter; 2024-04-10T20:01:20.807Z,1712779280.807 [SBIT](IMPORTANT): WetLabsBB2FL.loadAtStartup=0 bool; 2024-04-10T20:01:21.231Z,1712779281.231 [MissionManager](IMPORTANT): Started mission Startup 2024-04-10T20:01:21.232Z,1712779281.232 [Startup] Running Loop=1 2024-04-10T20:01:21.232Z,1712779281.232 [Startup](DEBUG): Aggregate::initialize Startup 2024-04-10T20:01:21.232Z,1712779281.232 [Startup:A.GoToSurface] Running Loop=1 2024-04-10T20:01:21.232Z,1712779281.232 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2024-04-10T20:01:21.232Z,1712779281.232 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2024-04-10T20:01:21.233Z,1712779281.233 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2024-04-10T20:01:21.233Z,1712779281.233 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2024-04-10T20:01:21.233Z,1712779281.233 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2024-04-10T20:01:21.234Z,1712779281.234 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2024-04-10T20:01:21.235Z,1712779281.235 [Startup:StartupSatComms] Running Loop=1 2024-04-10T20:01:21.235Z,1712779281.235 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2024-04-10T20:01:21.235Z,1712779281.235 [Startup:StartupSatComms:A] Running Loop=1 2024-04-10T20:01:21.621Z,1712779281.621 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2024-04-10T20:01:40.261Z,1712779300.261 [CommandExec](IMPORTANT): got command failComponent 2024-04-10T20:01:40.261Z,1712779300.261 [CommandExec](IMPORTANT): Failed components: 2024-04-10T20:01:40.262Z,1712779300.262 [CommandExec](IMPORTANT): No failed Components. 2024-04-10T20:01:41.860Z,1712779301.860 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-10T20:01:46.265Z,1712779306.265 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2024-04-10T20:01:46.265Z,1712779306.265 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-04-10T20:01:46.295Z,1712779306.295 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-04-10T20:01:46.671Z,1712779306.671 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-04-10T20:01:46.672Z,1712779306.672 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2024-04-10T20:01:49.188Z,1712779309.188 [CommandExec](IMPORTANT): got command get Onboard.Pressure 2024-04-10T20:01:49.188Z,1712779309.188 [CommandExec](IMPORTANT): Onboard.Pressure 67430.117188 Pa 2024-04-10T20:01:55.267Z,1712779315.267 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-10T20:02:02.389Z,1712779322.389 [CommandExec](IMPORTANT): got command get Onboard.Humidity 2024-04-10T20:02:02.390Z,1712779322.390 [CommandExec](IMPORTANT): Onboard.Humidity 13.252349 % 2024-04-10T20:02:07.657Z,1712779327.657 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-10T20:02:20.585Z,1712779340.585 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-10T20:02:21.476Z,1712779341.476 [Startup:StartupSatComms:A](INFO): Timed out from 2024-04-10T20:01:21.2Z 2024-04-10T20:02:21.476Z,1712779341.476 [Startup:StartupSatComms:A] Stopped 2024-04-10T20:02:21.476Z,1712779341.476 [Startup:StartupSatComms:B] Running Loop=1 2024-04-10T20:02:21.884Z,1712779341.884 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2024-04-10T20:02:26.488Z,1712779346.488 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20240327T173606/Courier0069.lzma 2024-04-10T20:02:27.489Z,1712779347.489 [DataOverHttps](INFO): Moved sent file to Logs/20240327T173606/Courier0069.lzma.bak 2024-04-10T20:02:27.489Z,1712779347.489 [DataOverHttps](INFO): SBD MOMSN=19396439 2024-04-10T20:02:33.685Z,1712779353.685 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-10T20:02:43.052Z,1712779363.052 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20240410T195833/Courier0000.lzma 2024-04-10T20:02:44.053Z,1712779364.053 [DataOverHttps](INFO): Moved sent file to Logs/20240410T195833/Courier0000.lzma.bak 2024-04-10T20:02:44.053Z,1712779364.053 [DataOverHttps](INFO): SBD MOMSN=19396441 2024-04-10T20:02:47.017Z,1712779367.017 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-10T20:02:59.945Z,1712779379.945 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-10T20:03:00.012Z,1712779380.012 [DataOverHttps](INFO): Sending 220 bytes from file Logs/20240327T173606/Express0070.lzma 2024-04-10T20:03:01.009Z,1712779381.009 [DataOverHttps](INFO): Moved sent file to Logs/20240327T173606/Express0070.lzma.bak 2024-04-10T20:03:01.009Z,1712779381.009 [DataOverHttps](INFO): SBD MOMSN=19396444 2024-04-10T20:03:12.873Z,1712779392.873 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-10T20:03:15.593Z,1712779395.593 [DataOverHttps](INFO): Sending 1186 bytes from file Logs/20240410T195833/Express0001.lzma 2024-04-10T20:03:16.593Z,1712779396.593 [DataOverHttps](INFO): Moved sent file to Logs/20240410T195833/Express0001.lzma.bak 2024-04-10T20:03:16.593Z,1712779396.593 [DataOverHttps](INFO): SBD MOMSN=19396453 2024-04-10T20:03:18.144Z,1712779398.144 [Startup:StartupSatComms:B] Stopped 2024-04-10T20:03:18.144Z,1712779398.144 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2024-04-10T20:03:18.145Z,1712779398.145 [Startup:StartupSatComms] Stopped 2024-04-10T20:03:18.145Z,1712779398.145 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2024-04-10T20:03:18.145Z,1712779398.145 [Startup](INFO): Completed Startup 2024-04-10T20:03:18.146Z,1712779398.146 [MissionManager](INFO): Startup is completed. 2024-04-10T20:03:18.146Z,1712779398.146 [MissionManager](INFO): Uninitializing Mission Startup 2024-04-10T20:03:18.146Z,1712779398.146 [Startup] Stopped 2024-04-10T20:03:18.146Z,1712779398.146 [Startup](DEBUG): Aggregate::uninitialize Startup 2024-04-10T20:03:18.146Z,1712779398.146 [Startup:A.GoToSurface] Stopped 2024-04-10T20:03:18.146Z,1712779398.146 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2024-04-10T20:03:18.546Z,1712779398.546 [MissionManager](IMPORTANT): Started mission Default 2024-04-10T20:03:18.546Z,1712779398.546 [Default] Running Loop=1 2024-04-10T20:03:18.546Z,1712779398.546 [Default](DEBUG): Aggregate::initialize Default 2024-04-10T20:03:18.546Z,1712779398.546 [Default:B.GoToSurface] Running Loop=1 2024-04-10T20:03:18.547Z,1712779398.547 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2024-04-10T20:03:18.547Z,1712779398.547 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2024-04-10T20:03:18.547Z,1712779398.547 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2024-04-10T20:03:18.548Z,1712779398.548 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2024-04-10T20:03:18.548Z,1712779398.548 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2024-04-10T20:03:18.548Z,1712779398.548 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2024-04-10T20:03:18.548Z,1712779398.548 [Default:A.Wait] Running Loop=1 2024-04-10T20:03:18.549Z,1712779398.549 [Default:A.Wait](DEBUG): Initialize Wait Component. 2024-04-10T20:03:25.801Z,1712779405.801 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-10T20:03:31.901Z,1712779411.901 [Default:A.Wait](INFO): Done Waiting. 2024-04-10T20:03:31.901Z,1712779411.901 [Default:A.Wait] Stopped 2024-04-10T20:03:31.901Z,1712779411.901 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2024-04-10T20:03:32.325Z,1712779412.325 [Default:CheckIn] Running Loop=1 2024-04-10T20:03:32.325Z,1712779412.325 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-04-10T20:03:32.325Z,1712779412.325 [Default:CheckIn:Read_GPS] Running Loop=1 2024-04-10T20:03:32.689Z,1712779412.689 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2024-04-10T20:03:36.716Z,1712779416.716 [CommandExec](IMPORTANT): got command ibit 2024-04-10T20:03:36.790Z,1712779416.790 [IBIT](IMPORTANT): Beginning Initiated BIT 2024-04-10T20:03:36.790Z,1712779416.790 [IBIT](IMPORTANT): Beginning control surface checks. 2024-04-10T20:03:36.797Z,1712779416.797 [CBIT](IMPORTANT): Beginning ground fault scan 2024-04-10T20:03:39.133Z,1712779419.133 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-10T20:03:47.642Z,1712779427.642 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan. 2024-04-10T20:03:48.052Z,1712779428.052 [CBIT](IMPORTANT): Beginning ground fault scan 2024-04-10T20:03:52.061Z,1712779432.061 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-10T20:03:59.060Z,1712779439.060 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan. 2024-04-10T20:03:59.552Z,1712779439.552 [CBIT](IMPORTANT): Beginning ground fault scan 2024-04-10T20:04:10.388Z,1712779450.388 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan. 2024-04-10T20:04:10.389Z,1712779450.389 [CBIT](IMPORTANT): Ground fault scan returned out of bounds value in succession 3 times. Will re-run scan on normal schedule. 2024-04-10T20:04:29.238Z,1712779469.238 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2024-04-10T20:04:47.434Z,1712779487.434 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2024-04-10T20:04:47.434Z,1712779487.434 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-04-10T20:04:47.472Z,1712779487.472 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-04-10T20:04:47.836Z,1712779487.836 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-04-10T20:04:47.836Z,1712779487.836 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2024-04-10T20:05:27.457Z,1712779527.457 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired. 2024-04-10T20:05:27.848Z,1712779527.848 [IBIT](FAULT): Warning: Battery Data not active. Expected only when running primaries. Threshold checking not active. 2024-04-10T20:05:28.308Z,1712779528.308 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2024-04-10T20:05:28.308Z,1712779528.308 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2024-04-10T20:05:28.309Z,1712779528.309 [IBIT](IMPORTANT): Pressure:9.809140 PSI 2024-04-10T20:05:28.309Z,1712779528.309 [IBIT](IMPORTANT): Humidity:13.252349 % 2024-04-10T20:05:28.658Z,1712779528.658 [IBIT](IMPORTANT): Vehicle Pitch:-0.885002 degrees 2024-04-10T20:05:28.658Z,1712779528.658 [IBIT](IMPORTANT): Vehicle Roll:6.051240 degrees 2024-04-10T20:05:28.659Z,1712779528.659 [IBIT](IMPORTANT): Vehicle Heading:199.044052 degrees 2024-04-10T20:05:29.062Z,1712779529.062 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m 2024-04-10T20:05:29.063Z,1712779529.063 [IBIT](IMPORTANT): buoyancyNeutral: 363.127380 cc 2024-04-10T20:05:29.063Z,1712779529.063 [IBIT](IMPORTANT): massDefault: -2.019169 cm 2024-04-10T20:05:29.063Z,1712779529.063 [IBIT](IMPORTANT): stopDepth: 250.000000 m 2024-04-10T20:05:29.064Z,1712779529.064 [IBIT](IMPORTANT): abortDepth: 270.000000 m 2024-04-10T20:05:29.064Z,1712779529.064 [IBIT](IMPORTANT): IBIT FAILED 2024-04-10T20:06:17.516Z,1712779577.516 [BPC1](INFO): Calculating totals. Valid battery stick count: 39. Valid reserve battery stick count: 3. 2024-04-10T20:06:17.520Z,1712779577.520 [BPC1](INFO): Received data from all battery sticks. 2024-04-10T20:07:48.438Z,1712779668.438 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2024-04-10T20:07:48.438Z,1712779668.438 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-04-10T20:07:48.449Z,1712779668.449 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-04-10T20:07:48.854Z,1712779668.854 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-04-10T20:07:48.854Z,1712779668.854 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2024-04-10T20:08:32.461Z,1712779712.461 [Default:CheckIn:Read_GPS](INFO): Timed out from 2024-04-10T20:03:32.3Z 2024-04-10T20:08:32.461Z,1712779712.461 [Default:CheckIn:Read_GPS] Stopped 2024-04-10T20:08:32.462Z,1712779712.462 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-04-10T20:08:32.866Z,1712779712.866 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2024-04-10T20:08:39.467Z,1712779719.467 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20240410T195833/Courier0004.lzma 2024-04-10T20:08:40.721Z,1712779720.721 [DataOverHttps](INFO): Moved sent file to Logs/20240410T195833/Courier0004.lzma.bak 2024-04-10T20:08:40.721Z,1712779720.721 [DataOverHttps](INFO): SBD MOMSN=19396534 2024-04-10T20:08:55.988Z,1712779735.988 [DataOverHttps](INFO): Sending 711 bytes from file Logs/20240410T195833/Express0005.lzma 2024-04-10T20:08:56.989Z,1712779736.989 [DataOverHttps](INFO): Moved sent file to Logs/20240410T195833/Express0005.lzma.bak 2024-04-10T20:08:56.989Z,1712779736.989 [DataOverHttps](INFO): SBD MOMSN=19396537 2024-04-10T20:08:58.330Z,1712779738.330 [Default:CheckIn:Read_Iridium] Stopped 2024-04-10T20:08:58.330Z,1712779738.330 [Default:CheckIn:C.Wait] Running Loop=1 2024-04-10T20:08:58.330Z,1712779738.330 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-04-10T20:09:27.397Z,1712779767.397 [NAL9602](FAULT): GPS failed to acquire within timeout. 2024-04-10T20:09:27.397Z,1712779767.397 [NAL9602] Data Fault, FailCount= 1 2024-04-10T20:09:27.397Z,1712779767.397 [NAL9602](ERROR): Data Fault 2024-04-10T20:09:27.456Z,1712779767.456 [CBIT](ERROR): Data Fault in component: NAL9602 2024-04-10T20:09:27.800Z,1712779767.800 [NAL9602](INFO): Powering down 2024-04-10T20:09:28.627Z,1712779768.627 [CBIT](INFO): Clearing failed state for component NAL9602 2024-04-10T20:09:28.627Z,1712779768.627 [NAL9602] No Fault, FailCount= 1 2024-04-10T20:09:58.105Z,1712779798.105 [NAL9602](INFO): Powering up NAL9602 2024-04-10T20:10:09.009Z,1712779809.009 [NAL9602](INFO): NAL9602 initialized 2024-04-10T20:10:49.416Z,1712779849.416 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2024-04-10T20:10:49.416Z,1712779849.416 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-04-10T20:10:49.442Z,1712779849.442 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-04-10T20:10:49.829Z,1712779849.829 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-04-10T20:10:49.829Z,1712779849.829 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2024-04-10T20:13:50.414Z,1712780030.414 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2024-04-10T20:13:50.414Z,1712780030.414 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-04-10T20:13:50.425Z,1712780030.425 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-04-10T20:13:50.834Z,1712780030.834 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-04-10T20:13:50.834Z,1712780030.834 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2024-04-10T20:13:58.907Z,1712780038.907 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-04-10T20:13:58.907Z,1712780038.907 [Default:CheckIn:C.Wait] Stopped 2024-04-10T20:13:58.907Z,1712780038.907 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-04-10T20:13:58.907Z,1712780038.907 [Default:CheckIn:D] Running Loop=1 2024-04-10T20:13:59.310Z,1712780039.310 [Default:CheckIn:D] Stopped 2024-04-10T20:13:59.310Z,1712780039.310 [Default:CheckIn:E] Running Loop=1 2024-04-10T20:13:59.701Z,1712780039.701 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.679391 min 2024-04-10T20:13:59.701Z,1712780039.701 [Default:CheckIn:E] Stopped 2024-04-10T20:13:59.701Z,1712780039.701 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-04-10T20:13:59.701Z,1712780039.701 [Default:CheckIn] Stopped 2024-04-10T20:13:59.701Z,1712780039.701 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-04-10T20:13:59.702Z,1712780039.702 [Default:CheckIn](INFO): Running loop #2 2024-04-10T20:13:59.702Z,1712780039.702 [Default:CheckIn] Running Loop=2 2024-04-10T20:13:59.702Z,1712780039.702 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-04-10T20:13:59.702Z,1712780039.702 [Default:CheckIn:Read_GPS] Running Loop=1 2024-04-10T20:16:51.410Z,1712780211.410 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2024-04-10T20:16:51.410Z,1712780211.410 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-04-10T20:16:51.441Z,1712780211.441 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-04-10T20:16:51.862Z,1712780211.862 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-04-10T20:16:51.862Z,1712780211.862 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2024-04-10T20:18:59.898Z,1712780339.898 [Default:CheckIn:Read_GPS](INFO): Timed out from 2024-04-10T20:13:59.7Z 2024-04-10T20:18:59.898Z,1712780339.898 [Default:CheckIn:Read_GPS] Stopped 2024-04-10T20:18:59.898Z,1712780339.898 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-04-10T20:19:06.931Z,1712780346.931 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20240410T195833/Courier0007.lzma 2024-04-10T20:19:07.933Z,1712780347.933 [DataOverHttps](INFO): Moved sent file to Logs/20240410T195833/Courier0007.lzma.bak 2024-04-10T20:19:07.933Z,1712780347.933 [DataOverHttps](INFO): SBD MOMSN=19396649 2024-04-10T20:19:23.408Z,1712780363.408 [DataOverHttps](INFO): Sending 192 bytes from file Logs/20240410T195833/Express0008.lzma 2024-04-10T20:19:24.409Z,1712780364.409 [DataOverHttps](INFO): Moved sent file to Logs/20240410T195833/Express0008.lzma.bak 2024-04-10T20:19:24.409Z,1712780364.409 [DataOverHttps](INFO): SBD MOMSN=19396651 2024-04-10T20:19:25.757Z,1712780365.757 [Default:CheckIn:Read_Iridium] Stopped 2024-04-10T20:19:25.757Z,1712780365.757 [Default:CheckIn:C.Wait] Running Loop=1 2024-04-10T20:19:25.757Z,1712780365.757 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-04-10T20:19:52.409Z,1712780392.409 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7 2024-04-10T20:19:52.409Z,1712780392.409 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-04-10T20:19:52.419Z,1712780392.419 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-04-10T20:19:52.826Z,1712780392.826 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-04-10T20:19:52.826Z,1712780392.826 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7 2024-04-10T20:20:04.103Z,1712780404.103 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202003.00,A,3648.17729,N,12147.28596,W,0.039,0.00,100424,,,A*74 2024-04-10T20:20:04.129Z,1712780404.129 [NAL9602](INFO): GPS fix at 20240410T202003: (36.802955, -121.788099) 2024-04-10T20:20:36.437Z,1712780436.437 [NAL9602](INFO): Not Powering down - fast GPS 2024-04-10T20:22:35.273Z,1712780555.273 [DataOverHttps](IMPORTANT): SBD MTMSN=20240410T202234 2024-04-10T20:22:42.559Z,1712780562.559 [DataOverHttps](INFO): Received command: ibit 2024-04-10T20:22:42.580Z,1712780562.580 [CommandExec](IMPORTANT): got command ibit 2024-04-10T20:22:42.910Z,1712780562.910 [IBIT](IMPORTANT): Beginning Initiated BIT 2024-04-10T20:22:42.910Z,1712780562.910 [IBIT](IMPORTANT): Beginning control surface checks. 2024-04-10T20:22:42.913Z,1712780562.913 [CBIT](IMPORTANT): Beginning ground fault scan 2024-04-10T20:22:44.510Z,1712780564.510 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202243.00,A,3648.17759,N,12147.28581,W,0.019,0.00,100424,,,A*71 2024-04-10T20:22:44.513Z,1712780564.513 [NAL9602](INFO): GPS fix at 20240410T202243: (36.802960, -121.788097) 2024-04-10T20:22:53.832Z,1712780573.832 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan. 2024-04-10T20:22:54.269Z,1712780574.269 [CBIT](IMPORTANT): Beginning ground fault scan 2024-04-10T20:23:05.176Z,1712780585.176 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan. 2024-04-10T20:23:05.629Z,1712780585.629 [CBIT](IMPORTANT): Beginning ground fault scan 2024-04-10T20:23:06.318Z,1712780586.318 [NAL9602](INFO): SBD MO Status=2, MOMSN=49373, MT Status=2, MTMSN=0 2024-04-10T20:23:06.318Z,1712780586.318 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-04-10T20:23:16.015Z,1712780596.015 [NAL9602](INFO): SBD MO Status=0, MOMSN=49373, MT Status=0, MTMSN=0 2024-04-10T20:23:16.016Z,1712780596.016 [NAL9602](INFO): No messages in MT queue 2024-04-10T20:23:16.504Z,1712780596.504 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan. 2024-04-10T20:23:16.504Z,1712780596.504 [CBIT](IMPORTANT): Ground fault scan returned out of bounds value in succession 3 times. Will re-run scan on normal schedule. 2024-04-10T20:23:17.226Z,1712780597.226 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202316.00,A,3648.17750,N,12147.28577,W,0.039,0.00,100424,,,A*72 2024-04-10T20:23:17.228Z,1712780597.228 [NAL9602](INFO): GPS fix at 20240410T202316: (36.802958, -121.788096) 2024-04-10T20:23:20.058Z,1712780600.058 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202319.00,A,3648.17747,N,12147.28576,W,0.019,0.00,100424,,,A*78 2024-04-10T20:23:20.060Z,1712780600.060 [NAL9602](INFO): GPS fix at 20240410T202319: (36.802958, -121.788096) 2024-04-10T20:23:22.886Z,1712780602.886 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202322.00,A,3648.17744,N,12147.28574,W,0.058,0.00,100424,,,A*74 2024-04-10T20:23:22.888Z,1712780602.888 [NAL9602](INFO): GPS fix at 20240410T202322: (36.802957, -121.788096) 2024-04-10T20:23:26.122Z,1712780606.122 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202325.00,A,3648.17738,N,12147.28572,W,0.019,0.00,100424,,,A*7B 2024-04-10T20:23:26.124Z,1712780606.124 [NAL9602](INFO): GPS fix at 20240410T202325: (36.802956, -121.788095) 2024-04-10T20:23:28.946Z,1712780608.946 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202328.00,A,3648.17732,N,12147.28569,W,0.019,0.00,100424,,,A*76 2024-04-10T20:23:28.948Z,1712780608.948 [NAL9602](INFO): GPS fix at 20240410T202328: (36.802955, -121.788095) 2024-04-10T20:23:28.977Z,1712780608.977 [IBIT](IMPORTANT): Communications Status: Fix Status: 1 Iridium Signal Strength: 3 Latitude: 36.802956 Longitude: -121.788094 2024-04-10T20:23:29.409Z,1712780609.409 [IBIT](IMPORTANT): Battery Status: Battery Charge (AH): 0.000000 Voltage: 15.580000 2024-04-10T20:23:29.410Z,1712780609.410 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah 2024-04-10T20:23:29.410Z,1712780609.410 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V 2024-04-10T20:23:29.766Z,1712780609.766 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2024-04-10T20:23:29.767Z,1712780609.767 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2024-04-10T20:23:29.767Z,1712780609.767 [IBIT](IMPORTANT): Pressure:9.786630 PSI 2024-04-10T20:23:29.767Z,1712780609.767 [IBIT](IMPORTANT): Humidity:13.179100 % 2024-04-10T20:23:30.186Z,1712780610.186 [IBIT](IMPORTANT): Vehicle Pitch:-0.879861 degrees 2024-04-10T20:23:30.186Z,1712780610.186 [IBIT](IMPORTANT): Vehicle Roll:6.919568 degrees 2024-04-10T20:23:30.187Z,1712780610.187 [IBIT](IMPORTANT): Vehicle Heading:193.083740 degrees 2024-04-10T20:23:30.605Z,1712780610.605 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m 2024-04-10T20:23:30.605Z,1712780610.605 [IBIT](IMPORTANT): buoyancyNeutral: 363.127380 cc 2024-04-10T20:23:30.606Z,1712780610.606 [IBIT](IMPORTANT): massDefault: -2.019169 cm 2024-04-10T20:23:30.606Z,1712780610.606 [IBIT](IMPORTANT): stopDepth: 250.000000 m 2024-04-10T20:23:30.606Z,1712780610.606 [IBIT](IMPORTANT): abortDepth: 270.000000 m 2024-04-10T20:23:30.606Z,1712780610.606 [IBIT](IMPORTANT): IBIT PASSED 2024-04-10T20:24:01.264Z,1712780641.264 [NAL9602](INFO): Not Powering down - fast GPS 2024-04-10T20:24:26.351Z,1712780666.351 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-04-10T20:24:26.351Z,1712780666.351 [Default:CheckIn:C.Wait] Stopped 2024-04-10T20:24:26.351Z,1712780666.351 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-04-10T20:24:26.355Z,1712780666.355 [Default:CheckIn:D] Running Loop=1 2024-04-10T20:24:26.724Z,1712780666.724 [Default:CheckIn:D] Stopped 2024-04-10T20:24:26.725Z,1712780666.725 [Default:CheckIn:E] Running Loop=1 2024-04-10T20:24:27.135Z,1712780667.135 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.136302 min 2024-04-10T20:24:27.135Z,1712780667.135 [Default:CheckIn:E] Stopped 2024-04-10T20:24:27.135Z,1712780667.135 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-04-10T20:24:27.135Z,1712780667.135 [Default:CheckIn] Stopped 2024-04-10T20:24:27.136Z,1712780667.136 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-04-10T20:24:27.136Z,1712780667.136 [Default:CheckIn](INFO): Running loop #3 2024-04-10T20:24:27.136Z,1712780667.136 [Default:CheckIn] Running Loop=3 2024-04-10T20:24:27.136Z,1712780667.136 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-04-10T20:24:27.136Z,1712780667.136 [Default:CheckIn:Read_GPS] Running Loop=1 2024-04-10T20:24:29.138Z,1712780669.138 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202428.00,A,3648.17733,N,12147.28562,W,0.019,0.00,100424,,,A*7B 2024-04-10T20:24:29.140Z,1712780669.140 [NAL9602](INFO): GPS fix at 20240410T202428: (36.802956, -121.788094) 2024-04-10T20:24:29.174Z,1712780669.174 [Default:CheckIn:Read_GPS] Stopped 2024-04-10T20:24:29.174Z,1712780669.174 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-04-10T20:24:36.840Z,1712780676.840 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20240410T195833/Courier0010.lzma 2024-04-10T20:24:37.841Z,1712780677.841 [DataOverHttps](INFO): Moved sent file to Logs/20240410T195833/Courier0010.lzma.bak 2024-04-10T20:24:37.841Z,1712780677.841 [DataOverHttps](INFO): SBD MOMSN=19396704 2024-04-10T20:24:46.514Z,1712780686.514 [NAL9602](INFO): SBD MO Status=2, MOMSN=49374, MT Status=2, MTMSN=0 2024-04-10T20:24:46.514Z,1712780686.514 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-04-10T20:24:57.412Z,1712780697.412 [DataOverHttps](INFO): Sending 864 bytes from file Logs/20240410T195833/Express0011.lzma 2024-04-10T20:24:58.413Z,1712780698.413 [DataOverHttps](INFO): Moved sent file to Logs/20240410T195833/Express0011.lzma.bak 2024-04-10T20:24:58.413Z,1712780698.413 [DataOverHttps](INFO): SBD MOMSN=19396707 2024-04-10T20:25:14.399Z,1712780714.399 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20240410T195833/Express0014.lzma 2024-04-10T20:25:15.401Z,1712780715.401 [DataOverHttps](INFO): Moved sent file to Logs/20240410T195833/Express0014.lzma.bak 2024-04-10T20:25:15.401Z,1712780715.401 [DataOverHttps](INFO): SBD MOMSN=19396735 2024-04-10T20:25:16.895Z,1712780716.895 [Default:CheckIn:Read_Iridium] Stopped 2024-04-10T20:25:16.895Z,1712780716.895 [Default:CheckIn:C.Wait] Running Loop=1 2024-04-10T20:25:16.895Z,1712780716.895 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-04-10T20:25:27.784Z,1712780727.784 [NAL9602](INFO): SBD MO Status=2, MOMSN=49374, MT Status=2, MTMSN=0 2024-04-10T20:25:27.784Z,1712780727.784 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-04-10T20:25:50.007Z,1712780750.007 [NAL9602](INFO): SBD MO Status=0, MOMSN=49374, MT Status=0, MTMSN=0 2024-04-10T20:25:50.007Z,1712780750.007 [NAL9602](INFO): No messages in MT queue 2024-04-10T20:26:20.712Z,1712780780.712 [NAL9602](INFO): Not Powering down - fast GPS 2024-04-10T20:30:17.305Z,1712781017.305 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-04-10T20:30:17.305Z,1712781017.305 [Default:CheckIn:C.Wait] Stopped 2024-04-10T20:30:17.305Z,1712781017.305 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-04-10T20:30:17.305Z,1712781017.305 [Default:CheckIn:D] Running Loop=1 2024-04-10T20:30:17.719Z,1712781017.719 [Default:CheckIn:D] Stopped 2024-04-10T20:30:17.720Z,1712781017.720 [Default:CheckIn:E] Running Loop=1 2024-04-10T20:30:18.102Z,1712781018.102 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 26.986220 min 2024-04-10T20:30:18.102Z,1712781018.102 [Default:CheckIn:E] Stopped 2024-04-10T20:30:18.102Z,1712781018.102 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-04-10T20:30:18.102Z,1712781018.102 [Default:CheckIn] Stopped 2024-04-10T20:30:18.102Z,1712781018.102 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-04-10T20:30:18.102Z,1712781018.102 [Default:CheckIn](INFO): Running loop #4 2024-04-10T20:30:18.102Z,1712781018.102 [Default:CheckIn] Running Loop=4 2024-04-10T20:30:18.103Z,1712781018.103 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-04-10T20:30:18.103Z,1712781018.103 [Default:CheckIn:Read_GPS] Running Loop=1 2024-04-10T20:30:20.085Z,1712781020.085 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203019.00,A,3648.17206,N,12147.28468,W,0.019,189.51,100424,,,A*70 2024-04-10T20:30:20.087Z,1712781020.088 [NAL9602](INFO): GPS fix at 20240410T203019: (36.802868, -121.788078) 2024-04-10T20:30:20.106Z,1712781020.106 [Default:CheckIn:Read_GPS] Stopped 2024-04-10T20:30:20.106Z,1712781020.106 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-04-10T20:30:30.446Z,1712781030.446 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20240410T195833/Courier0016.lzma 2024-04-10T20:30:31.445Z,1712781031.445 [DataOverHttps](INFO): Moved sent file to Logs/20240410T195833/Courier0016.lzma.bak 2024-04-10T20:30:31.445Z,1712781031.445 [DataOverHttps](INFO): SBD MOMSN=19396750 2024-04-10T20:30:43.326Z,1712781043.326 [NAL9602](INFO): SBD MO Status=2, MOMSN=49375, MT Status=2, MTMSN=0 2024-04-10T20:30:43.326Z,1712781043.326 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-04-10T20:30:47.383Z,1712781047.383 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20240410T195833/Express0017.lzma 2024-04-10T20:30:48.385Z,1712781048.385 [DataOverHttps](INFO): Moved sent file to Logs/20240410T195833/Express0017.lzma.bak 2024-04-10T20:30:48.385Z,1712781048.385 [DataOverHttps](INFO): SBD MOMSN=19396753 2024-04-10T20:30:50.219Z,1712781050.219 [Default:CheckIn:Read_Iridium] Stopped 2024-04-10T20:30:50.219Z,1712781050.219 [Default:CheckIn:C.Wait] Running Loop=1 2024-04-10T20:30:50.220Z,1712781050.220 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-04-10T20:32:51.864Z,1712781171.864 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-04-10T20:33:22.987Z,1712781202.987 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-04-10T20:35:22.592Z,1712781322.592 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2024-04-10T20:35:50.894Z,1712781350.894 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-04-10T20:35:50.894Z,1712781350.894 [Default:CheckIn:C.Wait] Stopped 2024-04-10T20:35:50.894Z,1712781350.894 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-04-10T20:35:50.894Z,1712781350.894 [Default:CheckIn:D] Running Loop=1 2024-04-10T20:35:51.282Z,1712781351.282 [Default:CheckIn:D] Stopped 2024-04-10T20:35:51.283Z,1712781351.283 [Default:CheckIn:E] Running Loop=1 2024-04-10T20:35:51.687Z,1712781351.687 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 32.545601 min 2024-04-10T20:35:51.687Z,1712781351.687 [Default:CheckIn:E] Stopped 2024-04-10T20:35:51.688Z,1712781351.688 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-04-10T20:35:51.688Z,1712781351.688 [Default:CheckIn] Stopped 2024-04-10T20:35:51.688Z,1712781351.688 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-04-10T20:35:51.688Z,1712781351.688 [Default:CheckIn](INFO): Running loop #5 2024-04-10T20:35:51.688Z,1712781351.688 [Default:CheckIn] Running Loop=5 2024-04-10T20:35:51.688Z,1712781351.688 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-04-10T20:35:51.688Z,1712781351.688 [Default:CheckIn:Read_GPS] Running Loop=1 2024-04-10T20:35:53.706Z,1712781353.706 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203552.00,A,3648.16612,N,12147.28268,W,0.175,205.09,100424,,,A*7D 2024-04-10T20:35:53.709Z,1712781353.709 [NAL9602](INFO): GPS fix at 20240410T203552: (36.802769, -121.788045) 2024-04-10T20:35:53.724Z,1712781353.724 [Default:CheckIn:Read_GPS] Stopped 2024-04-10T20:35:53.724Z,1712781353.724 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-04-10T20:36:00.779Z,1712781360.779 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240410T195833/Courier0019.lzma 2024-04-10T20:36:01.781Z,1712781361.781 [DataOverHttps](INFO): Moved sent file to Logs/20240410T195833/Courier0019.lzma.bak 2024-04-10T20:36:01.781Z,1712781361.781 [DataOverHttps](INFO): SBD MOMSN=19396807 2024-04-10T20:36:17.592Z,1712781377.592 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20240410T195833/Express0020.lzma 2024-04-10T20:36:18.593Z,1712781378.593 [DataOverHttps](INFO): Moved sent file to Logs/20240410T195833/Express0020.lzma.bak 2024-04-10T20:36:18.594Z,1712781378.594 [DataOverHttps](INFO): SBD MOMSN=19396810 2024-04-10T20:36:20.459Z,1712781380.459 [Default:CheckIn:Read_Iridium] Stopped 2024-04-10T20:36:20.459Z,1712781380.459 [Default:CheckIn:C.Wait] Running Loop=1 2024-04-10T20:36:20.459Z,1712781380.459 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-04-10T20:36:26.480Z,1712781386.480 [NAL9602](INFO): Not Powering down - fast GPS 2024-04-10T20:38:13.378Z,1712781493.378 [CommandExec](IMPORTANT): got command maintain control VerticalControl.buoyancyAction 200 cubic_centimeter 2024-04-10T20:38:13.382Z,1712781493.382 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.buoyancyAction" handled in the control thread. 2024-04-10T20:38:13.622Z,1712781493.622 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,PowerOnly,Power24vConverter,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.buoyancyAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2024-04-10T20:38:32.021Z,1712781512.021 [CommandExec](IMPORTANT): got command get platform_buoyancy_position 2024-04-10T20:38:32.021Z,1712781512.021 [CommandExec](IMPORTANT): platform_buoyancy_position 799.746460 cc 2024-04-10T20:38:35.752Z,1712781515.752 [CommandExec](IMPORTANT): got command get platform_buoyancy_position 2024-04-10T20:38:35.755Z,1712781515.755 [CommandExec](IMPORTANT): platform_buoyancy_position 752.338562 cc 2024-04-10T20:38:40.131Z,1712781520.131 [CommandExec](IMPORTANT): got command get platform_buoyancy_position 2024-04-10T20:38:40.132Z,1712781520.132 [CommandExec](IMPORTANT): platform_buoyancy_position 694.455261 cc 2024-04-10T20:38:46.170Z,1712781526.170 [CommandExec](IMPORTANT): got command get platform_buoyancy_position 2024-04-10T20:38:46.171Z,1712781526.171 [CommandExec](IMPORTANT): platform_buoyancy_position 614.949646 cc 2024-04-10T20:38:51.894Z,1712781531.894 [CommandExec](IMPORTANT): got command get platform_buoyancy_position 2024-04-10T20:38:51.894Z,1712781531.894 [CommandExec](IMPORTANT): platform_buoyancy_position 539.607300 cc 2024-04-10T20:39:06.716Z,1712781546.716 [CommandExec](IMPORTANT): got command get platform_buoyancy_position 2024-04-10T20:39:06.717Z,1712781546.717 [CommandExec](IMPORTANT): platform_buoyancy_position 344.066528 cc 2024-04-10T20:39:10.747Z,1712781550.747 [CommandExec](IMPORTANT): got command get platform_buoyancy_position 2024-04-10T20:39:10.751Z,1712781550.751 [CommandExec](IMPORTANT): platform_buoyancy_position 292.495331 cc 2024-04-10T20:39:15.322Z,1712781555.322 [CommandExec](IMPORTANT): got command get platform_buoyancy_position 2024-04-10T20:39:15.322Z,1712781555.322 [CommandExec](IMPORTANT): platform_buoyancy_position 232.866119 cc 2024-04-10T20:39:20.392Z,1712781560.392 [CommandExec](IMPORTANT): got command get platform_buoyancy_position 2024-04-10T20:39:20.393Z,1712781560.393 [CommandExec](IMPORTANT): platform_buoyancy_position 206.811920 cc 2024-04-10T20:39:23.921Z,1712781563.921 [CommandExec](IMPORTANT): got command get platform_buoyancy_position 2024-04-10T20:39:23.921Z,1712781563.921 [CommandExec](IMPORTANT): platform_buoyancy_position 206.811920 cc 2024-04-10T20:41:21.154Z,1712781681.154 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-04-10T20:41:21.154Z,1712781681.154 [Default:CheckIn:C.Wait] Stopped 2024-04-10T20:41:21.154Z,1712781681.154 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-04-10T20:41:21.154Z,1712781681.154 [Default:CheckIn:D] Running Loop=1 2024-04-10T20:41:21.563Z,1712781681.563 [Default:CheckIn:D] Stopped 2024-04-10T20:41:21.563Z,1712781681.563 [Default:CheckIn:E] Running Loop=1 2024-04-10T20:41:21.981Z,1712781681.981 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 38.050273 min 2024-04-10T20:41:21.981Z,1712781681.981 [Default:CheckIn:E] Stopped 2024-04-10T20:41:21.981Z,1712781681.981 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-04-10T20:41:21.981Z,1712781681.981 [Default:CheckIn] Stopped 2024-04-10T20:41:21.981Z,1712781681.981 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-04-10T20:41:21.982Z,1712781681.982 [Default:CheckIn](INFO): Running loop #6 2024-04-10T20:41:21.982Z,1712781681.982 [Default:CheckIn] Running Loop=6 2024-04-10T20:41:21.982Z,1712781681.982 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-04-10T20:41:21.982Z,1712781681.982 [Default:CheckIn:Read_GPS] Running Loop=1 2024-04-10T20:41:23.974Z,1712781683.974 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204123.00,A,3648.16803,N,12147.28248,W,0.739,205.09,100424,,,A*7A 2024-04-10T20:41:23.976Z,1712781683.976 [NAL9602](INFO): GPS fix at 20240410T204123: (36.802801, -121.788041) 2024-04-10T20:41:23.999Z,1712781683.999 [Default:CheckIn:Read_GPS] Stopped 2024-04-10T20:41:23.000Z,1712781684.000 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-04-10T20:41:31.187Z,1712781691.187 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20240410T195833/Courier0022.lzma 2024-04-10T20:41:32.189Z,1712781692.189 [DataOverHttps](INFO): Moved sent file to Logs/20240410T195833/Courier0022.lzma.bak 2024-04-10T20:41:32.189Z,1712781692.189 [DataOverHttps](INFO): SBD MOMSN=19396828 2024-04-10T20:41:48.168Z,1712781708.168 [DataOverHttps](INFO): Sending 390 bytes from file Logs/20240410T195833/Express0023.lzma 2024-04-10T20:41:49.169Z,1712781709.169 [DataOverHttps](INFO): Moved sent file to Logs/20240410T195833/Express0023.lzma.bak 2024-04-10T20:41:49.169Z,1712781709.169 [DataOverHttps](INFO): SBD MOMSN=19396831 2024-04-10T20:41:51.472Z,1712781711.472 [Default:CheckIn:Read_Iridium] Stopped 2024-04-10T20:41:51.472Z,1712781711.472 [Default:CheckIn:C.Wait] Running Loop=1 2024-04-10T20:41:51.472Z,1712781711.472 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-04-10T20:41:54.677Z,1712781714.677 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2024-04-10T20:41:54.759Z,1712781714.759 [NAL9602](ERROR): received: +CSQ:0 OK375, 2, 0, 0, 0 OK 2024-04-10T20:42:22.150Z,1712781742.150 [NAL9602](INFO): SBD MO Status=2, MOMSN=49375, MT Status=2, MTMSN=0 2024-04-10T20:42:22.150Z,1712781742.150 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-04-10T20:46:03.316Z,1712781963.316 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting. 2024-04-10T20:46:26.225Z,1712781986.225 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2024-04-10T20:46:35.745Z,1712781995.745 [CommandExec](IMPORTANT): got command get platform_mass_position 2024-04-10T20:46:35.745Z,1712781995.745 [CommandExec](IMPORTANT): platform_mass_position -0.020197 m 2024-04-10T20:46:52.120Z,1712782012.120 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-04-10T20:46:52.120Z,1712782012.120 [Default:CheckIn:C.Wait] Stopped 2024-04-10T20:46:52.120Z,1712782012.120 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-04-10T20:46:52.120Z,1712782012.120 [Default:CheckIn:D] Running Loop=1 2024-04-10T20:46:52.499Z,1712782012.499 [Default:CheckIn:D] Stopped 2024-04-10T20:46:52.499Z,1712782012.499 [Default:CheckIn:E] Running Loop=1 2024-04-10T20:46:52.899Z,1712782012.899 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 43.565869 min 2024-04-10T20:46:52.899Z,1712782012.899 [Default:CheckIn:E] Stopped 2024-04-10T20:46:52.899Z,1712782012.899 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-04-10T20:46:52.899Z,1712782012.899 [Default:CheckIn] Stopped 2024-04-10T20:46:52.899Z,1712782012.899 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-04-10T20:46:52.900Z,1712782012.900 [Default:CheckIn](INFO): Running loop #7 2024-04-10T20:46:52.900Z,1712782012.900 [Default:CheckIn] Running Loop=7 2024-04-10T20:46:52.900Z,1712782012.900 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-04-10T20:46:52.900Z,1712782012.900 [Default:CheckIn:Read_GPS] Running Loop=1 2024-04-10T20:46:54.906Z,1712782014.906 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204654.00,A,3648.17071,N,12147.27990,W,0.778,0.00,100424,,,A*7B 2024-04-10T20:46:54.908Z,1712782014.908 [NAL9602](INFO): GPS fix at 20240410T204654: (36.802845, -121.787998) 2024-04-10T20:46:54.967Z,1712782014.967 [Default:CheckIn:Read_GPS] Stopped 2024-04-10T20:46:54.967Z,1712782014.967 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-04-10T20:47:02.476Z,1712782022.476 [CommandExec](IMPORTANT): got command get platform_mass_position 2024-04-10T20:47:02.476Z,1712782022.476 [CommandExec](IMPORTANT): platform_mass_position -0.020197 m 2024-04-10T20:47:04.271Z,1712782024.271 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20240410T195833/Courier0025.lzma 2024-04-10T20:47:05.273Z,1712782025.273 [DataOverHttps](INFO): Moved sent file to Logs/20240410T195833/Courier0025.lzma.bak 2024-04-10T20:47:05.273Z,1712782025.273 [DataOverHttps](INFO): SBD MOMSN=19396909 2024-04-10T20:47:21.155Z,1712782041.155 [DataOverHttps](INFO): Sending 270 bytes from file Logs/20240410T195833/Express0026.lzma 2024-04-10T20:47:22.157Z,1712782042.157 [DataOverHttps](INFO): Moved sent file to Logs/20240410T195833/Express0026.lzma.bak 2024-04-10T20:47:22.157Z,1712782042.157 [DataOverHttps](INFO): SBD MOMSN=19396915 2024-04-10T20:47:23.644Z,1712782043.644 [Default:CheckIn:Read_Iridium] Stopped 2024-04-10T20:47:23.644Z,1712782043.644 [Default:CheckIn:C.Wait] Running Loop=1 2024-04-10T20:47:23.644Z,1712782043.644 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-04-10T20:47:27.256Z,1712782047.256 [NAL9602](INFO): Not Powering down - fast GPS 2024-04-10T20:47:47.310Z,1712782067.310 [CommandExec](IMPORTANT): got command maintain control VerticalControl.massPositionAction 20 millimeter 2024-04-10T20:47:47.313Z,1712782067.313 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.massPositionAction" handled in the control thread. 2024-04-10T20:47:47.511Z,1712782067.511 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,PowerOnly,Power24vConverter,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.buoyancyAction,Maintain_VerticalControl.massPositionAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2024-04-10T20:47:59.813Z,1712782079.813 [CommandExec](IMPORTANT): got command get platform_mass_position 2024-04-10T20:47:59.813Z,1712782079.813 [CommandExec](IMPORTANT): platform_mass_position -0.012293 m 2024-04-10T20:48:03.430Z,1712782083.430 [CommandExec](IMPORTANT): got command get platform_mass_position 2024-04-10T20:48:03.431Z,1712782083.431 [CommandExec](IMPORTANT): platform_mass_position -0.009474 m 2024-04-10T20:48:07.380Z,1712782087.380 [CommandExec](IMPORTANT): got command get platform_mass_position 2024-04-10T20:48:07.381Z,1712782087.381 [CommandExec](IMPORTANT): platform_mass_position -0.006291 m 2024-04-10T20:48:11.838Z,1712782091.838 [CommandExec](IMPORTANT): got command get platform_mass_position 2024-04-10T20:48:11.838Z,1712782091.838 [CommandExec](IMPORTANT): platform_mass_position -0.002822 m 2024-04-10T20:48:19.656Z,1712782099.656 [CommandExec](IMPORTANT): got command get platform_mass_position 2024-04-10T20:48:19.656Z,1712782099.656 [CommandExec](IMPORTANT): platform_mass_position 0.003252 m 2024-04-10T20:48:25.226Z,1712782105.226 [CommandExec](IMPORTANT): got command get platform_mass_position 2024-04-10T20:48:25.226Z,1712782105.226 [CommandExec](IMPORTANT): platform_mass_position 0.007692 m 2024-04-10T20:49:00.553Z,1712782140.553 [CommandExec](IMPORTANT): got command get platform_mass_position 2024-04-10T20:49:00.554Z,1712782140.554 [CommandExec](IMPORTANT): platform_mass_position 0.020005 m 2024-04-10T20:49:33.098Z,1712782173.098 [CommandExec](IMPORTANT): got command get platform_mass_position 2024-04-10T20:49:33.098Z,1712782173.098 [CommandExec](IMPORTANT): platform_mass_position 0.020005 m 2024-04-10T20:50:02.863Z,1712782202.863 [CommandExec](IMPORTANT): got command maintain control VerticalControl.massPositionAction 10 millimeter 2024-04-10T20:52:24.366Z,1712782344.366 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-04-10T20:52:24.366Z,1712782344.366 [Default:CheckIn:C.Wait] Stopped 2024-04-10T20:52:24.366Z,1712782344.366 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-04-10T20:52:24.367Z,1712782344.367 [Default:CheckIn:D] Running Loop=1 2024-04-10T20:52:24.774Z,1712782344.774 [Default:CheckIn:D] Stopped 2024-04-10T20:52:24.774Z,1712782344.774 [Default:CheckIn:E] Running Loop=1 2024-04-10T20:52:25.186Z,1712782345.186 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 49.103800 min 2024-04-10T20:52:25.186Z,1712782345.186 [Default:CheckIn:E] Stopped 2024-04-10T20:52:25.186Z,1712782345.186 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-04-10T20:52:25.186Z,1712782345.186 [Default:CheckIn] Stopped 2024-04-10T20:52:25.186Z,1712782345.186 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-04-10T20:52:25.186Z,1712782345.186 [Default:CheckIn](INFO): Running loop #8 2024-04-10T20:52:25.186Z,1712782345.186 [Default:CheckIn] Running Loop=8 2024-04-10T20:52:25.186Z,1712782345.186 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-04-10T20:52:25.186Z,1712782345.186 [Default:CheckIn:Read_GPS] Running Loop=1 2024-04-10T20:52:27.210Z,1712782347.210 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205226.00,A,3648.16958,N,12147.28341,W,1.341,0.00,100424,,,A*7E 2024-04-10T20:52:27.216Z,1712782347.216 [NAL9602](INFO): GPS fix at 20240410T205226: (36.802826, -121.788057) 2024-04-10T20:52:27.280Z,1712782347.280 [Default:CheckIn:Read_GPS] Stopped 2024-04-10T20:52:27.280Z,1712782347.280 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-04-10T20:52:37.927Z,1712782357.927 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20240410T195833/Courier0028.lzma 2024-04-10T20:52:38.929Z,1712782358.929 [DataOverHttps](INFO): Moved sent file to Logs/20240410T195833/Courier0028.lzma.bak 2024-04-10T20:52:38.929Z,1712782358.929 [DataOverHttps](INFO): SBD MOMSN=19396934 2024-04-10T20:52:57.645Z,1712782377.645 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2024-04-10T20:52:57.735Z,1712782377.735 [NAL9602](ERROR): received: +CSQ:0 OK375, 2, 0, 0, 0 OK 2024-04-10T20:52:59.595Z,1712782379.595 [DataOverHttps](INFO): Sending 357 bytes from file Logs/20240410T195833/Express0029.lzma 2024-04-10T20:53:00.597Z,1712782380.597 [DataOverHttps](INFO): Moved sent file to Logs/20240410T195833/Express0029.lzma.bak 2024-04-10T20:53:00.597Z,1712782380.597 [DataOverHttps](INFO): SBD MOMSN=19396940 2024-04-10T20:53:02.115Z,1712782382.115 [Default:CheckIn:Read_Iridium] Stopped 2024-04-10T20:53:02.115Z,1712782382.115 [Default:CheckIn:C.Wait] Running Loop=1 2024-04-10T20:53:02.115Z,1712782382.115 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-04-10T20:53:04.522Z,1712782384.522 [CommandExec](IMPORTANT): got command maintain control VerticalControl.massPositionAction 20 millimeter 2024-04-10T20:54:23.110Z,1712782463.110 [CommandExec](IMPORTANT): got command maintain clear 2024-04-10T20:54:23.338Z,1712782463.338 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,PowerOnly,Power24vConverter,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2024-04-10T20:55:58.046Z,1712782558.046 [CommandExec](IMPORTANT): got command restart application 2024-04-10T20:55:59.047Z,1712782559.047 [Supervisor](INFO): Stop Mission called by Supervisor::terminate 2024-04-10T20:55:59.048Z,1712782559.048 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2024-04-10T20:55:59.048Z,1712782559.048 [CommandExec](INFO): Uninitializing the command executive. 2024-04-10T20:55:59.048Z,1712782559.048 [CommandExec](INFO): Uninitializing the command scheduler. 2024-04-10T20:55:59.048Z,1712782559.048 [CommandExec ThreadHandler](INFO): Thread cancelled. 2024-04-10T20:55:59.075Z,1712782559.075 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2024-04-10T20:55:59.075Z,1712782559.075 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2024-04-10T20:55:59.075Z,1712782559.075 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2024-04-10T20:55:59.076Z,1712782559.076 [NavChartDb](INFO): Join timeout helper Thread ID is 4165 2024-04-10T20:55:59.235Z,1712782559.235 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2024-04-10T20:55:59.236Z,1712782559.236 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2024-04-10T20:55:59.243Z,1712782559.243 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2024-04-10T20:55:59.243Z,1712782559.243 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2024-04-10T20:55:59.244Z,1712782559.244 [CTD_Seabird](INFO): Join timeout helper Thread ID is 4166 2024-04-10T20:56:00.031Z,1712782560.031 [CTD_Seabird](INFO): Powering down 2024-04-10T20:56:00.043Z,1712782560.043 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2024-04-10T20:56:00.044Z,1712782560.044 [CTD_Seabird](INFO): Powering down 2024-04-10T20:56:00.055Z,1712782560.055 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2024-04-10T20:56:00.073Z,1712782560.073 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2024-04-10T20:56:00.073Z,1712782560.073 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2024-04-10T20:56:00.073Z,1712782560.073 [Radio_Surface](INFO): Join timeout helper Thread ID is 4167 2024-04-10T20:56:00.439Z,1712782560.439 [Radio_Surface](INFO): Powering down 2024-04-10T20:56:00.440Z,1712782560.440 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2024-04-10T20:56:00.440Z,1712782560.440 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2024-04-10T20:56:00.447Z,1712782560.447 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2024-04-10T20:56:00.447Z,1712782560.447 [Onboard ThreadHandler](INFO): Thread cancelled. 2024-04-10T20:56:00.448Z,1712782560.448 [Onboard](INFO): Join timeout helper Thread ID is 4168 2024-04-10T20:56:00.763Z,1712782560.763 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2024-04-10T20:56:04.303Z,1712782564.303 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2024-04-10T20:56:04.303Z,1712782564.303 [Onboard ThreadHandler](INFO): Thread cancelled. 2024-04-10T20:56:04.307Z,1712782564.307 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2024-04-10T20:56:04.307Z,1712782564.307 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2024-04-10T20:56:04.308Z,1712782564.308 [DataOverHttps](INFO): Join timeout helper Thread ID is 4169 2024-04-10T20:56:04.779Z,1712782564.779 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2024-04-10T20:56:04.780Z,1712782564.780 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2024-04-10T20:56:04.792Z,1712782564.792 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2024-04-10T20:56:04.792Z,1712782564.792 [logger ThreadHandler](INFO): Thread cancelled. 2024-04-10T20:56:04.793Z,1712782564.793 [logger](INFO): Join timeout helper Thread ID is 4170 2024-04-10T20:56:04.823Z,1712782564.823 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2024-04-10T20:56:04.824Z,1712782564.824 [logger ThreadHandler](INFO): Thread cancelled. 2024-04-10T20:56:04.832Z,1712782564.832 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2024-04-10T20:56:04.832Z,1712782564.832 [CommandLine ThreadHandler](INFO): Thread cancelled. 2024-04-10T20:56:04.832Z,1712782564.832 [CommandLine](INFO): Join timeout helper Thread ID is 4171 2024-04-10T20:56:04.891Z,1712782564.891 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2024-04-10T20:56:04.892Z,1712782564.892 [CommandLine ThreadHandler](INFO): Thread cancelled. 2024-04-10T20:56:04.912Z,1712782564.912 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2024-04-10T20:56:04.912Z,1712782564.912 [CommandExec ThreadHandler](INFO): Thread cancelled. 2024-04-10T20:56:04.912Z,1712782564.912 [CommandExec](INFO): Join timeout helper Thread ID is 4172 2024-04-10T20:56:04.913Z,1712782564.913 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2024-04-10T20:56:04.914Z,1712782564.914 [controlThread ThreadHandler](INFO): Thread cancelled. 2024-04-10T20:56:04.914Z,1712782564.914 [controlThread](INFO): Join timeout helper Thread ID is 4173 2024-04-10T20:56:05.079Z,1712782565.079 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2024-04-10T20:56:05.080Z,1712782565.080 [controlThread](DEBUG): Uninitializing ControlThread 2024-04-10T20:56:05.080Z,1712782565.080 [AHRS_M2](INFO): Powering down 2024-04-10T20:56:05.152Z,1712782565.152 [NAL9602](INFO): Powering down 2024-04-10T20:56:05.155Z,1712782565.155 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2024-04-10T20:56:05.156Z,1712782565.156 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2024-04-10T20:56:05.156Z,1712782565.156 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2024-04-10T20:56:05.157Z,1712782565.157 [MissionManager](INFO): Uninitializing Mission Default 2024-04-10T20:56:05.157Z,1712782565.157 [Default] Stopped 2024-04-10T20:56:05.157Z,1712782565.157 [Default](DEBUG): Aggregate::uninitialize Default 2024-04-10T20:56:05.157Z,1712782565.157 [Default:B.GoToSurface] Stopped 2024-04-10T20:56:05.157Z,1712782565.157 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2024-04-10T20:56:05.157Z,1712782565.157 [Default:CheckIn] Stopped 2024-04-10T20:56:05.157Z,1712782565.157 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-04-10T20:56:05.157Z,1712782565.157 [Default:CheckIn:C.Wait] Stopped 2024-04-10T20:56:05.157Z,1712782565.157 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-04-10T20:56:05.160Z,1712782565.160 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2024-04-10T20:56:05.160Z,1712782565.160 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2024-04-10T20:56:05.161Z,1712782565.161 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2024-04-10T20:56:05.161Z,1712782565.161 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2024-04-10T20:56:05.161Z,1712782565.161 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2024-04-10T20:56:05.161Z,1712782565.161 [BuoyancyServo](INFO): Powering down 2024-04-10T20:56:05.175Z,1712782565.175 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2024-04-10T20:56:05.175Z,1712782565.175 [ElevatorServo](INFO): Powering down 2024-04-10T20:56:05.176Z,1712782565.176 [MassServo](DEBUG): Uninitialize Mass Servo. 2024-04-10T20:56:05.176Z,1712782565.176 [MassServo](INFO): Powering down 2024-04-10T20:56:05.177Z,1712782565.177 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2024-04-10T20:56:05.177Z,1712782565.177 [RudderServo](INFO): Powering down 2024-04-10T20:56:05.178Z,1712782565.178 [ThrusterHE](DEBUG): Uninitialize Thruster Servo. 2024-04-10T20:56:05.178Z,1712782565.178 [ThrusterHE](INFO): Powering down 2024-04-10T20:56:05.179Z,1712782565.179 [SBIT](DEBUG): Uninitialize SBIT Component. 2024-04-10T20:56:05.179Z,1712782565.179 [IBIT](DEBUG): Uninitialize IBIT Component. 2024-04-10T20:56:05.180Z,1712782565.180 [CBIT](DEBUG): Uninitialize CBIT Component. 2024-04-10T20:56:05.180Z,1712782565.180 [CBIT](DEBUG): Powering off loads. 2024-04-10T20:56:05.191Z,1712782565.191 [CBIT](DEBUG): Disabling WDT. 2024-04-10T20:56:05.203Z,1712782565.203 [CBIT](DEBUG): Opening all GF detection circuits. 2024-04-10T20:56:05.204Z,1712782565.204 [controlThread ThreadHandler](INFO): Thread cancelled. 2024-04-10T20:56:05.248Z,1712782565.248 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2024-04-10T20:56:05.252Z,1712782565.252 [Onboard ThreadHandler](INFO): Thread cancelled. 2024-04-10T20:56:05.258Z,1712782565.258 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2024-04-10T20:56:05.330Z,1712782565.330 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2024-04-10T20:56:05.371Z,1712782565.371 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2024-04-10T20:56:05.445Z,1712782565.445 [logger ThreadHandler](INFO): Thread cancelled.