2025-04-29T01:16:15.306Z,1745889375.306 [Supervisor](DEBUG): Initializing supervisor. 2025-04-29T01:16:15.310Z,1745889375.310 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2025-04-29T01:16:15.311Z,1745889375.311 [SyncHandler](INFO): Protected caller Thread ID is 839 2025-04-29T01:16:15.311Z,1745889375.311 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2025-04-29T01:16:15.312Z,1745889375.312 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2025-04-29T01:16:15.312Z,1745889375.312 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 840 2025-04-29T01:16:15.316Z,1745889375.316 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2025-04-29T01:16:15.337Z,1745889375.337 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2025-04-29T01:16:15.338Z,1745889375.338 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2025-04-29T01:16:15.338Z,1745889375.338 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 841 2025-04-29T01:16:15.342Z,1745889375.342 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2025-04-29T01:16:15.343Z,1745889375.343 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2025-04-29T01:16:15.344Z,1745889375.344 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 842 2025-04-29T01:16:15.346Z,1745889375.346 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2025-04-29T01:16:15.347Z,1745889375.347 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2025-04-29T01:16:15.347Z,1745889375.347 [logger ThreadHandler](INFO): Protected caller Thread ID is 843 2025-04-29T01:16:15.351Z,1745889375.351 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2025-04-29T01:16:15.352Z,1745889375.352 [Supervisor](INFO): Looking for Config files in directory: Config/ 2025-04-29T01:16:15.355Z,1745889375.355 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2025-04-29T01:16:15.579Z,1745889375.579 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2025-04-29T01:16:15.581Z,1745889375.581 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2025-04-29T01:16:15.707Z,1745889375.707 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2025-04-29T01:16:15.709Z,1745889375.709 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2025-04-29T01:16:15.815Z,1745889375.815 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2025-04-29T01:16:15.816Z,1745889375.816 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2025-04-29T01:16:16.322Z,1745889376.322 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2025-04-29T01:16:16.323Z,1745889376.323 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2025-04-29T01:16:16.692Z,1745889376.692 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2025-04-29T01:16:16.693Z,1745889376.693 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2025-04-29T01:16:17.338Z,1745889377.338 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2025-04-29T01:16:17.339Z,1745889377.339 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2025-04-29T01:16:17.542Z,1745889377.542 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2025-04-29T01:16:17.542Z,1745889377.542 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2025-04-29T01:16:17.632Z,1745889377.632 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2025-04-29T01:16:17.724Z,1745889377.724 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2025-04-29T01:16:18.155Z,1745889378.155 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2025-04-29T01:16:18.156Z,1745889378.156 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2025-04-29T01:16:18.464Z,1745889378.464 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2025-04-29T01:16:18.465Z,1745889378.465 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2025-04-29T01:16:19.041Z,1745889379.041 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2025-04-29T01:16:19.041Z,1745889379.041 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2025-04-29T01:16:19.299Z,1745889379.299 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2025-04-29T01:16:19.301Z,1745889379.301 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2025-04-29T01:16:19.558Z,1745889379.558 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2025-04-29T01:16:19.559Z,1745889379.559 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2025-04-29T01:16:19.712Z,1745889379.712 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2025-04-29T01:16:19.714Z,1745889379.714 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2025-04-29T01:16:20.612Z,1745889380.612 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2025-04-29T01:16:20.614Z,1745889380.614 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-galene/ 2025-04-29T01:16:20.618Z,1745889380.618 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/secure.cfg 2025-04-29T01:16:20.713Z,1745889380.713 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/vehicle.cfg 2025-04-29T01:16:20.858Z,1745889380.858 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Battery.cfg 2025-04-29T01:16:21.140Z,1745889381.140 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2025-04-29T01:16:21.142Z,1745889381.142 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Science.cfg 2025-04-29T01:16:21.277Z,1745889381.277 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Control.cfg 2025-04-29T01:16:21.386Z,1745889381.385 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/logger.cfg 2025-04-29T01:16:21.490Z,1745889381.490 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Servo.cfg 2025-04-29T01:16:21.610Z,1745889381.610 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Navigation.cfg 2025-04-29T01:16:21.715Z,1745889381.715 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Simulator.cfg 2025-04-29T01:16:22.208Z,1745889382.208 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/BIT.cfg 2025-04-29T01:16:22.679Z,1745889382.679 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Sensor.cfg 2025-04-29T01:16:22.859Z,1745889382.859 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2025-04-29T01:16:22.864Z,1745889382.864 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2025-04-29T01:16:22.938Z,1745889382.938 [DepthRateCalculator] Loaded 2025-04-29T01:16:22.938Z,1745889382.938 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2025-04-29T01:16:22.944Z,1745889382.944 [PitchRateCalculator] Loaded 2025-04-29T01:16:22.944Z,1745889382.944 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2025-04-29T01:16:22.955Z,1745889382.955 [SpeedCalculator] Loaded 2025-04-29T01:16:22.955Z,1745889382.955 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2025-04-29T01:16:22.960Z,1745889382.960 [YawRateCalculator] Loaded 2025-04-29T01:16:22.960Z,1745889382.960 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2025-04-29T01:16:22.982Z,1745889382.982 [ElevatorOffsetCalculator] Loaded 2025-04-29T01:16:22.982Z,1745889382.982 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2025-04-29T01:16:22.983Z,1745889382.983 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2025-04-29T01:16:22.985Z,1745889382.985 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2025-04-29T01:16:23.033Z,1745889383.033 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2025-04-29T01:16:23.035Z,1745889383.035 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2025-04-29T01:16:23.051Z,1745889383.051 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2025-04-29T01:16:23.052Z,1745889383.052 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2025-04-29T01:16:23.904Z,1745889383.904 [AHRS_M2] Loaded 2025-04-29T01:16:23.905Z,1745889383.905 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2025-04-29T01:16:24.158Z,1745889384.158 [BackseatComponent] Loaded 2025-04-29T01:16:24.158Z,1745889384.158 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2025-04-29T01:16:24.159Z,1745889384.159 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408754E0 2025-04-29T01:16:24.159Z,1745889384.159 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 925 2025-04-29T01:16:24.162Z,1745889384.162 [LcmUniversalReporter] Loaded 2025-04-29T01:16:24.163Z,1745889384.163 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2025-04-29T01:16:25.336Z,1745889385.336 [BPC1] Loaded 2025-04-29T01:16:25.336Z,1745889385.336 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2025-04-29T01:16:25.433Z,1745889385.433 [DAT] Loaded 2025-04-29T01:16:25.433Z,1745889385.433 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2025-04-29T01:16:25.434Z,1745889385.434 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 408A54E0 2025-04-29T01:16:25.435Z,1745889385.435 [DAT ThreadHandler](INFO): Protected caller Thread ID is 926 2025-04-29T01:16:25.579Z,1745889385.579 [DataOverHttps] Loaded 2025-04-29T01:16:25.580Z,1745889385.580 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2025-04-29T01:16:25.581Z,1745889385.581 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408D54E0 2025-04-29T01:16:25.581Z,1745889385.581 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 927 2025-04-29T01:16:25.604Z,1745889385.604 [Depth_Keller] Loaded 2025-04-29T01:16:25.604Z,1745889385.604 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2025-04-29T01:16:25.610Z,1745889385.610 [DropWeight] Loaded 2025-04-29T01:16:25.610Z,1745889385.610 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2025-04-29T01:16:25.632Z,1745889385.632 [MultiRay](INFO): Found secondary power supply at: /dev/loadC7 2025-04-29T01:16:25.632Z,1745889385.632 [MultiRay] Loaded 2025-04-29T01:16:25.632Z,1745889385.632 [ComponentRegistry](DEBUG): SyncComponent "MultiRay" handled in the control thread. 2025-04-29T01:16:25.697Z,1745889385.697 [NAL9602] Loaded 2025-04-29T01:16:25.697Z,1745889385.697 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2025-04-29T01:16:25.727Z,1745889385.727 [Onboard] Loaded 2025-04-29T01:16:25.728Z,1745889385.728 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2025-04-29T01:16:25.729Z,1745889385.729 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409054E0 2025-04-29T01:16:25.729Z,1745889385.729 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 928 2025-04-29T01:16:25.735Z,1745889385.735 [PowerOnly](INFO): Adding load control power supply at /dev/loadC3 2025-04-29T01:16:25.749Z,1745889385.749 [PowerOnly] Loaded 2025-04-29T01:16:25.749Z,1745889385.749 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread. 2025-04-29T01:16:25.763Z,1745889385.763 [Power24vConverter] Loaded 2025-04-29T01:16:25.763Z,1745889385.763 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2025-04-29T01:16:25.780Z,1745889385.780 [Radio_Surface] Loaded 2025-04-29T01:16:25.780Z,1745889385.780 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2025-04-29T01:16:25.781Z,1745889385.781 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409354E0 2025-04-29T01:16:25.782Z,1745889385.782 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 929 2025-04-29T01:16:25.807Z,1745889385.807 [Waterlinked] Loaded 2025-04-29T01:16:25.807Z,1745889385.807 [ComponentRegistry](DEBUG): SyncComponent "Waterlinked" handled in the control thread. 2025-04-29T01:16:25.808Z,1745889385.808 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2025-04-29T01:16:25.808Z,1745889385.808 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2025-04-29T01:16:25.949Z,1745889385.949 [DeadReckonUsingMultipleVelocitySources] Loaded 2025-04-29T01:16:25.950Z,1745889385.950 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2025-04-29T01:16:25.964Z,1745889385.964 [NavChart] Loaded 2025-04-29T01:16:25.964Z,1745889385.964 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2025-04-29T01:16:25.970Z,1745889385.970 [UniversalFixResidualReporter] Loaded 2025-04-29T01:16:25.970Z,1745889385.970 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2025-04-29T01:16:25.971Z,1745889385.971 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2025-04-29T01:16:25.971Z,1745889385.971 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2025-04-29T01:16:26.172Z,1745889386.172 [SBIT](DEBUG): Construct Startup Built In Test. 2025-04-29T01:16:26.186Z,1745889386.186 [SBIT] Loaded 2025-04-29T01:16:26.186Z,1745889386.186 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2025-04-29T01:16:26.189Z,1745889386.189 [IBIT](DEBUG): Construct Initiated Built In Test. 2025-04-29T01:16:26.203Z,1745889386.203 [IBIT] Loaded 2025-04-29T01:16:26.203Z,1745889386.203 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2025-04-29T01:16:26.208Z,1745889386.208 [CBIT](DEBUG): Construct Continuous Built In Test. 2025-04-29T01:16:26.290Z,1745889386.290 [CBIT] Loaded 2025-04-29T01:16:26.291Z,1745889386.291 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2025-04-29T01:16:26.322Z,1745889386.322 [GFScanner] Loaded 2025-04-29T01:16:26.323Z,1745889386.323 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread. 2025-04-29T01:16:26.323Z,1745889386.323 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2025-04-29T01:16:26.324Z,1745889386.324 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2025-04-29T01:16:26.543Z,1745889386.543 [CTD_Seabird] Loaded 2025-04-29T01:16:26.543Z,1745889386.543 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2025-04-29T01:16:26.544Z,1745889386.544 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A474E0 2025-04-29T01:16:26.545Z,1745889386.545 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 930 2025-04-29T01:16:26.567Z,1745889386.567 [PAR_Licor] Loaded 2025-04-29T01:16:26.568Z,1745889386.568 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2025-04-29T01:16:26.615Z,1745889386.615 [WetLabsBB2FL] Loaded 2025-04-29T01:16:26.615Z,1745889386.615 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2025-04-29T01:16:26.616Z,1745889386.616 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A774E0 2025-04-29T01:16:26.616Z,1745889386.616 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 931 2025-04-29T01:16:26.617Z,1745889386.617 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2025-04-29T01:16:26.618Z,1745889386.618 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2025-04-29T01:16:26.798Z,1745889386.798 [BuoyancyServo] Loaded 2025-04-29T01:16:26.798Z,1745889386.798 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2025-04-29T01:16:26.822Z,1745889386.822 [ElevatorServo] Loaded 2025-04-29T01:16:26.822Z,1745889386.822 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2025-04-29T01:16:26.846Z,1745889386.846 [MassServo] Loaded 2025-04-29T01:16:26.846Z,1745889386.846 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2025-04-29T01:16:26.869Z,1745889386.869 [RudderServo] Loaded 2025-04-29T01:16:26.869Z,1745889386.869 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2025-04-29T01:16:26.888Z,1745889386.888 [ThrusterHE] Loaded 2025-04-29T01:16:26.888Z,1745889386.888 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2025-04-29T01:16:26.888Z,1745889386.888 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2025-04-29T01:16:26.889Z,1745889386.889 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2025-04-29T01:16:27.097Z,1745889387.097 [VerticalControl](DEBUG): Construct VerticalControl. 2025-04-29T01:16:27.151Z,1745889387.151 [VerticalControl] Loaded 2025-04-29T01:16:27.151Z,1745889387.151 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2025-04-29T01:16:27.154Z,1745889387.154 [HorizontalControl](DEBUG): Construct HorizontalControl. 2025-04-29T01:16:27.202Z,1745889387.202 [HorizontalControl] Loaded 2025-04-29T01:16:27.202Z,1745889387.202 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2025-04-29T01:16:27.205Z,1745889387.205 [SpeedControl](DEBUG): Construct SpeedControl. 2025-04-29T01:16:27.207Z,1745889387.207 [SpeedControl] Loaded 2025-04-29T01:16:27.207Z,1745889387.207 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2025-04-29T01:16:27.210Z,1745889387.210 [LoopControl](DEBUG): Construct LoopControl. 2025-04-29T01:16:27.210Z,1745889387.210 [LoopControl] Loaded 2025-04-29T01:16:27.211Z,1745889387.211 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2025-04-29T01:16:27.211Z,1745889387.211 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2025-04-29T01:16:27.212Z,1745889387.212 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2025-04-29T01:16:27.381Z,1745889387.381 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2025-04-29T01:16:27.382Z,1745889387.382 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2025-04-29T01:16:27.604Z,1745889387.604 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2025-04-29T01:16:27.604Z,1745889387.604 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2025-04-29T01:16:28.031Z,1745889388.031 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2025-04-29T01:16:28.032Z,1745889388.032 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2025-04-29T01:16:28.120Z,1745889388.120 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2025-04-29T01:16:28.127Z,1745889388.127 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2025-04-29T01:16:28.130Z,1745889388.130 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2025-04-29T01:16:28.141Z,1745889388.141 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2025-04-29T01:16:28.143Z,1745889388.143 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C654E0 2025-04-29T01:16:28.143Z,1745889388.143 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 932 2025-04-29T01:16:28.147Z,1745889388.147 [Supervisor](INFO): Main Thread ID is 830 2025-04-29T01:16:28.148Z,1745889388.148 [Supervisor](DEBUG): Running supervisor. 2025-04-29T01:16:28.148Z,1745889388.148 [CommandExec ThreadHandler](INFO): Handler Thread ID is 933 2025-04-29T01:16:28.149Z,1745889388.149 [CommandExec](INFO): Initializing the command executive. 2025-04-29T01:16:28.150Z,1745889388.150 [CommandLine ThreadHandler](INFO): Handler Thread ID is 934 2025-04-29T01:16:28.152Z,1745889388.152 [controlThread ThreadHandler](INFO): Handler Thread ID is 935 2025-04-29T01:16:28.153Z,1745889388.153 [controlThread](DEBUG): Initializing ControlThread 2025-04-29T01:16:28.154Z,1745889388.154 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2025-04-29T01:16:28.154Z,1745889388.154 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2025-04-29T01:16:28.154Z,1745889388.154 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2025-04-29T01:16:28.155Z,1745889388.155 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2025-04-29T01:16:28.155Z,1745889388.155 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2025-04-29T01:16:28.159Z,1745889388.159 [NavChart](DEBUG): Initialize NavChart Navigation. 2025-04-29T01:16:28.159Z,1745889388.159 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2025-04-29T01:16:28.160Z,1745889388.160 [SBIT](INFO): Initialize SBIT Component. 2025-04-29T01:16:28.160Z,1745889388.160 [SBIT](IMPORTANT): git: 2025-04-24 2025-04-29T01:16:28.160Z,1745889388.160 [SBIT](INFO): git hash: ed8b2699e10264a13705e958152987274a27a0ee 2025-04-29T01:16:28.161Z,1745889388.161 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2025-04-29T01:16:28.162Z,1745889388.162 [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-29T01:16:28.163Z,1745889388.163 [SBIT](INFO): Beginning SBIT in 28.000000 seconds. 2025-04-29T01:16:28.164Z,1745889388.164 [IBIT](INFO): Initialize IBIT Component. 2025-04-29T01:16:28.164Z,1745889388.164 [CBIT](DEBUG): Initialize CBIT Component. 2025-04-29T01:16:28.165Z,1745889388.165 [logger ThreadHandler](INFO): Handler Thread ID is 936 2025-04-29T01:16:28.178Z,1745889388.178 [CBIT](DEBUG): Initialized mux pins. 2025-04-29T01:16:28.178Z,1745889388.178 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL. 2025-04-29T01:16:28.178Z,1745889388.178 [CBIT](DEBUG): Initializing the watchdog timer. 2025-04-29T01:16:28.186Z,1745889388.186 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 937 2025-04-29T01:16:28.202Z,1745889388.202 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2025-04-29T01:16:28.203Z,1745889388.203 [DAT ThreadHandler](INFO): Handler Thread ID is 938 2025-04-29T01:16:28.204Z,1745889388.204 [CBIT](FAULT): Found backtrace file: 1745889000.220307 [CommandExec]: SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?) 1745889000.220307 [CommandExec]: Backtrace: ./bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x1b3f74] 2025-04-29T01:16:28.206Z,1745889388.206 [DAT](INFO): Powering up 2025-04-29T01:16:28.206Z,1745889388.206 [DAT](DEBUG): Initializing DAT. 2025-04-29T01:16:28.214Z,1745889388.214 [CBIT](FAULT): Renaming backtrace file to Data/backtrace9 2025-04-29T01:16:28.215Z,1745889388.215 [CBIT](DEBUG): Initializing heartbeat. 2025-04-29T01:16:28.216Z,1745889388.216 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 940 2025-04-29T01:16:28.218Z,1745889388.218 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2025-04-29T01:16:28.234Z,1745889388.234 [Onboard ThreadHandler](INFO): Handler Thread ID is 941 2025-04-29T01:16:28.252Z,1745889388.252 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 942 2025-04-29T01:16:28.271Z,1745889388.271 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 943 2025-04-29T01:16:28.272Z,1745889388.272 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2025-04-29T01:16:28.275Z,1745889388.275 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 945 2025-04-29T01:16:28.278Z,1745889388.278 [WetLabsBB2FL](INFO): Powering up 2025-04-29T01:16:28.279Z,1745889388.279 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 947 2025-04-29T01:16:28.286Z,1745889388.286 [CBIT](DEBUG): Deactivating emergency mode. 2025-04-29T01:16:28.288Z,1745889388.288 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2025-04-29T01:16:28.288Z,1745889388.288 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2025-04-29T01:16:28.288Z,1745889388.288 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2025-04-29T01:16:28.288Z,1745889388.288 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2025-04-29T01:16:28.289Z,1745889388.289 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2025-04-29T01:16:28.289Z,1745889388.289 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2025-04-29T01:16:28.289Z,1745889388.289 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2025-04-29T01:16:28.289Z,1745889388.289 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2025-04-29T01:16:28.326Z,1745889388.326 [CBIT](DEBUG): Backplane powered. 2025-04-29T01:16:28.326Z,1745889388.326 [GFScanner](DEBUG): Initializing GFScanner 2025-04-29T01:16:28.326Z,1745889388.326 [GFScanner](DEBUG): Deactivating GF circuits. 2025-04-29T01:16:28.335Z,1745889388.335 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2025-04-29T01:16:28.337Z,1745889388.337 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2025-04-29T01:16:28.337Z,1745889388.337 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2025-04-29T01:16:28.338Z,1745889388.338 [LoopControl](DEBUG): Initialize LoopControlComponent. 2025-04-29T01:16:28.339Z,1745889388.339 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser 2025-04-29T01:16:28.340Z,1745889388.340 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl 2025-04-29T01:16:28.340Z,1745889388.340 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl 2025-04-29T01:16:28.345Z,1745889388.345 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl 2025-04-29T01:16:28.398Z,1745889388.398 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into: 2025-04-29T01:16:28.402Z,1745889388.402 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2025-04-29T01:16:28.427Z,1745889388.427 [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-29T01:16:28.427Z,1745889388.427 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl 2025-04-29T01:16:28.427Z,1745889388.427 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl 2025-04-29T01:16:28.430Z,1745889388.430 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl 2025-04-29T01:16:28.629Z,1745889388.629 [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-29T01:16:28.647Z,1745889388.647 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2025-04-29T01:16:28.648Z,1745889388.648 [Default:A.Wait](DEBUG): Construct Wait. 2025-04-29T01:16:28.658Z,1745889388.658 [Radio_Surface](INFO): Powering up 2025-04-29T01:16:28.659Z,1745889388.659 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2025-04-29T01:16:28.673Z,1745889388.673 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2025-04-29T01:16:28.676Z,1745889388.676 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2025-04-29T01:16:28.711Z,1745889388.711 [Default:E.Execute](DEBUG): Construct Execute. 2025-04-29T01:16:28.714Z,1745889388.714 [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-29T01:16:28.719Z,1745889388.719 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,MultiRay,NAL9602,PowerOnly,Power24vConverter,Waterlinked,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-29T01:16:28.736Z,1745889388.736 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2025-04-29T01:16:28.842Z,1745889388.842 [Depth_Keller](INFO): Initializing. 2025-04-29T01:16:28.843Z,1745889388.843 [MultiRay](INFO): Powering up MultiRay Lights 2025-04-29T01:16:28.843Z,1745889388.843 [MultiRay](INFO): Powering up secondary power supply. 2025-04-29T01:16:28.879Z,1745889388.879 [Power24vConverter](INFO): Powering up. 2025-04-29T01:16:28.898Z,1745889388.898 [DepthRateCalculator](ERROR): Depth measurement is not active 2025-04-29T01:16:28.917Z,1745889388.917 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2025-04-29T01:16:28.926Z,1745889388.926 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2025-04-29T01:16:28.927Z,1745889388.927 [ElevatorServo](DEBUG): Initializing EZServoServo. 2025-04-29T01:16:28.934Z,1745889388.934 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2025-04-29T01:16:28.935Z,1745889388.935 [MassServo](DEBUG): Initializing EZServoServo. 2025-04-29T01:16:28.942Z,1745889388.942 [MassServo](DEBUG): Initializing MassServo. 2025-04-29T01:16:28.943Z,1745889388.943 [RudderServo](DEBUG): Initializing EZServoServo. 2025-04-29T01:16:28.950Z,1745889388.950 [RudderServo](DEBUG): Initializing RudderServo. 2025-04-29T01:16:28.951Z,1745889388.951 [ThrusterHE](DEBUG): Initializing EZServoServo. 2025-04-29T01:16:28.958Z,1745889388.958 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2025-04-29T01:16:29.939Z,1745889389.939 [MultiRay](INFO): Powering down 2025-04-29T01:16:30.058Z,1745889390.058 [MultiRay](INFO): Powering down LCB2 2025-04-29T01:16:30.886Z,1745889390.886 [WetLabsBB2FL](INFO): Powering down 2025-04-29T01:16:40.559Z,1745889400.559 [DAT](INFO): DAT read: 2025-04-29T01:16:40.560Z,1745889400.560 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2025-04-29T01:16:41.826Z,1745889401.826 [DAT](INFO): DAT read: MF Frequency Band 2025-04-29T01:16:42.079Z,1745889402.079 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2025-04-29T01:16:42.080Z,1745889402.080 [DAT](INFO): DAT read: Apr 29 2025 01:16:38 2025-04-29T01:16:43.083Z,1745889403.083 [DAT](INFO): DAT read: Features enabled [Bearing] 2025-04-29T01:16:43.084Z,1745889403.084 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP 2025-04-29T01:16:43.084Z,1745889403.084 [DAT](INFO): commRate: 800 2025-04-29T01:16:45.150Z,1745889405.150 [DAT](INFO): entering command mode 2025-04-29T01:16:45.350Z,1745889405.350 [DAT](INFO): DAT read: 2025-04-29T01:16:45.351Z,1745889405.351 [DAT](INFO): DAT read: user:1> 2025-04-29T01:16:45.351Z,1745889405.351 [DAT](INFO): setting verbose to 3 2025-04-29T01:16:45.602Z,1745889405.602 [DAT](INFO): DAT read: user:1> 2025-04-29T01:16:45.603Z,1745889405.603 [DAT](INFO): DAT read: Verbose | 3 2025-04-29T01:16:45.604Z,1745889405.604 [DAT](INFO): set verbose to 3 2025-04-29T01:16:45.604Z,1745889405.604 [DAT](INFO): setting DatVerbose to 27440 2025-04-29T01:16:45.854Z,1745889405.854 [DAT](INFO): DAT read: user:2> 2025-04-29T01:16:45.855Z,1745889405.855 [DAT](INFO): DAT read: DatVerbose | 27440 2025-04-29T01:16:45.856Z,1745889405.856 [DAT](INFO): set DatVerbose to 27440 2025-04-29T01:16:45.856Z,1745889405.856 [DAT](INFO): setting transmit power to 8 2025-04-29T01:16:46.106Z,1745889406.106 [DAT](INFO): DAT read: user:3> 2025-04-29T01:16:46.107Z,1745889406.107 [DAT](INFO): DAT read: TxPower | 8 (Max) 2025-04-29T01:16:46.108Z,1745889406.108 [DAT](INFO): set transmit power to 8 2025-04-29T01:16:46.108Z,1745889406.108 [DAT](INFO): setting local address to 9 2025-04-29T01:16:46.358Z,1745889406.358 [DAT](INFO): DAT read: user:4> 2025-04-29T01:16:46.359Z,1745889406.359 [DAT](INFO): DAT read: LocalAddr | 9 2025-04-29T01:16:46.360Z,1745889406.360 [DAT](INFO): set local address to 9 2025-04-29T01:16:46.361Z,1745889406.361 [DAT](INFO): Setting time to: 1:16:46 And date to:4/29/2025 2025-04-29T01:16:46.611Z,1745889406.611 [DAT](INFO): DAT read: user:5> 2025-04-29T01:16:46.612Z,1745889406.612 [DAT](INFO): DAT read: Tue Apr 29, 2025 01:16:46 2025-04-29T01:16:46.612Z,1745889406.612 [DAT](INFO): Local DAT time set to Tue Apr 29, 2025 01:16:46 2025-04-29T01:16:55.868Z,1745889415.868 [NAL9602](INFO): Powering up NAL9602 2025-04-29T01:16:56.723Z,1745889416.723 [SBIT](IMPORTANT): Beginning Startup BIT 2025-04-29T01:16:56.736Z,1745889416.736 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-04-29T01:16:57.080Z,1745889417.080 [Waterlinked](FAULT): Could not initialize. 2025-04-29T01:16:57.081Z,1745889417.081 [Waterlinked] Communications Fault, FailCount= 1 2025-04-29T01:16:57.081Z,1745889417.081 [Waterlinked](ERROR): Communications Fault 2025-04-29T01:16:57.291Z,1745889417.291 [CBIT](ERROR): Communications Fault in component: Waterlinked 2025-04-29T01:16:57.570Z,1745889417.570 [Waterlinked](INFO): Powering down 2025-04-29T01:16:58.519Z,1745889418.519 [CBIT](INFO): Clearing failed state for component Waterlinked 2025-04-29T01:16:58.519Z,1745889418.519 [Waterlinked] No Fault, FailCount= 1 2025-04-29T01:17:01.195Z,1745889421.195 [GFScanner](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.070338 CHAN A1 (24V): 0.100100 CHAN A2 (12V): 0.053685 CHAN A3 (5V): 0.031974 CHAN B0 (3.3V): 0.028128 CHAN B1 (3.15aV): 0.028490 CHAN B2 (3.15bV): 0.028063 CHAN B3 (GND): 0.018163 OPEN: 0.016785 Full Scale: +/- 1 mA 2025-04-29T01:17:06.776Z,1745889426.776 [NAL9602](INFO): NAL9602 initialized 2025-04-29T01:17:10.084Z,1745889430.084 [SBIT](FAULT): Mass: EXPECTED:0.009600 ACTUAL:0.003580 2025-04-29T01:17:26.977Z,1745889446.977 [Waterlinked](FAULT): Could not initialize. 2025-04-29T01:17:26.977Z,1745889446.977 [Waterlinked] Communications Fault, FailCount= 2 2025-04-29T01:17:26.977Z,1745889446.977 [Waterlinked](ERROR): Communications Fault 2025-04-29T01:17:26.994Z,1745889446.994 [CBIT](ERROR): Communications Fault in component: Waterlinked 2025-04-29T01:17:27.470Z,1745889447.470 [Waterlinked](INFO): Powering down 2025-04-29T01:17:28.205Z,1745889448.205 [CBIT](INFO): Clearing failed state for component Waterlinked 2025-04-29T01:17:28.205Z,1745889448.205 [Waterlinked] No Fault, FailCount= 2 2025-04-29T01:17:50.480Z,1745889470.480 [SBIT](CRITICAL): SBIT FAILED 2025-04-29T01:17:50.481Z,1745889470.481 [SBIT](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2025-04-29T01:17:50.482Z,1745889470.482 [CommandExec](FAULT): Scheduling is paused 2025-04-29T01:17:50.482Z,1745889470.482 [CBIT](INFO): Critical error at 20250429T011750 2025-04-29T01:17:50.483Z,1745889470.483 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2025-04-29T01:17:50.867Z,1745889470.867 [MissionManager](IMPORTANT): Started mission Startup 2025-04-29T01:17:50.867Z,1745889470.867 [Startup] Running Loop=1 2025-04-29T01:17:50.868Z,1745889470.868 [Startup](DEBUG): Aggregate::initialize Startup 2025-04-29T01:17:50.868Z,1745889470.868 [Startup:A.GoToSurface] Running Loop=1 2025-04-29T01:17:50.868Z,1745889470.868 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-04-29T01:17:50.868Z,1745889470.868 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-04-29T01:17:50.869Z,1745889470.869 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-04-29T01:17:50.869Z,1745889470.869 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-04-29T01:17:50.870Z,1745889470.870 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-04-29T01:17:50.870Z,1745889470.870 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-04-29T01:17:50.870Z,1745889470.870 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-04-29T01:17:50.872Z,1745889470.872 [Startup:StartupSatComms] Running Loop=1 2025-04-29T01:17:50.872Z,1745889470.872 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2025-04-29T01:17:50.872Z,1745889470.872 [Startup:StartupSatComms:A] Running Loop=1 2025-04-29T01:17:51.272Z,1745889471.272 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2025-04-29T01:17:56.920Z,1745889476.920 [Waterlinked](FAULT): Could not initialize. 2025-04-29T01:17:56.920Z,1745889476.920 [Waterlinked] Communications Fault, FailCount= 3 2025-04-29T01:17:56.920Z,1745889476.920 [Waterlinked](ERROR): Communications Fault 2025-04-29T01:17:57.059Z,1745889477.059 [CBIT](ERROR): Communications Fault in component: Waterlinked 2025-04-29T01:17:57.060Z,1745889477.060 [CBIT](CRITICAL): Communications Fault in component: Waterlinked 2025-04-29T01:17:57.411Z,1745889477.411 [Waterlinked](INFO): Powering down 2025-04-29T01:17:57.435Z,1745889477.435 [CBIT](INFO): Critical error at 20250429T011757 2025-04-29T01:18:51.076Z,1745889531.076 [Startup:StartupSatComms:A](INFO): Timed out from 2025-04-29T01:17:50.9Z 2025-04-29T01:18:51.076Z,1745889531.076 [Startup:StartupSatComms:A] Stopped 2025-04-29T01:18:51.076Z,1745889531.076 [Startup:StartupSatComms:B] Running Loop=1 2025-04-29T01:18:51.472Z,1745889531.472 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-04-29T01:19:28.242Z,1745889568.242 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2025-04-29T01:19:28.242Z,1745889568.242 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-04-29T01:19:28.253Z,1745889568.253 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-04-29T01:19:28.663Z,1745889568.663 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-04-29T01:19:28.663Z,1745889568.663 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2025-04-29T01:19:51.357Z,1745889591.357 [Startup:StartupSatComms:B](INFO): Timed out from 2025-04-29T01:18:51.1Z 2025-04-29T01:19:51.357Z,1745889591.357 [Startup:StartupSatComms:B] Stopped 2025-04-29T01:19:51.357Z,1745889591.357 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2025-04-29T01:19:51.357Z,1745889591.357 [Startup:StartupSatComms] Stopped 2025-04-29T01:19:51.357Z,1745889591.357 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2025-04-29T01:19:51.362Z,1745889591.362 [Startup](INFO): Completed Startup 2025-04-29T01:19:51.362Z,1745889591.362 [MissionManager](INFO): Startup is completed. 2025-04-29T01:19:51.363Z,1745889591.363 [MissionManager](INFO): Uninitializing Mission Startup 2025-04-29T01:19:51.363Z,1745889591.363 [Startup] Stopped 2025-04-29T01:19:51.363Z,1745889591.363 [Startup](DEBUG): Aggregate::uninitialize Startup 2025-04-29T01:19:51.363Z,1745889591.363 [Startup:A.GoToSurface] Stopped 2025-04-29T01:19:51.363Z,1745889591.363 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-04-29T01:19:51.752Z,1745889591.752 [MissionManager](IMPORTANT): Started mission Default 2025-04-29T01:19:51.752Z,1745889591.752 [Default] Running Loop=1 2025-04-29T01:19:51.752Z,1745889591.752 [Default](DEBUG): Aggregate::initialize Default 2025-04-29T01:19:51.753Z,1745889591.753 [Default:B.GoToSurface] Running Loop=1 2025-04-29T01:19:51.753Z,1745889591.753 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-04-29T01:19:51.753Z,1745889591.753 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-04-29T01:19:51.753Z,1745889591.753 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-04-29T01:19:51.794Z,1745889591.794 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-04-29T01:19:51.794Z,1745889591.794 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-04-29T01:19:51.794Z,1745889591.794 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-04-29T01:19:51.795Z,1745889591.795 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-04-29T01:19:51.795Z,1745889591.795 [Default:A.Wait] Running Loop=1 2025-04-29T01:19:51.795Z,1745889591.795 [Default:A.Wait](DEBUG): Initialize Wait Component. 2025-04-29T01:19:55.318Z,1745889595.318 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005095 2025-04-29T01:20:05.079Z,1745889605.079 [Default:A.Wait](INFO): Done Waiting. 2025-04-29T01:20:05.079Z,1745889605.079 [Default:A.Wait] Stopped 2025-04-29T01:20:05.079Z,1745889605.079 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2025-04-29T01:20:05.464Z,1745889605.464 [Default:CheckIn] Running Loop=1 2025-04-29T01:20:05.464Z,1745889605.464 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-29T01:20:05.464Z,1745889605.464 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-29T01:20:05.871Z,1745889605.871 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2025-04-29T01:20:07.073Z,1745889607.073 [NAL9602](INFO): SBD MO Status=2, MOMSN=19057, MT Status=2, MTMSN=0 2025-04-29T01:20:07.073Z,1745889607.073 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-29T01:20:57.257Z,1745889657.257 [CBIT](INFO): Clearing failed state for component Waterlinked 2025-04-29T01:20:57.257Z,1745889657.257 [Waterlinked] No Fault, FailCount= 3 2025-04-29T01:21:25.865Z,1745889685.865 [Waterlinked](FAULT): Could not initialize. 2025-04-29T01:21:25.865Z,1745889685.865 [Waterlinked] Communications Fault, FailCount= 1 2025-04-29T01:21:25.865Z,1745889685.865 [Waterlinked](ERROR): Communications Fault 2025-04-29T01:21:25.937Z,1745889685.937 [CBIT](ERROR): Communications Fault in component: Waterlinked 2025-04-29T01:21:26.350Z,1745889686.350 [Waterlinked](INFO): Powering down 2025-04-29T01:21:27.138Z,1745889687.138 [CBIT](INFO): Clearing failed state for component Waterlinked 2025-04-29T01:21:27.138Z,1745889687.138 [Waterlinked] No Fault, FailCount= 1 2025-04-29T01:21:55.875Z,1745889715.875 [Waterlinked](FAULT): Could not initialize. 2025-04-29T01:21:55.875Z,1745889715.875 [Waterlinked] Communications Fault, FailCount= 2 2025-04-29T01:21:55.875Z,1745889715.875 [Waterlinked](ERROR): Communications Fault 2025-04-29T01:21:55.954Z,1745889715.954 [CBIT](ERROR): Communications Fault in component: Waterlinked 2025-04-29T01:21:56.370Z,1745889716.370 [Waterlinked](INFO): Powering down 2025-04-29T01:21:57.169Z,1745889717.169 [CBIT](INFO): Clearing failed state for component Waterlinked 2025-04-29T01:21:57.169Z,1745889717.169 [Waterlinked] No Fault, FailCount= 2 2025-04-29T01:22:10.011Z,1745889730.011 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-04-29T01:22:14.861Z,1745889734.861 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,012215.00,A,3647.65832,N,12150.10439,W,0.350,10.88,290425,,,A*42 2025-04-29T01:22:14.864Z,1745889734.864 [NAL9602](INFO): GPS fix at 20250429T012215: (36.794305, -121.835073) 2025-04-29T01:22:14.921Z,1745889734.921 [Default:CheckIn:Read_GPS] Stopped 2025-04-29T01:22:14.921Z,1745889734.921 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-29T01:22:15.362Z,1745889735.362 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-04-29T01:22:25.544Z,1745889745.544 [Waterlinked](FAULT): Could not initialize. 2025-04-29T01:22:25.544Z,1745889745.544 [Waterlinked] Communications Fault, FailCount= 3 2025-04-29T01:22:25.544Z,1745889745.544 [Waterlinked](ERROR): Communications Fault 2025-04-29T01:22:25.656Z,1745889745.656 [CBIT](ERROR): Communications Fault in component: Waterlinked 2025-04-29T01:22:25.656Z,1745889745.656 [CBIT](CRITICAL): Communications Fault in component: Waterlinked 2025-04-29T01:22:26.030Z,1745889746.030 [Waterlinked](INFO): Powering down 2025-04-29T01:22:26.092Z,1745889746.092 [CBIT](INFO): Critical error at 20250429T012225 2025-04-29T01:22:27.259Z,1745889747.259 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20250428T213549/Courier0120.lzma 2025-04-29T01:22:28.260Z,1745889748.260 [DataOverHttps](INFO): Moved sent file to Logs/20250428T213549/Courier0120.lzma.bak 2025-04-29T01:22:28.260Z,1745889748.260 [DataOverHttps](INFO): SBD MOMSN=24742316 2025-04-29T01:22:47.351Z,1745889767.351 [NAL9602](INFO): Not Powering down - fast GPS 2025-04-29T01:22:54.262Z,1745889774.262 [DataOverHttps](INFO): Sending 232 bytes from file Logs/20250429T011615/Courier0000.lzma 2025-04-29T01:22:55.264Z,1745889775.264 [DataOverHttps](INFO): Moved sent file to Logs/20250429T011615/Courier0000.lzma.bak 2025-04-29T01:22:55.264Z,1745889775.264 [DataOverHttps](IMPORTANT): SBD MOMSN=24742319, MTMSN=20250429T012255 2025-04-29T01:23:07.434Z,1745889787.434 [DataOverHttps](INFO): Received command: restart sys 2025-04-29T01:23:07.479Z,1745889787.479 [CommandExec](IMPORTANT): got command restart system 2025-04-29T01:23:09.698Z,1745889789.698 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2025-04-29T01:23:09.698Z,1745889789.698 [CommandExec](INFO): Uninitializing the command executive. 2025-04-29T01:23:09.698Z,1745889789.698 [CommandExec](INFO): Uninitializing the command scheduler. 2025-04-29T01:23:09.699Z,1745889789.699 [CommandExec ThreadHandler](INFO): Thread cancelled. 2025-04-29T01:23:09.790Z,1745889789.790 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2025-04-29T01:23:09.790Z,1745889789.790 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2025-04-29T01:23:09.790Z,1745889789.790 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-04-29T01:23:09.791Z,1745889789.791 [NavChartDb](INFO): Join timeout helper Thread ID is 1009 2025-04-29T01:23:10.158Z,1745889790.158 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2025-04-29T01:23:10.158Z,1745889790.158 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-04-29T01:23:10.174Z,1745889790.174 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2025-04-29T01:23:10.174Z,1745889790.174 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2025-04-29T01:23:10.174Z,1745889790.174 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1010 2025-04-29T01:23:10.206Z,1745889790.206 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2025-04-29T01:23:10.206Z,1745889790.206 [WetLabsBB2FL](INFO): Powering down 2025-04-29T01:23:10.207Z,1745889790.207 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2025-04-29T01:23:10.219Z,1745889790.219 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2025-04-29T01:23:10.219Z,1745889790.219 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2025-04-29T01:23:10.219Z,1745889790.219 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1011 2025-04-29T01:23:10.998Z,1745889790.998 [CTD_Seabird](INFO): Powering down 2025-04-29T01:23:11.014Z,1745889791.014 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2025-04-29T01:23:11.014Z,1745889791.014 [CTD_Seabird](INFO): Powering down 2025-04-29T01:23:11.026Z,1745889791.026 [