2025-04-07T19:33:57.760Z,1744054437.760 [Supervisor](DEBUG): Initializing supervisor. 2025-04-07T19:33:57.764Z,1744054437.764 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2025-04-07T19:33:57.764Z,1744054437.764 [SyncHandler](INFO): Protected caller Thread ID is 837 2025-04-07T19:33:57.765Z,1744054437.765 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2025-04-07T19:33:57.766Z,1744054437.766 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2025-04-07T19:33:57.766Z,1744054437.766 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 838 2025-04-07T19:33:57.770Z,1744054437.770 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2025-04-07T19:33:57.790Z,1744054437.790 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2025-04-07T19:33:57.791Z,1744054437.791 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2025-04-07T19:33:57.792Z,1744054437.792 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 839 2025-04-07T19:33:57.796Z,1744054437.796 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2025-04-07T19:33:57.797Z,1744054437.797 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2025-04-07T19:33:57.797Z,1744054437.797 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 840 2025-04-07T19:33:57.800Z,1744054437.800 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2025-04-07T19:33:57.801Z,1744054437.801 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2025-04-07T19:33:57.801Z,1744054437.801 [logger ThreadHandler](INFO): Protected caller Thread ID is 841 2025-04-07T19:33:57.805Z,1744054437.805 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2025-04-07T19:33:57.805Z,1744054437.805 [Supervisor](INFO): Looking for Config files in directory: Config/ 2025-04-07T19:33:57.809Z,1744054437.809 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2025-04-07T19:33:58.159Z,1744054438.159 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2025-04-07T19:33:58.161Z,1744054438.161 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2025-04-07T19:33:58.252Z,1744054438.252 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2025-04-07T19:33:58.370Z,1744054438.370 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2025-04-07T19:33:58.372Z,1744054438.372 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2025-04-07T19:33:58.513Z,1744054438.513 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2025-04-07T19:33:58.515Z,1744054438.515 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2025-04-07T19:33:58.872Z,1744054438.872 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2025-04-07T19:33:58.873Z,1744054438.873 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2025-04-07T19:33:58.979Z,1744054438.979 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2025-04-07T19:33:58.981Z,1744054438.981 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2025-04-07T19:33:59.411Z,1744054439.411 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2025-04-07T19:33:59.413Z,1744054439.413 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2025-04-07T19:33:59.648Z,1744054439.648 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2025-04-07T19:33:59.650Z,1744054439.650 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2025-04-07T19:33:59.741Z,1744054439.741 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2025-04-07T19:33:59.994Z,1744054439.994 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2025-04-07T19:33:59.994Z,1744054439.994 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2025-04-07T19:34:00.228Z,1744054440.228 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2025-04-07T19:34:00.229Z,1744054440.229 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2025-04-07T19:34:00.773Z,1744054440.773 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2025-04-07T19:34:00.773Z,1744054440.773 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2025-04-07T19:34:01.001Z,1744054441.001 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2025-04-07T19:34:01.003Z,1744054441.003 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2025-04-07T19:34:01.300Z,1744054441.300 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2025-04-07T19:34:01.301Z,1744054441.301 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2025-04-07T19:34:02.197Z,1744054442.197 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2025-04-07T19:34:02.198Z,1744054442.198 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2025-04-07T19:34:02.778Z,1744054442.778 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2025-04-07T19:34:02.780Z,1744054442.780 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-ahi/ 2025-04-07T19:34:02.782Z,1744054442.782 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Control.cfg 2025-04-07T19:34:02.890Z,1744054442.890 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Science.cfg 2025-04-07T19:34:03.034Z,1744054443.034 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/secure.cfg 2025-04-07T19:34:03.174Z,1744054443.174 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Servo.cfg 2025-04-07T19:34:03.293Z,1744054443.293 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/BIT.cfg 2025-04-07T19:34:03.391Z,1744054443.391 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Battery.cfg 2025-04-07T19:34:03.663Z,1744054443.663 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2025-04-07T19:34:03.664Z,1744054443.664 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/vehicle.cfg 2025-04-07T19:34:03.785Z,1744054443.785 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/logger.cfg 2025-04-07T19:34:03.895Z,1744054443.895 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Sensor.cfg 2025-04-07T19:34:04.049Z,1744054444.049 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Simulator.cfg 2025-04-07T19:34:04.146Z,1744054444.146 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2025-04-07T19:34:04.150Z,1744054444.150 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2025-04-07T19:34:04.321Z,1744054444.321 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2025-04-07T19:34:04.322Z,1744054444.322 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2025-04-07T19:34:04.395Z,1744054444.395 [VerticalControl](DEBUG): Construct VerticalControl. 2025-04-07T19:34:04.458Z,1744054444.458 [VerticalControl] Loaded 2025-04-07T19:34:04.458Z,1744054444.458 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2025-04-07T19:34:04.461Z,1744054444.461 [HorizontalControl](DEBUG): Construct HorizontalControl. 2025-04-07T19:34:04.509Z,1744054444.509 [HorizontalControl] Loaded 2025-04-07T19:34:04.509Z,1744054444.509 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2025-04-07T19:34:04.512Z,1744054444.512 [SpeedControl](DEBUG): Construct SpeedControl. 2025-04-07T19:34:04.515Z,1744054444.515 [SpeedControl] Loaded 2025-04-07T19:34:04.515Z,1744054444.515 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2025-04-07T19:34:04.518Z,1744054444.518 [LoopControl](DEBUG): Construct LoopControl. 2025-04-07T19:34:04.518Z,1744054444.518 [LoopControl] Loaded 2025-04-07T19:34:04.519Z,1744054444.519 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2025-04-07T19:34:04.519Z,1744054444.519 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2025-04-07T19:34:04.521Z,1744054444.521 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2025-04-07T19:34:04.607Z,1744054444.607 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2025-04-07T19:34:04.607Z,1744054444.607 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2025-04-07T19:34:05.458Z,1744054445.458 [AHRS_M2] Loaded 2025-04-07T19:34:05.459Z,1744054445.459 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2025-04-07T19:34:05.711Z,1744054445.711 [BackseatComponent](INFO): Found secondary power supply at: /dev/loadC4 2025-04-07T19:34:05.712Z,1744054445.712 [BackseatComponent] Loaded 2025-04-07T19:34:05.712Z,1744054445.712 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2025-04-07T19:34:05.713Z,1744054445.713 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408BA4E0 2025-04-07T19:34:05.714Z,1744054445.714 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 921 2025-04-07T19:34:05.717Z,1744054445.717 [LcmUniversalReporter] Loaded 2025-04-07T19:34:05.717Z,1744054445.717 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2025-04-07T19:34:06.535Z,1744054446.535 [BPC1] Loaded 2025-04-07T19:34:06.535Z,1744054446.535 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2025-04-07T19:34:06.631Z,1744054446.631 [DAT] Loaded 2025-04-07T19:34:06.631Z,1744054446.631 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2025-04-07T19:34:06.632Z,1744054446.632 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 408EA4E0 2025-04-07T19:34:06.632Z,1744054446.632 [DAT ThreadHandler](INFO): Protected caller Thread ID is 922 2025-04-07T19:34:06.772Z,1744054446.772 [DataOverHttps] Loaded 2025-04-07T19:34:06.773Z,1744054446.773 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2025-04-07T19:34:06.774Z,1744054446.774 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4091A4E0 2025-04-07T19:34:06.774Z,1744054446.774 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 923 2025-04-07T19:34:06.797Z,1744054446.797 [Depth_Keller] Loaded 2025-04-07T19:34:06.797Z,1744054446.797 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2025-04-07T19:34:06.802Z,1744054446.802 [DropWeight] Loaded 2025-04-07T19:34:06.802Z,1744054446.802 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2025-04-07T19:34:06.867Z,1744054446.867 [NAL9602] Loaded 2025-04-07T19:34:06.867Z,1744054446.867 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2025-04-07T19:34:06.897Z,1744054446.897 [Onboard] Loaded 2025-04-07T19:34:06.898Z,1744054446.898 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2025-04-07T19:34:06.898Z,1744054446.898 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4094A4E0 2025-04-07T19:34:06.899Z,1744054446.899 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 924 2025-04-07T19:34:06.913Z,1744054446.913 [Power24vConverter] Loaded 2025-04-07T19:34:06.914Z,1744054446.914 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2025-04-07T19:34:06.930Z,1744054446.930 [Radio_Surface] Loaded 2025-04-07T19:34:06.930Z,1744054446.930 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2025-04-07T19:34:06.931Z,1744054446.931 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4097A4E0 2025-04-07T19:34:06.931Z,1744054446.931 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 925 2025-04-07T19:34:06.947Z,1744054446.947 [Sonardyne_Nano] Loaded 2025-04-07T19:34:06.947Z,1744054446.947 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread. 2025-04-07T19:34:06.972Z,1744054446.972 [Waterlinked] Loaded 2025-04-07T19:34:06.972Z,1744054446.972 [ComponentRegistry](DEBUG): SyncComponent "Waterlinked" handled in the control thread. 2025-04-07T19:34:06.972Z,1744054446.972 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2025-04-07T19:34:06.973Z,1744054446.973 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2025-04-07T19:34:06.989Z,1744054446.989 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2025-04-07T19:34:06.990Z,1744054446.990 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2025-04-07T19:34:07.037Z,1744054447.037 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2025-04-07T19:34:07.038Z,1744054447.038 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2025-04-07T19:34:07.237Z,1744054447.237 [SBIT](DEBUG): Construct Startup Built In Test. 2025-04-07T19:34:07.246Z,1744054447.246 [SBIT] Loaded 2025-04-07T19:34:07.246Z,1744054447.246 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2025-04-07T19:34:07.249Z,1744054447.249 [IBIT](DEBUG): Construct Initiated Built In Test. 2025-04-07T19:34:07.262Z,1744054447.262 [IBIT] Loaded 2025-04-07T19:34:07.262Z,1744054447.262 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2025-04-07T19:34:07.268Z,1744054447.268 [CBIT](DEBUG): Construct Continuous Built In Test. 2025-04-07T19:34:07.349Z,1744054447.349 [CBIT] Loaded 2025-04-07T19:34:07.349Z,1744054447.349 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2025-04-07T19:34:07.382Z,1744054447.382 [GFScanner] Loaded 2025-04-07T19:34:07.382Z,1744054447.382 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread. 2025-04-07T19:34:07.382Z,1744054447.382 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2025-04-07T19:34:07.383Z,1744054447.383 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2025-04-07T19:34:07.801Z,1744054447.801 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2025-04-07T19:34:07.803Z,1744054447.803 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2025-04-07T19:34:07.875Z,1744054447.875 [DepthRateCalculator] Loaded 2025-04-07T19:34:07.875Z,1744054447.875 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2025-04-07T19:34:07.880Z,1744054447.880 [PitchRateCalculator] Loaded 2025-04-07T19:34:07.881Z,1744054447.881 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2025-04-07T19:34:07.891Z,1744054447.891 [SpeedCalculator] Loaded 2025-04-07T19:34:07.891Z,1744054447.891 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2025-04-07T19:34:07.896Z,1744054447.896 [YawRateCalculator] Loaded 2025-04-07T19:34:07.896Z,1744054447.896 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2025-04-07T19:34:07.915Z,1744054447.915 [ElevatorOffsetCalculator] Loaded 2025-04-07T19:34:07.915Z,1744054447.915 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2025-04-07T19:34:07.916Z,1744054447.916 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2025-04-07T19:34:07.917Z,1744054447.917 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2025-04-07T19:34:08.138Z,1744054448.138 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2025-04-07T19:34:08.138Z,1744054448.138 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2025-04-07T19:34:08.278Z,1744054448.278 [DeadReckonUsingMultipleVelocitySources] Loaded 2025-04-07T19:34:08.278Z,1744054448.278 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2025-04-07T19:34:08.292Z,1744054448.292 [NavChart] Loaded 2025-04-07T19:34:08.293Z,1744054448.293 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2025-04-07T19:34:08.298Z,1744054448.298 [UniversalFixResidualReporter] Loaded 2025-04-07T19:34:08.299Z,1744054448.299 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2025-04-07T19:34:08.299Z,1744054448.299 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2025-04-07T19:34:08.300Z,1744054448.300 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2025-04-07T19:34:08.473Z,1744054448.473 [BuoyancyServo] Loaded 2025-04-07T19:34:08.473Z,1744054448.473 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2025-04-07T19:34:08.496Z,1744054448.496 [ElevatorServo] Loaded 2025-04-07T19:34:08.497Z,1744054448.497 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2025-04-07T19:34:08.518Z,1744054448.518 [MassServo] Loaded 2025-04-07T19:34:08.519Z,1744054448.519 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2025-04-07T19:34:08.540Z,1744054448.540 [RudderServo] Loaded 2025-04-07T19:34:08.540Z,1744054448.540 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2025-04-07T19:34:08.557Z,1744054448.557 [ThrusterHE] Loaded 2025-04-07T19:34:08.558Z,1744054448.558 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2025-04-07T19:34:08.558Z,1744054448.558 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2025-04-07T19:34:08.559Z,1744054448.559 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2025-04-07T19:34:08.775Z,1744054448.775 [CTD_Seabird] Loaded 2025-04-07T19:34:08.775Z,1744054448.775 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2025-04-07T19:34:08.776Z,1744054448.776 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40C054E0 2025-04-07T19:34:08.777Z,1744054448.777 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 926 2025-04-07T19:34:08.814Z,1744054448.814 [ESPComponent] Loaded 2025-04-07T19:34:08.814Z,1744054448.814 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2025-04-07T19:34:08.836Z,1744054448.836 [PAR_Licor] Loaded 2025-04-07T19:34:08.837Z,1744054448.837 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2025-04-07T19:34:08.883Z,1744054448.883 [WetLabsBB2FL] Loaded 2025-04-07T19:34:08.883Z,1744054448.883 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2025-04-07T19:34:08.884Z,1744054448.884 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40C354E0 2025-04-07T19:34:08.885Z,1744054448.885 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 927 2025-04-07T19:34:08.885Z,1744054448.885 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2025-04-07T19:34:08.892Z,1744054448.892 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2025-04-07T19:34:08.895Z,1744054448.895 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2025-04-07T19:34:08.906Z,1744054448.906 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2025-04-07T19:34:08.907Z,1744054448.907 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C654E0 2025-04-07T19:34:08.907Z,1744054448.907 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 928 2025-04-07T19:34:08.912Z,1744054448.912 [Supervisor](INFO): Main Thread ID is 828 2025-04-07T19:34:08.912Z,1744054448.912 [Supervisor](DEBUG): Running supervisor. 2025-04-07T19:34:08.913Z,1744054448.913 [CommandExec ThreadHandler](INFO): Handler Thread ID is 929 2025-04-07T19:34:08.913Z,1744054448.913 [CommandExec](INFO): Initializing the command executive. 2025-04-07T19:34:08.915Z,1744054448.915 [CommandLine ThreadHandler](INFO): Handler Thread ID is 930 2025-04-07T19:34:08.917Z,1744054448.917 [controlThread ThreadHandler](INFO): Handler Thread ID is 931 2025-04-07T19:34:08.917Z,1744054448.917 [controlThread](DEBUG): Initializing ControlThread 2025-04-07T19:34:08.918Z,1744054448.918 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2025-04-07T19:34:08.920Z,1744054448.920 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2025-04-07T19:34:08.921Z,1744054448.921 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2025-04-07T19:34:08.921Z,1744054448.921 [LoopControl](DEBUG): Initialize LoopControlComponent. 2025-04-07T19:34:08.924Z,1744054448.924 [SBIT](INFO): Initialize SBIT Component. 2025-04-07T19:34:08.925Z,1744054448.925 [SBIT](IMPORTANT): git: 2025-04-02-2-g1635786d1 2025-04-07T19:34:08.925Z,1744054448.925 [SBIT](INFO): git hash: 1635786d188a1b3aba7073e6184020eb8609012e 2025-04-07T19:34:08.925Z,1744054448.925 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2025-04-07T19:34:08.926Z,1744054448.926 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014 Kernel Reported: #1 PREEMPT Tue Nov 28 15:04:22 PST 2023 2025-04-07T19:34:08.927Z,1744054448.927 [SBIT](INFO): Beginning SBIT in 71.000000 seconds. 2025-04-07T19:34:08.928Z,1744054448.928 [IBIT](INFO): Initialize IBIT Component. 2025-04-07T19:34:08.929Z,1744054448.929 [CBIT](DEBUG): Initialize CBIT Component. 2025-04-07T19:34:08.930Z,1744054448.930 [logger ThreadHandler](INFO): Handler Thread ID is 932 2025-04-07T19:34:08.940Z,1744054448.940 [CBIT](DEBUG): Initialized mux pins. 2025-04-07T19:34:08.940Z,1744054448.940 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL. 2025-04-07T19:34:08.940Z,1744054448.940 [CBIT](DEBUG): Initializing the watchdog timer. 2025-04-07T19:34:08.948Z,1744054448.948 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 933 2025-04-07T19:34:08.964Z,1744054448.964 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET. 2025-04-07T19:34:08.964Z,1744054448.964 [CBIT](DEBUG): Initializing heartbeat. 2025-04-07T19:34:08.965Z,1744054448.965 [DAT ThreadHandler](INFO): Handler Thread ID is 934 2025-04-07T19:34:08.966Z,1744054448.966 [DAT](INFO): Powering up 2025-04-07T19:34:08.966Z,1744054448.966 [DAT](DEBUG): Initializing DAT. 2025-04-07T19:34:08.969Z,1744054448.969 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 936 2025-04-07T19:34:08.971Z,1744054448.971 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2025-04-07T19:34:08.993Z,1744054448.993 [Onboard ThreadHandler](INFO): Handler Thread ID is 937 2025-04-07T19:34:09.010Z,1744054449.010 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 938 2025-04-07T19:34:09.030Z,1744054449.030 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 939 2025-04-07T19:34:09.030Z,1744054449.030 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2025-04-07T19:34:09.036Z,1744054449.036 [CBIT](DEBUG): Deactivating emergency mode. 2025-04-07T19:34:09.037Z,1744054449.037 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 941 2025-04-07T19:34:09.041Z,1744054449.041 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 943 2025-04-07T19:34:09.045Z,1744054449.045 [WetLabsBB2FL](INFO): Powering up 2025-04-07T19:34:09.049Z,1744054449.049 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2025-04-07T19:34:09.049Z,1744054449.049 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2025-04-07T19:34:09.049Z,1744054449.049 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2025-04-07T19:34:09.049Z,1744054449.049 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2025-04-07T19:34:09.050Z,1744054449.050 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2025-04-07T19:34:09.050Z,1744054449.050 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2025-04-07T19:34:09.050Z,1744054449.050 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2025-04-07T19:34:09.050Z,1744054449.050 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2025-04-07T19:34:09.076Z,1744054449.076 [CBIT](DEBUG): Backplane powered. 2025-04-07T19:34:09.076Z,1744054449.076 [GFScanner](DEBUG): Initializing GFScanner 2025-04-07T19:34:09.076Z,1744054449.076 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2025-04-07T19:34:09.077Z,1744054449.077 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2025-04-07T19:34:09.077Z,1744054449.077 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2025-04-07T19:34:09.077Z,1744054449.077 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2025-04-07T19:34:09.078Z,1744054449.078 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2025-04-07T19:34:09.079Z,1744054449.079 [NavChart](DEBUG): Initialize NavChart Navigation. 2025-04-07T19:34:09.079Z,1744054449.079 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2025-04-07T19:34:09.084Z,1744054449.084 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser 2025-04-07T19:34:09.085Z,1744054449.085 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl 2025-04-07T19:34:09.085Z,1744054449.085 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl 2025-04-07T19:34:09.094Z,1744054449.094 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl 2025-04-07T19:34:09.134Z,1744054449.134 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into: 2025-04-07T19:34:09.155Z,1744054449.155 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2025-04-07T19:34:09.187Z,1744054449.187 [MissionManager](DEBUG): # Copyright (c) 2024 MBARI # MBARI Proprietary Information. Confidential. All Rights Reserved # Unauthorized copying or distribution of this file via any medium is strictly # prohibited. # # WARNING - This file contains information whose export is restricted by the # Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as # amended. Violations of these export laws are subject to severe civil and/or # criminal penalties. 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 } } } 2025-04-07T19:34:09.217Z,1744054449.217 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl 2025-04-07T19:34:09.217Z,1744054449.217 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl 2025-04-07T19:34:09.221Z,1744054449.221 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl 2025-04-07T19:34:09.416Z,1744054449.416 [Radio_Surface](INFO): Powering up 2025-04-07T19:34:09.510Z,1744054449.510 [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 2025-04-07T19:34:09.518Z,1744054449.518 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2025-04-07T19:34:09.519Z,1744054449.519 [Default:A.Wait](DEBUG): Construct Wait. 2025-04-07T19:34:09.521Z,1744054449.521 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2025-04-07T19:34:09.574Z,1744054449.574 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2025-04-07T19:34:09.585Z,1744054449.585 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2025-04-07T19:34:09.599Z,1744054449.599 [Default:E.Execute](DEBUG): Construct Execute. 2025-04-07T19:34:09.610Z,1744054449.610 [MissionManager](DEBUG): # Copyright (c) 2024 MBARI # MBARI Proprietary Information. Confidential. All Rights Reserved # Unauthorized copying or distribution of this file via any medium is strictly # prohibited. # # WARNING - This file contains information whose export is restricted by the # Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as # amended. Violations of these export laws are subject to severe civil and/or # criminal penalties. 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" } } 2025-04-07T19:34:09.616Z,1744054449.616 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,Sonardyne_Nano,Waterlinked,ESPComponent,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,GFScanner,LcmUniversalReporter,Reporter,LogSplitter, 2025-04-07T19:34:09.628Z,1744054449.628 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2025-04-07T19:34:09.792Z,1744054449.792 [Depth_Keller](INFO): Initializing. 2025-04-07T19:34:09.794Z,1744054449.794 [Power24vConverter](INFO): Powering up. 2025-04-07T19:34:09.794Z,1744054449.794 [Sonardyne_Nano](INFO): Initializing. 2025-04-07T19:34:09.833Z,1744054449.833 [DepthRateCalculator](ERROR): Depth measurement is not active 2025-04-07T19:34:09.859Z,1744054449.859 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2025-04-07T19:34:09.864Z,1744054449.864 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2025-04-07T19:34:09.865Z,1744054449.865 [ElevatorServo](DEBUG): Initializing EZServoServo. 2025-04-07T19:34:09.872Z,1744054449.872 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2025-04-07T19:34:09.873Z,1744054449.873 [MassServo](DEBUG): Initializing EZServoServo. 2025-04-07T19:34:09.880Z,1744054449.880 [MassServo](DEBUG): Initializing MassServo. 2025-04-07T19:34:09.881Z,1744054449.881 [RudderServo](DEBUG): Initializing EZServoServo. 2025-04-07T19:34:09.888Z,1744054449.888 [RudderServo](DEBUG): Initializing RudderServo. 2025-04-07T19:34:09.889Z,1744054449.889 [ThrusterHE](DEBUG): Initializing EZServoServo. 2025-04-07T19:34:09.896Z,1744054449.896 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2025-04-07T19:34:09.898Z,1744054449.898 [CommandExec](FAULT): Scheduling is paused 2025-04-07T19:34:09.899Z,1744054449.899 [CBIT](INFO): Critical error at 20250407T193408 2025-04-07T19:34:09.899Z,1744054449.899 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2025-04-07T19:34:11.148Z,1744054451.148 [WetLabsBB2FL](INFO): Powering down 2025-04-07T19:34:12.050Z,1744054452.050 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART 2025-04-07T19:34:13.292Z,1744054453.292 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2311 2025-04-07T19:34:15.641Z,1744054455.641 [ThrusterHE](ERROR): Zero Speed Commanded. 2025-04-07T19:34:22.069Z,1744054462.069 [DAT](INFO): DAT read: 2025-04-07T19:34:22.070Z,1744054462.070 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2025-04-07T19:34:23.581Z,1744054463.581 [DAT](INFO): DAT read: MF Frequency Band 2025-04-07T19:34:23.582Z,1744054463.582 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2025-04-07T19:34:23.582Z,1744054463.582 [DAT](INFO): DAT read: Apr 7 2025 19:34:18 2025-04-07T19:34:24.841Z,1744054464.841 [DAT](INFO): DAT read: Features enabled [Bearing] 2025-04-07T19:34:24.842Z,1744054464.842 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP 2025-04-07T19:34:24.843Z,1744054464.843 [DAT](INFO): commRate: 800 2025-04-07T19:34:26.908Z,1744054466.908 [DAT](INFO): entering command mode 2025-04-07T19:34:27.109Z,1744054467.109 [DAT](INFO): DAT read: 2025-04-07T19:34:27.109Z,1744054467.109 [DAT](INFO): DAT read: user:1> 2025-04-07T19:34:27.109Z,1744054467.109 [DAT](INFO): setting verbose to 3 2025-04-07T19:34:27.361Z,1744054467.361 [DAT](INFO): DAT read: user:1> 2025-04-07T19:34:27.362Z,1744054467.362 [DAT](INFO): DAT read: Verbose | 3 2025-04-07T19:34:27.362Z,1744054467.362 [DAT](INFO): set verbose to 3 2025-04-07T19:34:27.363Z,1744054467.363 [DAT](INFO): setting DatVerbose to 27440 2025-04-07T19:34:27.613Z,1744054467.613 [DAT](INFO): DAT read: user:2> 2025-04-07T19:34:27.613Z,1744054467.613 [DAT](INFO): DAT read: DatVerbose | 27440 2025-04-07T19:34:27.614Z,1744054467.614 [DAT](INFO): set DatVerbose to 27440 2025-04-07T19:34:27.614Z,1744054467.614 [DAT](INFO): setting transmit power to 8 2025-04-07T19:34:27.865Z,1744054467.865 [DAT](INFO): DAT read: user:3> 2025-04-07T19:34:27.866Z,1744054467.866 [DAT](INFO): DAT read: TxPower | 8 (Max) 2025-04-07T19:34:27.866Z,1744054467.866 [DAT](INFO): set transmit power to 8 2025-04-07T19:34:27.866Z,1744054467.866 [DAT](INFO): setting local address to 1 2025-04-07T19:34:28.117Z,1744054468.117 [DAT](INFO): DAT read: user:4> 2025-04-07T19:34:28.118Z,1744054468.118 [DAT](INFO): DAT read: LocalAddr | 1 2025-04-07T19:34:28.118Z,1744054468.118 [DAT](INFO): set local address to 1 2025-04-07T19:34:28.119Z,1744054468.119 [DAT](INFO): Setting time to: 19:34:28 And date to:4/7/2025 2025-04-07T19:34:28.369Z,1744054468.369 [DAT](INFO): DAT read: user:5> 2025-04-07T19:34:28.369Z,1744054468.369 [DAT](INFO): DAT read: Mon Apr 7, 2025 19:34:28 2025-04-07T19:34:28.370Z,1744054468.370 [DAT](INFO): Local DAT time set to Mon Apr 7, 2025 19:34:28 2025-04-07T19:34:37.139Z,1744054477.139 [NAL9602](INFO): Powering up NAL9602 2025-04-07T19:34:47.096Z,1744054487.096 [Waterlinked](INFO): Powering down 2025-04-07T19:34:48.226Z,1744054488.226 [NAL9602](INFO): NAL9602 initialized 2025-04-07T19:35:06.399Z,1744054506.399 [NAL9602](INFO): SBD MO Status=0, MOMSN=22523, MT Status=0, MTMSN=0 2025-04-07T19:35:06.399Z,1744054506.399 [NAL9602](INFO): No messages in MT queue 2025-04-07T19:35:07.615Z,1744054507.615 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193506.00,A,3647.82723,N,12151.32183,W,29.955,90.61,070425,,,A*7B 2025-04-07T19:35:07.619Z,1744054507.619 [NAL9602](INFO): GPS fix at 20250407T193506: (36.797120, -121.855364) 2025-04-07T19:35:17.324Z,1744054517.324 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-07T19:35:20.601Z,1744054520.601 [SBIT](IMPORTANT): Beginning Startup BIT 2025-04-07T19:35:32.663Z,1744054532.663 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-07T19:35:39.938Z,1744054539.938 [NAL9602](INFO): Not Powering down - fast GPS 2025-04-07T19:35:48.015Z,1744054548.015 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-07T19:36:03.771Z,1744054563.771 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-07T19:36:13.892Z,1744054573.892 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2025-04-07T19:36:14.323Z,1744054574.323 [SBIT](IMPORTANT): SBIT PASSED 2025-04-07T19:36:14.323Z,1744054574.323 [SBIT](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2025-04-07T19:36:14.692Z,1744054574.692 [MissionManager](IMPORTANT): Started mission Startup 2025-04-07T19:36:14.693Z,1744054574.693 [Startup] Running Loop=1 2025-04-07T19:36:14.693Z,1744054574.693 [Startup](DEBUG): Aggregate::initialize Startup 2025-04-07T19:36:14.693Z,1744054574.693 [Startup:A.GoToSurface] Running Loop=1 2025-04-07T19:36:14.693Z,1744054574.693 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-04-07T19:36:14.693Z,1744054574.693 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-04-07T19:36:14.694Z,1744054574.694 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-04-07T19:36:14.694Z,1744054574.694 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-04-07T19:36:14.695Z,1744054574.695 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-04-07T19:36:14.695Z,1744054574.695 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-04-07T19:36:14.695Z,1744054574.695 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-04-07T19:36:14.697Z,1744054574.697 [Startup:StartupSatComms] Running Loop=1 2025-04-07T19:36:14.697Z,1744054574.697 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2025-04-07T19:36:14.697Z,1744054574.697 [Startup:StartupSatComms:A] Running Loop=1 2025-04-07T19:36:15.098Z,1744054575.098 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2025-04-07T19:36:16.707Z,1744054576.707 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193615.00,A,3647.82089,N,12150.76418,W,4.529,88.49,070425,,,A*40 2025-04-07T19:36:16.709Z,1744054576.709 [NAL9602](INFO): GPS fix at 20250407T193615: (36.797015, -121.846070) 2025-04-07T19:36:16.721Z,1744054576.721 [Startup:StartupSatComms:A] Stopped 2025-04-07T19:36:16.721Z,1744054576.721 [Startup:StartupSatComms:B] Running Loop=1 2025-04-07T19:36:17.145Z,1744054577.145 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-04-07T19:36:19.152Z,1744054579.152 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-07T19:36:32.129Z,1744054592.129 [NAL9602](INFO): SBD MO Status=1, MOMSN=22524, MT Status=0, MTMSN=0 2025-04-07T19:36:32.188Z,1744054592.188 [NAL9602](INFO): Sent 86 bytes from file Logs/20250407T161932/Courier0094.lzma 2025-04-07T19:36:32.188Z,1744054592.188 [NAL9602](INFO): Packets left to send: 0 2025-04-07T19:36:35.400Z,1744054595.400 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7). 2025-04-07T19:36:37.023Z,1744054597.023 [NAL9602](INFO): SBD MO Status=1, MOMSN=22525, MT Status=0, MTMSN=0 2025-04-07T19:36:37.073Z,1744054597.073 [NAL9602](INFO): Sent 18 bytes from file Logs/20250407T161932/Courier0097.lzma 2025-04-07T19:36:37.073Z,1744054597.073 [NAL9602](INFO): Packets left to send: 0 2025-04-07T19:36:44.354Z,1744054604.354 [NAL9602](INFO): SBD MO Status=1, MOMSN=22526, MT Status=0, MTMSN=0 2025-04-07T19:36:44.404Z,1744054604.404 [NAL9602](INFO): Sent 332 bytes from file Logs/20250407T193357/Courier0000.lzma 2025-04-07T19:36:44.404Z,1744054604.404 [NAL9602](INFO): Packets left to send: 1 2025-04-07T19:36:59.333Z,1744054619.333 [NAL9602](INFO): SBD MO Status=2, MOMSN=22527, MT Status=2, MTMSN=0 2025-04-07T19:36:59.334Z,1744054619.334 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-07T19:37:17.119Z,1744054637.119 [Startup:StartupSatComms:B](INFO): Timed out from 2025-04-07T19:36:16.7Z 2025-04-07T19:37:17.120Z,1744054637.120 [Startup:StartupSatComms:B] Stopped 2025-04-07T19:37:17.120Z,1744054637.120 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2025-04-07T19:37:17.120Z,1744054637.120 [Startup:StartupSatComms] Stopped 2025-04-07T19:37:17.120Z,1744054637.120 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2025-04-07T19:37:17.121Z,1744054637.121 [Startup](INFO): Completed Startup 2025-04-07T19:37:17.121Z,1744054637.121 [MissionManager](INFO): Startup is completed. 2025-04-07T19:37:17.121Z,1744054637.121 [MissionManager](INFO): Uninitializing Mission Startup 2025-04-07T19:37:17.122Z,1744054637.122 [Startup] Stopped 2025-04-07T19:37:17.122Z,1744054637.122 [Startup](DEBUG): Aggregate::uninitialize Startup 2025-04-07T19:37:17.122Z,1744054637.122 [Startup:A.GoToSurface] Stopped 2025-04-07T19:37:17.122Z,1744054637.122 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-04-07T19:37:17.533Z,1744054637.533 [MissionManager](IMPORTANT): Started mission Default 2025-04-07T19:37:17.533Z,1744054637.533 [Default] Running Loop=1 2025-04-07T19:37:17.533Z,1744054637.533 [Default](DEBUG): Aggregate::initialize Default 2025-04-07T19:37:17.533Z,1744054637.533 [Default:B.GoToSurface] Running Loop=1 2025-04-07T19:37:17.534Z,1744054637.534 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-04-07T19:37:17.534Z,1744054637.534 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-04-07T19:37:17.534Z,1744054637.534 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-04-07T19:37:17.534Z,1744054637.534 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-04-07T19:37:17.535Z,1744054637.535 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-04-07T19:37:17.535Z,1744054637.535 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-04-07T19:37:17.535Z,1744054637.535 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-04-07T19:37:17.536Z,1744054637.536 [Default:A.Wait] Running Loop=1 2025-04-07T19:37:17.536Z,1744054637.536 [Default:A.Wait](DEBUG): Initialize Wait Component. 2025-04-07T19:37:30.921Z,1744054650.921 [Default:A.Wait](INFO): Done Waiting. 2025-04-07T19:37:30.921Z,1744054650.921 [Default:A.Wait] Stopped 2025-04-07T19:37:30.922Z,1744054650.922 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2025-04-07T19:37:31.263Z,1744054651.263 [Default:CheckIn] Running Loop=1 2025-04-07T19:37:31.263Z,1744054651.263 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-07T19:37:31.263Z,1744054651.263 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-07T19:37:31.680Z,1744054651.680 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2025-04-07T19:37:33.271Z,1744054653.271 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193731.00,A,3647.81986,N,12150.73580,W,0.622,280.79,070425,,,A*72 2025-04-07T19:37:33.273Z,1744054653.273 [NAL9602](INFO): GPS fix at 20250407T193731: (36.796998, -121.845597) 2025-04-07T19:37:33.285Z,1744054653.285 [Default:CheckIn:Read_GPS] Stopped 2025-04-07T19:37:33.285Z,1744054653.285 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-07T19:37:33.714Z,1744054653.714 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-04-07T19:37:53.121Z,1744054673.121 [NAL9602](INFO): SBD MO Status=2, MOMSN=22527, MT Status=2, MTMSN=0 2025-04-07T19:37:53.121Z,1744054673.121 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-07T19:37:59.479Z,1744054679.479 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004534 2025-04-07T19:38:07.156Z,1744054687.156 [DataOverHttps](INFO): Sending 334 bytes from file Logs/20250407T193357/Courier0000.lzma 2025-04-07T19:38:08.158Z,1744054688.158 [DataOverHttps](INFO): Moved sent file to Logs/20250407T193357/Courier0000.lzma.bak 2025-04-07T19:38:08.158Z,1744054688.158 [DataOverHttps](INFO): SBD MOMSN=24563993 2025-04-07T19:38:24.091Z,1744054704.091 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250407T193357/Courier0004.lzma 2025-04-07T19:38:25.094Z,1744054705.094 [DataOverHttps](INFO): Moved sent file to Logs/20250407T193357/Courier0004.lzma.bak 2025-04-07T19:38:25.094Z,1744054705.094 [DataOverHttps](INFO): SBD MOMSN=24563997 2025-04-07T19:38:31.625Z,1744054711.625 [NAL9602](INFO): Not Powering down - fast GPS 2025-04-07T19:38:42.178Z,1744054722.178 [DataOverHttps](INFO): Sending 297 bytes from file Logs/20250407T161932/Express0095.lzma 2025-04-07T19:38:43.178Z,1744054723.178 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161932/Express0095.lzma.bak 2025-04-07T19:38:43.178Z,1744054723.178 [DataOverHttps](INFO): SBD MOMSN=24564000 2025-04-07T19:38:57.004Z,1744054737.004 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-07T19:39:03.456Z,1744054743.456 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-07T19:39:03.743Z,1744054743.743 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20250407T161932/Express0098.lzma 2025-04-07T19:39:05.750Z,1744054745.750 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161932/Express0098.lzma.bak 2025-04-07T19:39:05.750Z,1744054745.750 [DataOverHttps](INFO): SBD MOMSN=24564008 2025-04-07T19:39:17.193Z,1744054757.193 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-07T19:39:21.685Z,1744054761.685 [DataOverHttps](INFO): Sending 797 bytes from file Logs/20250407T193357/Express0001.lzma 2025-04-07T19:39:22.686Z,1744054762.686 [DataOverHttps](INFO): Moved sent file to Logs/20250407T193357/Express0001.lzma.bak 2025-04-07T19:39:22.687Z,1744054762.687 [DataOverHttps](INFO): SBD MOMSN=24564010 2025-04-07T19:39:31.331Z,1744054771.331 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-07T19:39:40.720Z,1744054780.720 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20250407T193357/Express0005.lzma 2025-04-07T19:39:41.722Z,1744054781.722 [DataOverHttps](INFO): Moved sent file to Logs/20250407T193357/Express0005.lzma.bak 2025-04-07T19:39:41.722Z,1744054781.722 [DataOverHttps](INFO): SBD MOMSN=24564027 2025-04-07T19:39:43.068Z,1744054783.068 [Default:CheckIn:Read_Iridium] Stopped 2025-04-07T19:39:43.068Z,1744054783.068 [Default:CheckIn:C.Wait] Running Loop=1 2025-04-07T19:39:43.068Z,1744054783.068 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-04-07T19:39:45.478Z,1744054785.478 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-07T19:39:59.611Z,1744054799.611 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-07T19:40:13.348Z,1744054813.348 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-07T19:40:27.085Z,1744054827.085 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-07T19:40:40.419Z,1744054840.419 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-07T19:40:54.236Z,1744054854.236 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-07T19:41:08.378Z,1744054868.378 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-07T19:43:23.645Z,1744055003.645 [DataOverHttps](IMPORTANT): SBD MTMSN=20250407T194323 2025-04-07T19:43:32.028Z,1744055012.028 [DataOverHttps](INFO): Received command: restart sys 2025-04-07T19:43:32.117Z,1744055012.117 [CommandExec](IMPORTANT): got command restart system 2025-04-07T19:43:34.177Z,1744055014.177 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2025-04-07T19:43:34.177Z,1744055014.177 [CommandExec](INFO): Uninitializing the command executive. 2025-04-07T19:43:34.177Z,1744055014.177 [CommandExec](INFO): Uninitializing the command scheduler. 2025-04-07T19:43:34.178Z,1744055014.178 [CommandExec ThreadHandler](INFO): Thread cancelled. 2025-04-07T19:43:34.204Z,1744055014.204 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2025-04-07T19:43:34.204Z,1744055014.204 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2025-04-07T19:43:34.204Z,1744055014.204 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-04-07T19:43:34.205Z,1744055014.205 [NavChartDb](INFO): Join timeout helper Thread ID is 987 2025-04-07T19:43:34.404Z,1744055014.404 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2025-04-07T19:43:34.404Z,1744055014.404 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-04-07T19:43:34.424Z,1744055014.424 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2025-04-07T19:43:34.424Z,1744055014.424 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2025-04-07T19:43:34.424Z,1744055014.424 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 988 2025-04-07T19:43:34.772Z,1744055014.772 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2025-04-07T19:43:34.772Z,1744055014.772 [WetLabsBB2FL](INFO): Powering down 2025-04-07T19:43:34.773Z,1744055014.773 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2025-04-07T19:43:34.777Z,1744055014.777 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2025-04-07T19:43:34.777Z,1744055014.777 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2025-04-07T19:43:34.777Z,1744055014.777 [CTD_Seabird](INFO): Join timeout helper Thread ID is 989 2025-04-07T19:43:35.472Z,1744055015.472 [CTD_Seabird](INFO): Powering down 2025-04-07T19:43:35.484Z,1744055015.484 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2025-04-07T19:43:35.484Z,1744055015.484 [CTD_Seabird](INFO): Powering down 2025-04-07T19:43:35.496Z,1744055015.496 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2025-04-07T19:43:35.512Z,1744055015.512 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2025-04-07T19:43:35.512Z,1744055015.512 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2025-04-07T19:43:35.512Z,174