2025-04-15T15:37:14.594Z,1744731434.594 [Supervisor](DEBUG): Initializing supervisor. 2025-04-15T15:37:14.598Z,1744731434.598 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2025-04-15T15:37:14.599Z,1744731434.599 [SyncHandler](INFO): Protected caller Thread ID is 829 2025-04-15T15:37:14.599Z,1744731434.599 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2025-04-15T15:37:14.600Z,1744731434.600 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2025-04-15T15:37:14.601Z,1744731434.601 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 830 2025-04-15T15:37:14.605Z,1744731434.605 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2025-04-15T15:37:14.626Z,1744731434.626 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2025-04-15T15:37:14.627Z,1744731434.627 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2025-04-15T15:37:14.627Z,1744731434.627 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 831 2025-04-15T15:37:14.631Z,1744731434.631 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2025-04-15T15:37:14.633Z,1744731434.633 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2025-04-15T15:37:14.633Z,1744731434.633 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 832 2025-04-15T15:37:14.635Z,1744731434.635 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2025-04-15T15:37:14.636Z,1744731434.636 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2025-04-15T15:37:14.637Z,1744731434.637 [logger ThreadHandler](INFO): Protected caller Thread ID is 833 2025-04-15T15:37:14.641Z,1744731434.641 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2025-04-15T15:37:14.641Z,1744731434.641 [Supervisor](INFO): Looking for Config files in directory: Config/ 2025-04-15T15:37:14.646Z,1744731434.646 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2025-04-15T15:37:14.753Z,1744731434.753 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2025-04-15T15:37:14.755Z,1744731434.755 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2025-04-15T15:37:14.990Z,1744731434.990 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2025-04-15T15:37:14.992Z,1744731434.992 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2025-04-15T15:37:15.268Z,1744731435.268 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2025-04-15T15:37:15.270Z,1744731435.270 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2025-04-15T15:37:15.388Z,1744731435.388 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2025-04-15T15:37:15.390Z,1744731435.390 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2025-04-15T15:37:16.169Z,1744731436.169 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2025-04-15T15:37:16.171Z,1744731436.171 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2025-04-15T15:37:16.695Z,1744731436.695 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2025-04-15T15:37:16.695Z,1744731436.695 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2025-04-15T15:37:17.266Z,1744731437.266 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2025-04-15T15:37:17.267Z,1744731437.267 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2025-04-15T15:37:17.707Z,1744731437.707 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2025-04-15T15:37:18.009Z,1744731438.009 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2025-04-15T15:37:18.755Z,1744731438.755 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2025-04-15T15:37:18.755Z,1744731438.755 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2025-04-15T15:37:19.146Z,1744731439.146 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2025-04-15T15:37:19.146Z,1744731439.146 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2025-04-15T15:37:19.385Z,1744731439.385 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2025-04-15T15:37:19.387Z,1744731439.387 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2025-04-15T15:37:19.539Z,1744731439.539 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2025-04-15T15:37:19.539Z,1744731439.539 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2025-04-15T15:37:19.632Z,1744731439.632 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2025-04-15T15:37:19.722Z,1744731439.722 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2025-04-15T15:37:19.924Z,1744731439.924 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2025-04-15T15:37:19.926Z,1744731439.926 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2025-04-15T15:37:20.182Z,1744731440.182 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2025-04-15T15:37:20.184Z,1744731440.184 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/ 2025-04-15T15:37:20.186Z,1744731440.186 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg 2025-04-15T15:37:20.281Z,1744731440.281 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg 2025-04-15T15:37:20.560Z,1744731440.560 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2025-04-15T15:37:20.561Z,1744731440.561 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg 2025-04-15T15:37:20.655Z,1744731440.655 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg 2025-04-15T15:37:20.833Z,1744731440.833 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg 2025-04-15T15:37:20.943Z,1744731440.943 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg 2025-04-15T15:37:21.063Z,1744731441.063 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg 2025-04-15T15:37:21.185Z,1744731441.185 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg 2025-04-15T15:37:21.290Z,1744731441.290 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg 2025-04-15T15:37:21.459Z,1744731441.459 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Derivation.cfg 2025-04-15T15:37:21.566Z,1744731441.566 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/workSite.cfg 2025-04-15T15:37:21.661Z,1744731441.661 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg 2025-04-15T15:37:21.769Z,1744731441.769 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg 2025-04-15T15:37:21.865Z,1744731441.865 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2025-04-15T15:37:21.870Z,1744731441.870 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2025-04-15T15:37:22.094Z,1744731442.094 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2025-04-15T15:37:22.094Z,1744731442.094 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2025-04-15T15:37:22.290Z,1744731442.290 [BuoyancyServo] Loaded 2025-04-15T15:37:22.291Z,1744731442.291 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2025-04-15T15:37:22.315Z,1744731442.315 [ElevatorServo] Loaded 2025-04-15T15:37:22.315Z,1744731442.315 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2025-04-15T15:37:22.338Z,1744731442.338 [MassServo] Loaded 2025-04-15T15:37:22.338Z,1744731442.338 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2025-04-15T15:37:22.360Z,1744731442.360 [RudderServo] Loaded 2025-04-15T15:37:22.361Z,1744731442.361 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2025-04-15T15:37:22.379Z,1744731442.379 [ThrusterHE] Loaded 2025-04-15T15:37:22.379Z,1744731442.379 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2025-04-15T15:37:22.380Z,1744731442.380 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2025-04-15T15:37:22.381Z,1744731442.381 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2025-04-15T15:37:22.580Z,1744731442.580 [SBIT](DEBUG): Construct Startup Built In Test. 2025-04-15T15:37:22.595Z,1744731442.595 [SBIT] Loaded 2025-04-15T15:37:22.595Z,1744731442.595 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2025-04-15T15:37:22.598Z,1744731442.598 [IBIT](DEBUG): Construct Initiated Built In Test. 2025-04-15T15:37:22.620Z,1744731442.620 [IBIT] Loaded 2025-04-15T15:37:22.620Z,1744731442.620 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2025-04-15T15:37:22.625Z,1744731442.625 [CBIT](DEBUG): Construct Continuous Built In Test. 2025-04-15T15:37:22.819Z,1744731442.819 [CBIT] Loaded 2025-04-15T15:37:22.819Z,1744731442.819 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2025-04-15T15:37:22.851Z,1744731442.851 [GFScanner] Loaded 2025-04-15T15:37:22.851Z,1744731442.851 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread. 2025-04-15T15:37:22.851Z,1744731442.851 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2025-04-15T15:37:22.852Z,1744731442.852 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2025-04-15T15:37:23.627Z,1744731443.627 [CTD_Seabird] Loaded 2025-04-15T15:37:23.627Z,1744731443.627 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2025-04-15T15:37:23.628Z,1744731443.628 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406834E0 2025-04-15T15:37:23.628Z,1744731443.628 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 921 2025-04-15T15:37:23.664Z,1744731443.664 [ESPComponent] Loaded 2025-04-15T15:37:23.664Z,1744731443.664 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2025-04-15T15:37:23.686Z,1744731443.686 [PAR_Licor] Loaded 2025-04-15T15:37:23.686Z,1744731443.686 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2025-04-15T15:37:23.732Z,1744731443.732 [WetLabsBB2FL] Loaded 2025-04-15T15:37:23.733Z,1744731443.733 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2025-04-15T15:37:23.734Z,1744731443.734 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406B34E0 2025-04-15T15:37:23.734Z,1744731443.734 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 922 2025-04-15T15:37:23.735Z,1744731443.735 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2025-04-15T15:37:23.735Z,1744731443.735 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2025-04-15T15:37:23.808Z,1744731443.808 [DepthRateCalculator] Loaded 2025-04-15T15:37:23.808Z,1744731443.808 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2025-04-15T15:37:23.814Z,1744731443.814 [PitchRateCalculator] Loaded 2025-04-15T15:37:23.814Z,1744731443.814 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2025-04-15T15:37:23.824Z,1744731443.824 [SpeedCalculator] Loaded 2025-04-15T15:37:23.825Z,1744731443.825 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2025-04-15T15:37:23.829Z,1744731443.829 [YawRateCalculator] Loaded 2025-04-15T15:37:23.830Z,1744731443.830 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2025-04-15T15:37:23.849Z,1744731443.849 [ElevatorOffsetCalculator] Loaded 2025-04-15T15:37:23.850Z,1744731443.850 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2025-04-15T15:37:23.850Z,1744731443.850 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2025-04-15T15:37:23.851Z,1744731443.851 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2025-04-15T15:37:24.023Z,1744731444.023 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2025-04-15T15:37:24.024Z,1744731444.024 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2025-04-15T15:37:24.073Z,1744731444.073 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2025-04-15T15:37:24.075Z,1744731444.075 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2025-04-15T15:37:24.215Z,1744731444.215 [DeadReckonUsingMultipleVelocitySources] Loaded 2025-04-15T15:37:24.215Z,1744731444.215 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2025-04-15T15:37:24.230Z,1744731444.230 [NavChart] Loaded 2025-04-15T15:37:24.230Z,1744731444.230 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2025-04-15T15:37:24.236Z,1744731444.236 [UniversalFixResidualReporter] Loaded 2025-04-15T15:37:24.236Z,1744731444.236 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2025-04-15T15:37:24.236Z,1744731444.236 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2025-04-15T15:37:24.237Z,1744731444.237 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2025-04-15T15:37:25.123Z,1744731445.123 [AHRS_M2] Loaded 2025-04-15T15:37:25.123Z,1744731445.123 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2025-04-15T15:37:25.376Z,1744731445.376 [BackseatComponent] Loaded 2025-04-15T15:37:25.376Z,1744731445.376 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2025-04-15T15:37:25.377Z,1744731445.377 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 40A7F4E0 2025-04-15T15:37:25.378Z,1744731445.378 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 923 2025-04-15T15:37:25.381Z,1744731445.381 [LcmUniversalReporter] Loaded 2025-04-15T15:37:25.381Z,1744731445.381 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2025-04-15T15:37:26.122Z,1744731446.122 [BPC1] Loaded 2025-04-15T15:37:26.123Z,1744731446.123 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2025-04-15T15:37:26.221Z,1744731446.221 [DAT] Loaded 2025-04-15T15:37:26.221Z,1744731446.221 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2025-04-15T15:37:26.222Z,1744731446.222 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40AAF4E0 2025-04-15T15:37:26.222Z,1744731446.222 [DAT ThreadHandler](INFO): Protected caller Thread ID is 924 2025-04-15T15:37:26.364Z,1744731446.364 [DataOverHttps] Loaded 2025-04-15T15:37:26.364Z,1744731446.364 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2025-04-15T15:37:26.365Z,1744731446.365 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 40ADF4E0 2025-04-15T15:37:26.366Z,1744731446.366 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 925 2025-04-15T15:37:26.389Z,1744731446.389 [Depth_Keller] Loaded 2025-04-15T15:37:26.390Z,1744731446.390 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2025-04-15T15:37:26.395Z,1744731446.395 [DropWeight] Loaded 2025-04-15T15:37:26.395Z,1744731446.395 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2025-04-15T15:37:26.436Z,1744731446.436 [DVL_micro] Loaded 2025-04-15T15:37:26.436Z,1744731446.436 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2025-04-15T15:37:26.499Z,1744731446.499 [NAL9602] Loaded 2025-04-15T15:37:26.499Z,1744731446.499 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2025-04-15T15:37:26.526Z,1744731446.526 [Onboard] Loaded 2025-04-15T15:37:26.526Z,1744731446.526 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2025-04-15T15:37:26.527Z,1744731446.527 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40B0F4E0 2025-04-15T15:37:26.527Z,1744731446.527 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 926 2025-04-15T15:37:26.533Z,1744731446.533 [PowerOnly](INFO): Adding load control power supply at /dev/loadB1 2025-04-15T15:37:26.547Z,1744731446.547 [PowerOnly] Loaded 2025-04-15T15:37:26.547Z,1744731446.547 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread. 2025-04-15T15:37:26.562Z,1744731446.562 [Power24vConverter] Loaded 2025-04-15T15:37:26.562Z,1744731446.562 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2025-04-15T15:37:26.578Z,1744731446.578 [Radio_Surface] Loaded 2025-04-15T15:37:26.578Z,1744731446.578 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2025-04-15T15:37:26.579Z,1744731446.579 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40B3F4E0 2025-04-15T15:37:26.580Z,1744731446.580 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 927 2025-04-15T15:37:26.596Z,1744731446.596 [Sonardyne_Nano] Loaded 2025-04-15T15:37:26.596Z,1744731446.596 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread. 2025-04-15T15:37:26.597Z,1744731446.597 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2025-04-15T15:37:26.598Z,1744731446.598 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2025-04-15T15:37:26.685Z,1744731446.685 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2025-04-15T15:37:26.686Z,1744731446.686 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2025-04-15T15:37:26.761Z,1744731446.761 [VerticalControl](DEBUG): Construct VerticalControl. 2025-04-15T15:37:26.814Z,1744731446.814 [VerticalControl] Loaded 2025-04-15T15:37:26.815Z,1744731446.815 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2025-04-15T15:37:26.818Z,1744731446.818 [HorizontalControl](DEBUG): Construct HorizontalControl. 2025-04-15T15:37:26.863Z,1744731446.863 [HorizontalControl] Loaded 2025-04-15T15:37:26.863Z,1744731446.863 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2025-04-15T15:37:26.865Z,1744731446.865 [SpeedControl](DEBUG): Construct SpeedControl. 2025-04-15T15:37:26.867Z,1744731446.867 [SpeedControl] Loaded 2025-04-15T15:37:26.867Z,1744731446.867 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2025-04-15T15:37:26.870Z,1744731446.870 [LoopControl](DEBUG): Construct LoopControl. 2025-04-15T15:37:26.871Z,1744731446.871 [LoopControl] Loaded 2025-04-15T15:37:26.871Z,1744731446.871 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2025-04-15T15:37:26.872Z,1744731446.872 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2025-04-15T15:37:26.872Z,1744731446.872 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2025-04-15T15:37:26.888Z,1744731446.888 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2025-04-15T15:37:26.889Z,1744731446.889 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2025-04-15T15:37:27.305Z,1744731447.305 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2025-04-15T15:37:27.312Z,1744731447.312 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2025-04-15T15:37:27.315Z,1744731447.315 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2025-04-15T15:37:27.326Z,1744731447.326 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2025-04-15T15:37:27.327Z,1744731447.327 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C654E0 2025-04-15T15:37:27.328Z,1744731447.328 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 928 2025-04-15T15:37:27.332Z,1744731447.332 [Supervisor](INFO): Main Thread ID is 822 2025-04-15T15:37:27.332Z,1744731447.332 [Supervisor](DEBUG): Running supervisor. 2025-04-15T15:37:27.333Z,1744731447.333 [CommandExec ThreadHandler](INFO): Handler Thread ID is 929 2025-04-15T15:37:27.333Z,1744731447.333 [CommandExec](INFO): Initializing the command executive. 2025-04-15T15:37:27.335Z,1744731447.335 [CommandLine ThreadHandler](INFO): Handler Thread ID is 930 2025-04-15T15:37:27.337Z,1744731447.337 [controlThread ThreadHandler](INFO): Handler Thread ID is 931 2025-04-15T15:37:27.337Z,1744731447.337 [controlThread](DEBUG): Initializing ControlThread 2025-04-15T15:37:27.339Z,1744731447.339 [SBIT](INFO): Initialize SBIT Component. 2025-04-15T15:37:27.340Z,1744731447.340 [SBIT](IMPORTANT): git: 2025-04-02-2-g1635786d1 2025-04-15T15:37:27.340Z,1744731447.340 [SBIT](INFO): git hash: 1635786d188a1b3aba7073e6184020eb8609012e 2025-04-15T15:37:27.340Z,1744731447.340 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2025-04-15T15:37:27.342Z,1744731447.342 [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 2025-04-15T15:37:27.343Z,1744731447.343 [SBIT](INFO): Beginning SBIT in 107.000000 seconds. 2025-04-15T15:37:27.343Z,1744731447.343 [IBIT](INFO): Initialize IBIT Component. 2025-04-15T15:37:27.344Z,1744731447.344 [CBIT](DEBUG): Initialize CBIT Component. 2025-04-15T15:37:27.345Z,1744731447.345 [logger ThreadHandler](INFO): Handler Thread ID is 932 2025-04-15T15:37:27.356Z,1744731447.356 [CBIT](DEBUG): Initialized mux pins. 2025-04-15T15:37:27.357Z,1744731447.357 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL. 2025-04-15T15:37:27.357Z,1744731447.357 [CBIT](DEBUG): Initializing the watchdog timer. 2025-04-15T15:37:27.365Z,1744731447.365 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 933 2025-04-15T15:37:27.366Z,1744731447.366 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2025-04-15T15:37:27.370Z,1744731447.370 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 935 2025-04-15T15:37:27.373Z,1744731447.373 [WetLabsBB2FL](INFO): Powering up 2025-04-15T15:37:27.374Z,1744731447.374 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 937 2025-04-15T15:37:27.380Z,1744731447.380 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET. 2025-04-15T15:37:27.381Z,1744731447.381 [CBIT](DEBUG): Initializing heartbeat. 2025-04-15T15:37:27.382Z,1744731447.382 [DAT ThreadHandler](INFO): Handler Thread ID is 938 2025-04-15T15:37:27.383Z,1744731447.383 [DAT](INFO): Powering up 2025-04-15T15:37:27.383Z,1744731447.383 [DAT](DEBUG): Initializing DAT. 2025-04-15T15:37:27.386Z,1744731447.386 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 940 2025-04-15T15:37:27.387Z,1744731447.387 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2025-04-15T15:37:27.409Z,1744731447.409 [Onboard ThreadHandler](INFO): Handler Thread ID is 941 2025-04-15T15:37:27.426Z,1744731447.426 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 942 2025-04-15T15:37:27.449Z,1744731447.449 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 943 2025-04-15T15:37:27.452Z,1744731447.452 [CBIT](DEBUG): Deactivating emergency mode. 2025-04-15T15:37:27.457Z,1744731447.457 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2025-04-15T15:37:27.458Z,1744731447.458 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2025-04-15T15:37:27.458Z,1744731447.458 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2025-04-15T15:37:27.458Z,1744731447.458 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2025-04-15T15:37:27.458Z,1744731447.458 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2025-04-15T15:37:27.458Z,1744731447.458 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2025-04-15T15:37:27.459Z,1744731447.459 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2025-04-15T15:37:27.459Z,1744731447.459 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2025-04-15T15:37:27.493Z,1744731447.493 [CBIT](DEBUG): Backplane powered. 2025-04-15T15:37:27.493Z,1744731447.493 [GFScanner](DEBUG): Initializing GFScanner 2025-04-15T15:37:27.497Z,1744731447.497 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2025-04-15T15:37:27.497Z,1744731447.497 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2025-04-15T15:37:27.498Z,1744731447.498 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2025-04-15T15:37:27.498Z,1744731447.498 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2025-04-15T15:37:27.498Z,1744731447.498 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2025-04-15T15:37:27.499Z,1744731447.499 [NavChart](DEBUG): Initialize NavChart Navigation. 2025-04-15T15:37:27.500Z,1744731447.500 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2025-04-15T15:37:27.504Z,1744731447.504 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2025-04-15T15:37:27.505Z,1744731447.505 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2025-04-15T15:37:27.506Z,1744731447.506 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2025-04-15T15:37:27.506Z,1744731447.506 [LoopControl](DEBUG): Initialize LoopControlComponent. 2025-04-15T15:37:27.507Z,1744731447.507 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser 2025-04-15T15:37:27.508Z,1744731447.508 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl 2025-04-15T15:37:27.508Z,1744731447.508 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl 2025-04-15T15:37:27.516Z,1744731447.516 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl 2025-04-15T15:37:27.618Z,1744731447.618 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into: 2025-04-15T15:37:27.622Z,1744731447.622 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2025-04-15T15:37:27.637Z,1744731447.637 [DAT](INFO): Using elevation to construct direction to contact in vehicle frame. 2025-04-15T15:37:27.663Z,1744731447.663 [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-15T15:37:27.664Z,1744731447.664 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl 2025-04-15T15:37:27.664Z,1744731447.664 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl 2025-04-15T15:37:27.691Z,1744731447.691 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl 2025-04-15T15:37:27.833Z,1744731447.833 [Radio_Surface](INFO): Powering up 2025-04-15T15:37:28.011Z,1744731448.011 [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-15T15:37:28.041Z,1744731448.041 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2025-04-15T15:37:28.061Z,1744731448.061 [Default:A.Wait](DEBUG): Construct Wait. 2025-04-15T15:37:28.064Z,1744731448.064 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2025-04-15T15:37:28.084Z,1744731448.084 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2025-04-15T15:37:28.087Z,1744731448.087 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2025-04-15T15:37:28.122Z,1744731448.122 [Default:E.Execute](DEBUG): Construct Execute. 2025-04-15T15:37:28.125Z,1744731448.125 [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-15T15:37:28.130Z,1744731448.130 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,PowerOnly,Power24vConverter,Sonardyne_Nano,PAR_Licor,Depth_Keller,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-15T15:37:28.155Z,1744731448.155 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2025-04-15T15:37:28.285Z,1744731448.285 [Depth_Keller](INFO): Initializing. 2025-04-15T15:37:28.288Z,1744731448.288 [Power24vConverter](INFO): Powering up. 2025-04-15T15:37:28.289Z,1744731448.289 [Sonardyne_Nano](INFO): Initializing. 2025-04-15T15:37:28.317Z,1744731448.317 [DepthRateCalculator](ERROR): Depth measurement is not active 2025-04-15T15:37:28.369Z,1744731448.369 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2025-04-15T15:37:28.374Z,1744731448.374 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2025-04-15T15:37:28.375Z,1744731448.375 [ElevatorServo](DEBUG): Initializing EZServoServo. 2025-04-15T15:37:28.381Z,1744731448.381 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2025-04-15T15:37:28.382Z,1744731448.382 [MassServo](DEBUG): Initializing EZServoServo. 2025-04-15T15:37:28.390Z,1744731448.390 [MassServo](DEBUG): Initializing MassServo. 2025-04-15T15:37:28.390Z,1744731448.390 [RudderServo](DEBUG): Initializing EZServoServo. 2025-04-15T15:37:28.397Z,1744731448.397 [RudderServo](DEBUG): Initializing RudderServo. 2025-04-15T15:37:28.398Z,1744731448.398 [ThrusterHE](DEBUG): Initializing EZServoServo. 2025-04-15T15:37:28.405Z,1744731448.405 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2025-04-15T15:37:28.407Z,1744731448.407 [CommandExec](FAULT): Scheduling is paused 2025-04-15T15:37:28.407Z,1744731448.407 [CBIT](INFO): Critical error at 20250415T153727 2025-04-15T15:37:28.407Z,1744731448.407 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2025-04-15T15:37:29.985Z,1744731449.985 [WetLabsBB2FL](INFO): Powering down 2025-04-15T15:37:30.567Z,1744731450.567 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART 2025-04-15T15:37:31.806Z,1744731451.806 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2213 2025-04-15T15:37:34.061Z,1744731454.061 [ThrusterHE](ERROR): Zero Speed Commanded. 2025-04-15T15:37:39.485Z,1744731459.485 [DAT](INFO): DAT read: 2025-04-15T15:37:39.487Z,1744731459.487 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2025-04-15T15:37:41.249Z,1744731461.249 [DAT](INFO): DAT read: MF Frequency Band 2025-04-15T15:37:41.251Z,1744731461.251 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2025-04-15T15:37:41.251Z,1744731461.251 [DAT](INFO): DAT read: Apr 15 2025 15:37:36 2025-04-15T15:37:42.260Z,1744731462.260 [DAT](INFO): DAT read: Features enabled [Bearing] 2025-04-15T15:37:42.510Z,1744731462.510 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC 2025-04-15T15:37:42.510Z,1744731462.510 [DAT](INFO): commRate: 1200 2025-04-15T15:37:44.577Z,1744731464.577 [DAT](INFO): entering command mode 2025-04-15T15:37:44.777Z,1744731464.777 [DAT](INFO): DAT read: 2025-04-15T15:37:44.778Z,1744731464.778 [DAT](INFO): DAT read: user:1> 2025-04-15T15:37:44.778Z,1744731464.778 [DAT](INFO): setting verbose to 3 2025-04-15T15:37:45.029Z,1744731465.029 [DAT](INFO): DAT read: user:1> 2025-04-15T15:37:45.030Z,1744731465.030 [DAT](INFO): DAT read: Verbose | 3 2025-04-15T15:37:45.031Z,1744731465.031 [DAT](INFO): set verbose to 3 2025-04-15T15:37:45.031Z,1744731465.031 [DAT](INFO): setting DatVerbose to 27440 2025-04-15T15:37:45.281Z,1744731465.281 [DAT](INFO): DAT read: user:2> 2025-04-15T15:37:45.282Z,1744731465.282 [DAT](INFO): DAT read: DatVerbose | 27440 2025-04-15T15:37:45.283Z,1744731465.283 [DAT](INFO): set DatVerbose to 27440 2025-04-15T15:37:45.283Z,1744731465.283 [DAT](INFO): setting transmit power to 8 2025-04-15T15:37:45.533Z,1744731465.533 [DAT](INFO): DAT read: user:3> 2025-04-15T15:37:45.534Z,1744731465.534 [DAT](INFO): DAT read: TxPower | 8 (Max) 2025-04-15T15:37:45.535Z,1744731465.535 [DAT](INFO): set transmit power to 8 2025-04-15T15:37:45.535Z,1744731465.535 [DAT](INFO): setting local address to 5 2025-04-15T15:37:45.786Z,1744731465.786 [DAT](INFO): DAT read: user:4> 2025-04-15T15:37:45.787Z,1744731465.787 [DAT](INFO): DAT read: LocalAddr | 5 2025-04-15T15:37:45.787Z,1744731465.787 [DAT](INFO): set local address to 5 2025-04-15T15:37:45.788Z,1744731465.788 [DAT](INFO): Setting time to: 15:37:45 And date to:4/15/2025 2025-04-15T15:37:46.038Z,1744731466.038 [DAT](INFO): DAT read: user:5> 2025-04-15T15:37:46.040Z,1744731466.040 [DAT](INFO): DAT read: Tue Apr 15, 2025 15:37:45 2025-04-15T15:37:46.040Z,1744731466.040 [DAT](INFO): Local DAT time set to Tue Apr 15, 2025 15:37:45 2025-04-15T15:37:56.844Z,1744731476.844 [NAL9602](INFO): Powering up NAL9602 2025-04-15T15:38:07.739Z,1744731487.739 [NAL9602](INFO): NAL9602 initialized 2025-04-15T15:39:14.831Z,1744731554.831 [SBIT](IMPORTANT): Beginning Startup BIT 2025-04-15T15:39:28.327Z,1744731568.327 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004668 2025-04-15T15:40:09.048Z,1744731609.048 [SBIT](IMPORTANT): SBIT PASSED 2025-04-15T15:40:09.048Z,1744731609.048 [SBIT](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2025-04-15T15:40:09.450Z,1744731609.450 [MissionManager](IMPORTANT): Started mission Startup 2025-04-15T15:40:09.450Z,1744731609.450 [Startup] Running Loop=1 2025-04-15T15:40:09.450Z,1744731609.450 [Startup](DEBUG): Aggregate::initialize Startup 2025-04-15T15:40:09.451Z,1744731609.451 [Startup:A.GoToSurface] Running Loop=1 2025-04-15T15:40:09.451Z,1744731609.451 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-04-15T15:40:09.451Z,1744731609.451 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-04-15T15:40:09.452Z,1744731609.452 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-04-15T15:40:09.452Z,1744731609.452 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-04-15T15:40:09.452Z,1744731609.452 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-04-15T15:40:09.453Z,1744731609.453 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-04-15T15:40:09.453Z,1744731609.453 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-04-15T15:40:09.455Z,1744731609.455 [Startup:StartupSatComms] Running Loop=1 2025-04-15T15:40:09.455Z,1744731609.455 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2025-04-15T15:40:09.455Z,1744731609.455 [Startup:StartupSatComms:A] Running Loop=1 2025-04-15T15:40:09.863Z,1744731609.863 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2025-04-15T15:40:27.618Z,1744731627.618 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2025-04-15T15:40:27.619Z,1744731627.619 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-04-15T15:40:27.660Z,1744731627.660 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-04-15T15:40:28.031Z,1744731628.031 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-04-15T15:40:28.031Z,1744731628.031 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2025-04-15T15:41:09.656Z,1744731669.656 [Startup:StartupSatComms:A](INFO): Timed out from 2025-04-15T15:40:09.5Z 2025-04-15T15:41:09.656Z,1744731669.656 [Startup:StartupSatComms:A] Stopped 2025-04-15T15:41:09.656Z,1744731669.656 [Startup:StartupSatComms:B] Running Loop=1 2025-04-15T15:41:10.058Z,1744731670.058 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-04-15T15:41:17.420Z,1744731677.420 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20250415T152534/Courier0007.lzma 2025-04-15T15:41:18.422Z,1744731678.422 [DataOverHttps](INFO): Moved sent file to Logs/20250415T152534/Courier0007.lzma.bak 2025-04-15T15:41:18.423Z,1744731678.423 [DataOverHttps](INFO): SBD MOMSN=24666097 2025-04-15T15:41:36.193Z,1744731696.193 [DataOverHttps](INFO): Sending 214 bytes from file Logs/20250415T153714/Courier0000.lzma 2025-04-15T15:41:37.194Z,1744731697.194 [DataOverHttps](INFO): Moved sent file to Logs/20250415T153714/Courier0000.lzma.bak 2025-04-15T15:41:37.195Z,1744731697.195 [DataOverHttps](INFO): SBD MOMSN=24666099 2025-04-15T15:41:53.291Z,1744731713.291 [DataOverHttps](INFO): Sending 741 bytes from file Logs/20250415T152534/Express0005.lzma 2025-04-15T15:41:54.290Z,1744731714.290 [DataOverHttps](INFO): Moved sent file to Logs/20250415T152534/Express0005.lzma.bak 2025-04-15T15:41:54.291Z,1744731714.291 [DataOverHttps](INFO): SBD MOMSN=24666104 2025-04-15T15:42:09.848Z,1744731729.848 [Startup:StartupSatComms:B](INFO): Timed out from 2025-04-15T15:41:09.7Z 2025-04-15T15:42:09.848Z,1744731729.848 [Startup:StartupSatComms:B] Stopped 2025-04-15T15:42:09.849Z,1744731729.849 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2025-04-15T15:42:09.850Z,1744731729.850 [Startup:StartupSatComms] Stopped 2025-04-15T15:42:09.850Z,1744731729.850 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2025-04-15T15:42:09.853Z,1744731729.853 [Startup](INFO): Completed Startup 2025-04-15T15:42:09.853Z,1744731729.853 [MissionManager](INFO): Startup is completed. 2025-04-15T15:42:09.853Z,1744731729.853 [MissionManager](INFO): Uninitializing Mission Startup 2025-04-15T15:42:09.853Z,1744731729.853 [Startup] Stopped 2025-04-15T15:42:09.854Z,1744731729.854 [Startup](DEBUG): Aggregate::uninitialize Startup 2025-04-15T15:42:09.854Z,1744731729.854 [Startup:A.GoToSurface] Stopped 2025-04-15T15:42:09.854Z,1744731729.854 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-04-15T15:42:10.261Z,1744731730.261 [MissionManager](IMPORTANT): Started mission Default 2025-04-15T15:42:10.262Z,1744731730.262 [Default] Running Loop=1 2025-04-15T15:42:10.262Z,1744731730.262 [Default](DEBUG): Aggregate::initialize Default 2025-04-15T15:42:10.262Z,1744731730.262 [Default:B.GoToSurface] Running Loop=1 2025-04-15T15:42:10.262Z,1744731730.262 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-04-15T15:42:10.262Z,1744731730.262 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-04-15T15:42:10.263Z,1744731730.263 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-04-15T15:42:10.263Z,1744731730.263 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-04-15T15:42:10.263Z,1744731730.263 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-04-15T15:42:10.263Z,1744731730.263 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-04-15T15:42:10.264Z,1744731730.264 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-04-15T15:42:10.264Z,1744731730.264 [Default:A.Wait] Running Loop=1 2025-04-15T15:42:10.264Z,1744731730.264 [Default:A.Wait](DEBUG): Initialize Wait Component. 2025-04-15T15:42:10.316Z,1744731730.316 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20250415T152534/Express0008.lzma 2025-04-15T15:42:11.318Z,1744731731.318 [DataOverHttps](INFO): Moved sent file to Logs/20250415T152534/Express0008.lzma.bak 2025-04-15T15:42:11.318Z,1744731731.318 [DataOverHttps](INFO): SBD MOMSN=24666135 2025-04-15T15:42:23.584Z,1744731743.584 [Default:A.Wait](INFO): Done Waiting. 2025-04-15T15:42:23.584Z,1744731743.584 [Default:A.Wait] Stopped 2025-04-15T15:42:23.584Z,1744731743.584 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2025-04-15T15:42:24.006Z,1744731744.006 [Default:CheckIn] Running Loop=1 2025-04-15T15:42:24.006Z,1744731744.006 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-15T15:42:24.006Z,1744731744.006 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-15T15:42:24.395Z,1744731744.395 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2025-04-15T15:43:10.845Z,1744731790.845 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-04-15T15:43:28.654Z,1744731808.654 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2025-04-15T15:43:28.654Z,1744731808.654 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-04-15T15:43:28.666Z,1744731808.666 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-04-15T15:43:29.062Z,1744731809.062 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-04-15T15:43:29.062Z,1744731809.062 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2025-04-15T15:44:30.897Z,1744731870.897 [BPC1](ERROR): Battery stick #2 (s/n: 0124) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-04-15T15:44:30.898Z,1744731870.898 [BPC1](ERROR): Battery stick #4 (s/n: 017A) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0. 2025-04-15T15:44:30.899Z,1744731870.899 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6. 2025-04-15T15:44:30.911Z,1744731870.911 [BPC1](INFO): Received data from all battery sticks. 2025-04-15T15:46:29.653Z,1744731989.653 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2025-04-15T15:46:29.653Z,1744731989.653 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-04-15T15:46:29.684Z,1744731989.684 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-04-15T15:46:30.049Z,1744731990.049 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-04-15T15:46:30.050Z,1744731990.050 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2025-04-15T15:47:24.167Z,1744732044.167 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-04-15T15:42:24.0Z 2025-04-15T15:47:24.167Z,1744732044.167 [Default:CheckIn:Read_GPS] Stopped 2025-04-15T15:47:24.167Z,1744732044.167 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-15T15:47:24.571Z,1744732044.571 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-04-15T15:47:33.165Z,1744732053.165 [DataOverHttps](INFO): Sending 170 bytes from file Logs/20250415T153714/Courier0004.lzma 2025-04-15T15:47:34.167Z,1744732054.167 [DataOverHttps](INFO): Moved sent file to Logs/20250415T153714/Courier0004.lzma.bak 2025-04-15T15:47:34.167Z,1744732054.167 [DataOverHttps](INFO): SBD MOMSN=24666150 2025-04-15T15:47:46.818Z,1744732066.818 [CommandExec](IMPORTANT): got command strobe off 2025-04-15T15:47:46.818Z,1744732066.818 [CommandExec](IMPORTANT): Deactivating strobe 2025-04-15T15:47:50.962Z,1744732070.962 [DataOverHttps](INFO): Sending 589 bytes from file Logs/20250415T153714/Express0001.lzma 2025-04-15T15:47:52.966Z,1744732072.966 [DataOverHttps](INFO): Moved sent file to Logs/20250415T153714/Express0001.lzma.bak 2025-04-15T15:47:52.967Z,1744732072.967 [DataOverHttps](INFO): SBD MOMSN=24666152 2025-04-15T15:48:08.749Z,1744732088.749 [DataOverHttps](INFO): Sending 189 bytes from file Logs/20250415T153714/Express0005.lzma 2025-04-15T15:48:09.750Z,1744732089.750 [DataOverHttps](INFO): Moved sent file to Logs/20250415T153714/Express0005.lzma.bak 2025-04-15T15:48:09.751Z,1744732089.751 [DataOverHttps](INFO): SBD MOMSN=24666165 2025-04-15T15:48:10.636Z,1744732090.636 [NAL9602](FAULT): GPS failed to acquire within timeout. 2025-04-15T15:48:10.636Z,1744732090.636 [NAL9602] Data Fault, FailCount= 1 2025-04-15T15:48:10.636Z,1744732090.636 [NAL9602](ERROR): Data Fault 2025-04-15T15:48:10.653Z,1744732090.653 [CBIT](ERROR): Data Fault in component: NAL9602 2025-04-15T15:48:11.044Z,1744732091.044 [NAL9602](INFO): Powering down 2025-04-15T15:48:11.052Z,1744732091.052 [Default:CheckIn:Read_Iridium] Stopped 2025-04-15T15:48:11.052Z,1744732091.052 [Default:CheckIn:C.Wait] Running Loop=1 2025-04-15T15:48:11.052Z,1744732091.052 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-04-15T15:48:11.443Z,1744732091.443 [NAL9602](FAULT): LCB fault: Invalid Command. 2025-04-15T15:48:11.443Z,1744732091.443 [NAL9602] Hardware Fault, FailCount= 1 2025-04-15T15:48:11.443Z,1744732091.443 [NAL9602](ERROR): Hardware Fault 2025-04-15T15:48:11.867Z,1744732091.867 [CBIT](INFO): Clearing failed state for component NAL9602 2025-04-15T15:48:11.867Z,1744732091.867 [NAL9602] No Fault, FailCount= 1 2025-04-15T15:48:41.350Z,1744732121.350 [NAL9602](INFO): Powering up NAL9602 2025-04-15T15:48:52.246Z,1744732132.246 [NAL9602](INFO): NAL9602 initialized 2025-04-15T15:49:30.664Z,1744732170.664 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2025-04-15T15:49:30.664Z,1744732170.664 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-04-15T15:49:30.675Z,1744732170.675 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-04-15T15:49:31.046Z,1744732171.046 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-04-15T15:49:31.046Z,1744732171.046 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2025-04-15T15:52:31.633Z,1744732351.633 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2025-04-15T15:52:31.633Z,1744732351.633 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-04-15T15:52:31.644Z,1744732351.644 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-04-15T15:52:32.061Z,1744732352.061 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-04-15T15:52:32.061Z,1744732352.061 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2025-04-15T15:53:11.642Z,1744732391.642 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-04-15T15:53:11.642Z,1744732391.642 [Default:CheckIn:C.Wait] Stopped 2025-04-15T15:53:11.642Z,1744732391.642 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-04-15T15:53:11.642Z,1744732391.642 [Default:CheckIn:D] Running Loop=1 2025-04-15T15:53:12.023Z,1744732392.023 [Default:CheckIn:D] Stopped 2025-04-15T15:53:12.023Z,1744732392.023 [Default:CheckIn:E] Running Loop=1 2025-04-15T15:53:12.432Z,1744732392.432 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.029359 min 2025-04-15T15:53:12.432Z,1744732392.432 [Default:CheckIn:E] Stopped 2025-04-15T15:53:12.432Z,1744732392.432 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-04-15T15:53:12.432Z,1744732392.432 [Default:CheckIn] Stopped 2025-04-15T15:53:12.432Z,1744732392.432 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-04-15T15:53:12.432Z,1744732392.432 [Default:CheckIn](INFO): Running loop #2 2025-04-15T15:53:12.432Z,1744732392.432 [Default:CheckIn] Running Loop=2 2025-04-15T15:53:12.432Z,1744732392.432 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-15T15:53:12.433Z,1744732392.433 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-15T15:55:32.681Z,1744732532.681 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2025-04-15T15:55:32.682Z,1744732532.682 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-04-15T15:55:32.729Z,1744732532.729 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-04-15T15:55:33.054Z,1744732533.054 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-04-15T15:55:33.054Z,1744732533.054 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2025-04-15T15:58:12.610Z,1744732692.610 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-04-15T15:53:12.4Z 2025-04-15T15:58:12.610Z,1744732692.610 [Default:CheckIn:Read_GPS] Stopped 2025-04-15T15:58:12.610Z,1744732692.610 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-15T15:58:19.840Z,1744732699.840 [DataOverHttps](INFO): Sending 40 bytes from file Logs/20250415T153714/Courier0007.lzma 2025-04-15T15:58:20.842Z,1744732700.842 [DataOverHttps](INFO): Moved sent file to Logs/20250415T153714/Courier0007.lzma.bak 2025-04-15T15:58:20.843Z,1744732700.843 [DataOverHttps](INFO): SBD MOMSN=24666229 2025-04-15T15:58:33.754Z,1744732713.754 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7 2025-04-15T15:58:33.755Z,1744732713.755 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-04-15T15:58:33.850Z,1744732713.850 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-04-15T15:58:34.235Z,1744732714.235 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-04-15T15:58:34.235Z,1744732714.235 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7 2025-04-15T15:58:47.123Z,1744732727.123 [DataOverHttps](INFO): Sending 246 bytes from file Logs/20250415T153714/Express0008.lzma 2025-04-15T15:58:48.119Z,1744732728.119 [DataOverHttps](INFO): Moved sent file to Logs/20250415T153714/Express0008.lzma.bak 2025-04-15T15:58:48.119Z,1744732728.119 [DataOverHttps](INFO): SBD MOMSN=24666231 2025-04-15T15:58:49.434Z,1744732729.434 [Default:CheckIn:Read_Iridium] Stopped 2025-04-15T15:58:49.434Z,1744732729.434 [Default:CheckIn:C.Wait] Running Loop=1 2025-04-15T15:58:49.434Z,1744732729.434 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-04-15T15:58:53.858Z,1744732733.858 [NAL9602](FAULT): GPS failed to acquire within timeout. 2025-04-15T15:58:53.859Z,1744732733.859 [NAL9602] Data Fault, FailCount= 2 2025-04-15T15:58:53.859Z,1744732733.859 [NAL9602](ERROR): Data Fault 2025-04-15T15:58:53.887Z,1744732733.887 [CBIT](ERROR): Data Fault in component: NAL9602 2025-04-15T15:58:54.267Z,1744732734.267 [NAL9602](INFO): Powering down 2025-04-15T15:58:55.132Z,1744732735.132 [CBIT](INFO): Clearing failed state for component NAL9602 2025-04-15T15:58:55.132Z,1744732735.132 [NAL9602] No Fault, FailCount= 2 2025-04-15T15:59:24.572Z,1744732764.572 [NAL9602](INFO): Powering up NAL9602 2025-04-15T15:59:35.505Z,1744732775.505 [NAL9602](INFO): NAL9602 initialized 2025-04-15T16:00:21.082Z,1744732821.082 [CommandExec](IMPORTANT): got command restart system 2025-04-15T16:00:23.141Z,1744732823.141 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2025-04-15T16:00:23.141Z,1744732823.141 [CommandExec](INFO): Uninitializing the command executive. 2025-04-15T16:00:23.141Z,1744732823.141 [CommandExec](INFO): Uninitializing the command scheduler. 2025-04-15T16:00:23.141Z,1744732823.141 [CommandExec ThreadHandler](INFO): Thread cancelled. 2025-04-15T16:00:23.304Z,1744732823.304 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2025-04-15T16:00:23.305Z,1744732823.305 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2025-04-15T16:00:23.305Z,1744732823.305 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-04-15T16:00:23.306Z,1744732823.306 [NavChartDb](INFO): Join timeout helper Thread ID is 1118 2025-04-15T16:00:23.681Z,1744732823.681 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2025-04-15T16:00:23.681Z,1744732823.681 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-