2023-04-14T22:50:56.843Z,1681512656.843 [Supervisor](DEBUG): Initializing supervisor. 2023-04-14T22:50:56.847Z,1681512656.847 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2023-04-14T22:50:56.848Z,1681512656.848 [SyncHandler](INFO): Protected caller Thread ID is 949 2023-04-14T22:50:56.848Z,1681512656.848 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2023-04-14T22:50:56.849Z,1681512656.849 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2023-04-14T22:50:56.850Z,1681512656.850 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 950 2023-04-14T22:50:56.854Z,1681512656.854 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2023-04-14T22:50:56.872Z,1681512656.872 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2023-04-14T22:50:56.873Z,1681512656.873 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2023-04-14T22:50:56.873Z,1681512656.873 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 951 2023-04-14T22:50:56.878Z,1681512656.878 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2023-04-14T22:50:56.879Z,1681512656.879 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2023-04-14T22:50:56.879Z,1681512656.879 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 952 2023-04-14T22:50:56.881Z,1681512656.881 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2023-04-14T22:50:56.882Z,1681512656.882 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2023-04-14T22:50:56.882Z,1681512656.882 [logger ThreadHandler](INFO): Protected caller Thread ID is 953 2023-04-14T22:50:56.886Z,1681512656.886 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2023-04-14T22:50:56.887Z,1681512656.887 [Supervisor](INFO): Looking for Config files in directory: Config/ 2023-04-14T22:50:56.888Z,1681512656.888 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2023-04-14T22:50:57.046Z,1681512657.046 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2023-04-14T22:50:57.047Z,1681512657.047 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2023-04-14T22:50:57.263Z,1681512657.263 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2023-04-14T22:50:57.263Z,1681512657.263 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2023-04-14T22:50:57.518Z,1681512657.518 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2023-04-14T22:50:57.519Z,1681512657.519 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2023-04-14T22:50:57.626Z,1681512657.626 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2023-04-14T22:50:57.627Z,1681512657.627 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2023-04-14T22:50:58.311Z,1681512658.311 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2023-04-14T22:50:58.312Z,1681512658.312 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2023-04-14T22:50:58.866Z,1681512658.866 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2023-04-14T22:50:58.867Z,1681512658.867 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2023-04-14T22:50:59.352Z,1681512659.352 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2023-04-14T22:50:59.353Z,1681512659.353 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2023-04-14T22:50:59.748Z,1681512659.748 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2023-04-14T22:50:59.749Z,1681512659.749 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2023-04-14T22:51:00.072Z,1681512660.072 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2023-04-14T22:51:00.072Z,1681512660.072 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2023-04-14T22:51:00.437Z,1681512660.437 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2023-04-14T22:51:00.438Z,1681512660.438 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2023-04-14T22:51:00.661Z,1681512660.661 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2023-04-14T22:51:00.661Z,1681512660.661 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2023-04-14T22:51:00.798Z,1681512660.798 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2023-04-14T22:51:00.799Z,1681512660.799 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2023-04-14T22:51:00.878Z,1681512660.878 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2023-04-14T22:51:00.956Z,1681512660.956 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2023-04-14T22:51:01.145Z,1681512661.145 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2023-04-14T22:51:01.146Z,1681512661.146 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2023-04-14T22:51:01.367Z,1681512661.367 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2023-04-14T22:51:01.369Z,1681512661.369 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/ 2023-04-14T22:51:01.370Z,1681512661.370 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg 2023-04-14T22:51:01.452Z,1681512661.452 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg 2023-04-14T22:51:01.754Z,1681512661.754 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2023-04-14T22:51:01.754Z,1681512661.754 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg 2023-04-14T22:51:02.058Z,1681512662.058 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg 2023-04-14T22:51:02.364Z,1681512662.364 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg 2023-04-14T22:51:02.626Z,1681512662.626 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg 2023-04-14T22:51:02.710Z,1681512662.710 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg 2023-04-14T22:51:02.818Z,1681512662.818 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg 2023-04-14T22:51:02.920Z,1681512662.920 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg 2023-04-14T22:51:03.074Z,1681512663.074 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg 2023-04-14T22:51:03.168Z,1681512663.168 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg 2023-04-14T22:51:03.265Z,1681512663.265 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/ 2023-04-14T22:51:03.266Z,1681512663.266 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2023-04-14T22:51:03.281Z,1681512663.281 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2023-04-14T22:51:03.430Z,1681512663.430 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2023-04-14T22:51:03.431Z,1681512663.431 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2023-04-14T22:51:03.569Z,1681512663.569 [BuoyancyServo] Loaded 2023-04-14T22:51:03.569Z,1681512663.569 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2023-04-14T22:51:03.590Z,1681512663.590 [ElevatorServo] Loaded 2023-04-14T22:51:03.590Z,1681512663.590 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2023-04-14T22:51:03.611Z,1681512663.611 [MassServo] Loaded 2023-04-14T22:51:03.611Z,1681512663.611 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2023-04-14T22:51:03.631Z,1681512663.631 [RudderServo] Loaded 2023-04-14T22:51:03.632Z,1681512663.632 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2023-04-14T22:51:03.647Z,1681512663.647 [ThrusterHE] Loaded 2023-04-14T22:51:03.648Z,1681512663.648 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2023-04-14T22:51:03.648Z,1681512663.648 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2023-04-14T22:51:03.649Z,1681512663.649 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2023-04-14T22:51:03.793Z,1681512663.793 [SBIT](DEBUG): Construct Startup Built In Test. 2023-04-14T22:51:03.808Z,1681512663.808 [SBIT] Loaded 2023-04-14T22:51:03.808Z,1681512663.808 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2023-04-14T22:51:03.811Z,1681512663.811 [IBIT](DEBUG): Construct Initiated Built In Test. 2023-04-14T22:51:03.831Z,1681512663.831 [IBIT] Loaded 2023-04-14T22:51:03.832Z,1681512663.832 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2023-04-14T22:51:03.837Z,1681512663.837 [CBIT](DEBUG): Construct Continuous Built In Test. 2023-04-14T22:51:04.057Z,1681512664.057 [CBIT] Loaded 2023-04-14T22:51:04.057Z,1681512664.057 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2023-04-14T22:51:04.057Z,1681512664.057 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2023-04-14T22:51:04.058Z,1681512664.058 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2023-04-14T22:51:04.228Z,1681512664.228 [CTD_Seabird] Loaded 2023-04-14T22:51:04.228Z,1681512664.228 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2023-04-14T22:51:04.229Z,1681512664.229 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406644E0 2023-04-14T22:51:04.230Z,1681512664.230 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1036 2023-04-14T22:51:04.262Z,1681512664.262 [ESPComponent] Loaded 2023-04-14T22:51:04.262Z,1681512664.262 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2023-04-14T22:51:04.282Z,1681512664.282 [PAR_Licor] Loaded 2023-04-14T22:51:04.282Z,1681512664.282 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2023-04-14T22:51:04.313Z,1681512664.313 [WetLabsBB2FL] Loaded 2023-04-14T22:51:04.314Z,1681512664.314 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2023-04-14T22:51:04.315Z,1681512664.315 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406944E0 2023-04-14T22:51:04.315Z,1681512664.315 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1037 2023-04-14T22:51:04.316Z,1681512664.316 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2023-04-14T22:51:04.316Z,1681512664.316 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2023-04-14T22:51:04.367Z,1681512664.367 [DepthRateCalculator] Loaded 2023-04-14T22:51:04.367Z,1681512664.367 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2023-04-14T22:51:04.373Z,1681512664.373 [PitchRateCalculator] Loaded 2023-04-14T22:51:04.373Z,1681512664.373 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2023-04-14T22:51:04.383Z,1681512664.383 [SpeedCalculator] Loaded 2023-04-14T22:51:04.383Z,1681512664.383 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2023-04-14T22:51:04.398Z,1681512664.398 [VerticalHomogeneityIndexCalculator] Loaded 2023-04-14T22:51:04.398Z,1681512664.398 [ComponentRegistry](DEBUG): SyncComponent "VerticalHomogeneityIndexCalculator" handled in the control thread. 2023-04-14T22:51:04.403Z,1681512664.403 [YawRateCalculator] Loaded 2023-04-14T22:51:04.403Z,1681512664.403 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2023-04-14T22:51:04.422Z,1681512664.422 [ElevatorOffsetCalculator] Loaded 2023-04-14T22:51:04.423Z,1681512664.423 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2023-04-14T22:51:04.423Z,1681512664.423 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2023-04-14T22:51:04.424Z,1681512664.424 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2023-04-14T22:51:04.528Z,1681512664.528 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2023-04-14T22:51:04.528Z,1681512664.528 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2023-04-14T22:51:04.556Z,1681512664.556 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2023-04-14T22:51:04.557Z,1681512664.557 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2023-04-14T22:51:04.670Z,1681512664.670 [DeadReckonUsingMultipleVelocitySources] Loaded 2023-04-14T22:51:04.670Z,1681512664.670 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2023-04-14T22:51:04.684Z,1681512664.684 [NavChart] Loaded 2023-04-14T22:51:04.684Z,1681512664.684 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2023-04-14T22:51:04.690Z,1681512664.690 [UniversalFixResidualReporter] Loaded 2023-04-14T22:51:04.690Z,1681512664.690 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2023-04-14T22:51:04.691Z,1681512664.691 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2023-04-14T22:51:04.691Z,1681512664.691 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2023-04-14T22:51:05.128Z,1681512665.128 [AHRS_M2] Loaded 2023-04-14T22:51:05.129Z,1681512665.129 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2023-04-14T22:51:05.163Z,1681512665.163 [BackseatComponent] Loaded 2023-04-14T22:51:05.164Z,1681512665.164 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2023-04-14T22:51:05.165Z,1681512665.165 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 40A244E0 2023-04-14T22:51:05.165Z,1681512665.165 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 1038 2023-04-14T22:51:05.168Z,1681512665.168 [LcmUniversalReporter] Loaded 2023-04-14T22:51:05.168Z,1681512665.168 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2023-04-14T22:51:05.922Z,1681512665.922 [BPC1] Loaded 2023-04-14T22:51:05.922Z,1681512665.922 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2023-04-14T22:51:05.995Z,1681512665.995 [DataOverHttps] Loaded 2023-04-14T22:51:05.995Z,1681512665.995 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2023-04-14T22:51:05.996Z,1681512665.996 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 40A544E0 2023-04-14T22:51:05.997Z,1681512665.997 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1039 2023-04-14T22:51:06.018Z,1681512666.018 [Depth_Keller] Loaded 2023-04-14T22:51:06.018Z,1681512666.018 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2023-04-14T22:51:06.023Z,1681512666.023 [DropWeight] Loaded 2023-04-14T22:51:06.023Z,1681512666.023 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2023-04-14T22:51:06.062Z,1681512666.062 [DVL_micro] Loaded 2023-04-14T22:51:06.062Z,1681512666.062 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2023-04-14T22:51:06.124Z,1681512666.124 [NAL9602] Loaded 2023-04-14T22:51:06.124Z,1681512666.124 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2023-04-14T22:51:06.158Z,1681512666.158 [Onboard] Loaded 2023-04-14T22:51:06.162Z,1681512666.162 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2023-04-14T22:51:06.163Z,1681512666.163 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40A844E0 2023-04-14T22:51:06.164Z,1681512666.164 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 1040 2023-04-14T22:51:06.176Z,1681512666.176 [Power24vConverter] Loaded 2023-04-14T22:51:06.176Z,1681512666.176 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2023-04-14T22:51:06.190Z,1681512666.190 [Radio_Surface] Loaded 2023-04-14T22:51:06.190Z,1681512666.190 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2023-04-14T22:51:06.191Z,1681512666.191 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40AB44E0 2023-04-14T22:51:06.191Z,1681512666.191 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1041 2023-04-14T22:51:06.286Z,1681512666.286 [DAT] Loaded 2023-04-14T22:51:06.286Z,1681512666.286 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2023-04-14T22:51:06.287Z,1681512666.287 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40AE44E0 2023-04-14T22:51:06.288Z,1681512666.288 [DAT ThreadHandler](INFO): Protected caller Thread ID is 1042 2023-04-14T22:51:06.288Z,1681512666.288 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2023-04-14T22:51:06.289Z,1681512666.289 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2023-04-14T22:51:06.385Z,1681512666.385 [StratificationFrontDetector](IMPORTANT): thresholdVTHI set to: 0.050012 degC 2023-04-14T22:51:06.385Z,1681512666.385 [StratificationFrontDetector](INFO): (re)initializing 2023-04-14T22:51:06.385Z,1681512666.385 [StratificationFrontDetector] Loaded 2023-04-14T22:51:06.386Z,1681512666.386 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread. 2023-04-14T22:51:06.386Z,1681512666.386 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2023-04-14T22:51:06.387Z,1681512666.387 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2023-04-14T22:51:06.455Z,1681512666.455 [VerticalControl](DEBUG): Construct VerticalControl. 2023-04-14T22:51:06.506Z,1681512666.506 [VerticalControl] Loaded 2023-04-14T22:51:06.506Z,1681512666.506 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2023-04-14T22:51:06.510Z,1681512666.510 [HorizontalControl](DEBUG): Construct HorizontalControl. 2023-04-14T22:51:06.547Z,1681512666.547 [HorizontalControl] Loaded 2023-04-14T22:51:06.548Z,1681512666.548 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2023-04-14T22:51:06.550Z,1681512666.550 [SpeedControl](DEBUG): Construct SpeedControl. 2023-04-14T22:51:06.552Z,1681512666.552 [SpeedControl] Loaded 2023-04-14T22:51:06.552Z,1681512666.552 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2023-04-14T22:51:06.555Z,1681512666.555 [LoopControl](DEBUG): Construct LoopControl. 2023-04-14T22:51:06.556Z,1681512666.556 [LoopControl] Loaded 2023-04-14T22:51:06.556Z,1681512666.556 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2023-04-14T22:51:06.556Z,1681512666.556 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2023-04-14T22:51:06.557Z,1681512666.557 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2023-04-14T22:51:06.573Z,1681512666.573 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2023-04-14T22:51:06.574Z,1681512666.574 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2023-04-14T22:51:06.934Z,1681512666.934 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2023-04-14T22:51:06.977Z,1681512666.977 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2023-04-14T22:51:07.004Z,1681512667.004 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2023-04-14T22:51:07.043Z,1681512667.043 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2023-04-14T22:51:07.046Z,1681512667.046 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BDE4E0 2023-04-14T22:51:07.047Z,1681512667.047 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1043 2023-04-14T22:51:07.068Z,1681512667.068 [Supervisor](INFO): Main Thread ID is 948 2023-04-14T22:51:07.068Z,1681512667.068 [Supervisor](DEBUG): Running supervisor. 2023-04-14T22:51:07.069Z,1681512667.069 [CommandExec ThreadHandler](INFO): Handler Thread ID is 1044 2023-04-14T22:51:07.070Z,1681512667.070 [CommandExec](INFO): Initializing the command executive. 2023-04-14T22:51:07.108Z,1681512667.108 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1045 2023-04-14T22:51:07.111Z,1681512667.111 [controlThread ThreadHandler](INFO): Handler Thread ID is 1046 2023-04-14T22:51:07.111Z,1681512667.111 [controlThread](DEBUG): Initializing ControlThread 2023-04-14T22:51:07.113Z,1681512667.113 [SBIT](INFO): Initialize SBIT Component. 2023-04-14T22:51:07.114Z,1681512667.114 [SBIT](IMPORTANT): git: 2023-04-04 2023-04-14T22:51:07.114Z,1681512667.114 [SBIT](INFO): git hash: b8e3dc7784c205eaa6d34dbcc6cfad52b0792170 2023-04-14T22:51:07.114Z,1681512667.114 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2023-04-14T22:51:07.116Z,1681512667.116 [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 2023-04-14T22:51:07.117Z,1681512667.117 [SBIT](INFO): Beginning SBIT in 79.000000 seconds. 2023-04-14T22:51:07.117Z,1681512667.117 [IBIT](INFO): Initialize IBIT Component. 2023-04-14T22:51:07.118Z,1681512667.118 [CBIT](DEBUG): Initialize CBIT Component. 2023-04-14T22:51:07.119Z,1681512667.119 [logger ThreadHandler](INFO): Handler Thread ID is 1047 2023-04-14T22:51:07.132Z,1681512667.132 [CBIT](DEBUG): Initialized mux pins. 2023-04-14T22:51:07.132Z,1681512667.132 [CBIT](DEBUG): Initializing the watchdog timer. 2023-04-14T22:51:07.140Z,1681512667.140 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1048 2023-04-14T22:51:07.141Z,1681512667.141 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2023-04-14T22:51:07.143Z,1681512667.143 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1050 2023-04-14T22:51:07.144Z,1681512667.144 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 1051 2023-04-14T22:51:07.146Z,1681512667.146 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1052 2023-04-14T22:51:07.147Z,1681512667.147 [Onboard ThreadHandler](INFO): Handler Thread ID is 1053 2023-04-14T22:51:07.150Z,1681512667.150 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2023-04-14T22:51:07.157Z,1681512667.157 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2023-04-14T22:51:07.157Z,1681512667.157 [CBIT](DEBUG): Initializing heartbeat. 2023-04-14T22:51:07.189Z,1681512667.189 [DAT ThreadHandler](INFO): Handler Thread ID is 1055 2023-04-14T22:51:07.192Z,1681512667.192 [DAT](INFO): Powering up 2023-04-14T22:51:07.192Z,1681512667.192 [DAT](DEBUG): Initializing DAT. 2023-04-14T22:51:07.194Z,1681512667.194 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1057 2023-04-14T22:51:07.204Z,1681512667.204 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1054 2023-04-14T22:51:07.212Z,1681512667.212 [WetLabsBB2FL](INFO): Powering up 2023-04-14T22:51:07.228Z,1681512667.228 [CBIT](DEBUG): Deactivating GF circuits. 2023-04-14T22:51:07.228Z,1681512667.228 [CBIT](DEBUG): Deactivating emergency mode. 2023-04-14T22:51:07.268Z,1681512667.268 [CBIT](DEBUG): Backplane powered. 2023-04-14T22:51:07.272Z,1681512667.272 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2023-04-14T22:51:07.273Z,1681512667.273 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2023-04-14T22:51:07.273Z,1681512667.273 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2023-04-14T22:51:07.273Z,1681512667.273 [VerticalHomogeneityIndexCalculator](DEBUG): (re)initializing 2023-04-14T22:51:07.274Z,1681512667.274 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2023-04-14T22:51:07.274Z,1681512667.274 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2023-04-14T22:51:07.275Z,1681512667.275 [NavChart](DEBUG): Initialize NavChart Navigation. 2023-04-14T22:51:07.276Z,1681512667.276 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2023-04-14T22:51:07.282Z,1681512667.282 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2023-04-14T22:51:07.284Z,1681512667.284 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2023-04-14T22:51:07.285Z,1681512667.285 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2023-04-14T22:51:07.285Z,1681512667.285 [LoopControl](DEBUG): Initialize LoopControlComponent. 2023-04-14T22:51:07.286Z,1681512667.286 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml 2023-04-14T22:51:07.550Z,1681512667.550 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2023-04-14T22:51:07.550Z,1681512667.550 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2023-04-14T22:51:07.550Z,1681512667.550 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2023-04-14T22:51:07.550Z,1681512667.550 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2023-04-14T22:51:07.550Z,1681512667.550 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2023-04-14T22:51:07.550Z,1681512667.550 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2023-04-14T22:51:07.551Z,1681512667.551 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2023-04-14T22:51:07.551Z,1681512667.551 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2023-04-14T22:51:07.551Z,1681512667.551 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA69M.000 2023-04-14T22:51:07.551Z,1681512667.551 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA69M.000 2023-04-14T22:51:07.579Z,1681512667.579 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2023-04-14T22:51:07.607Z,1681512667.607 [MissionManager](DEBUG): 2023-04-14T22:51:07.608Z,1681512667.608 [Radio_Surface](INFO): Powering up 2023-04-14T22:51:07.632Z,1681512667.632 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml 2023-04-14T22:51:07.715Z,1681512667.715 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2023-04-14T22:51:07.736Z,1681512667.736 [Default:A.Wait](DEBUG): Construct Wait. 2023-04-14T22:51:07.739Z,1681512667.739 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2023-04-14T22:51:07.786Z,1681512667.786 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2023-04-14T22:51:07.789Z,1681512667.789 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2023-04-14T22:51:07.810Z,1681512667.810 [Default:E.Execute](DEBUG): Construct Execute. 2023-04-14T22:51:07.814Z,1681512667.814 [MissionManager](DEBUG): 0 Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. 13 Burn on Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2023-04-14T22:51:07.832Z,1681512667.832 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,VerticalHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter, 2023-04-14T22:51:07.846Z,1681512667.846 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2023-04-14T22:51:07.921Z,1681512667.921 [Depth_Keller](ERROR): Pressure or depth reading out of range: 1895.444336 decibar, 0.000000 m 2023-04-14T22:51:07.929Z,1681512667.929 [Power24vConverter](INFO): Powering up. 2023-04-14T22:51:07.937Z,1681512667.937 [DepthRateCalculator](ERROR): Depth measurement is not active 2023-04-14T22:51:07.958Z,1681512667.958 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2023-04-14T22:51:07.964Z,1681512667.964 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2023-04-14T22:51:07.965Z,1681512667.965 [ElevatorServo](DEBUG): Initializing EZServoServo. 2023-04-14T22:51:07.984Z,1681512667.984 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2023-04-14T22:51:07.985Z,1681512667.985 [MassServo](DEBUG): Initializing EZServoServo. 2023-04-14T22:51:07.996Z,1681512667.996 [MassServo](DEBUG): Initializing MassServo. 2023-04-14T22:51:07.997Z,1681512667.997 [RudderServo](DEBUG): Initializing EZServoServo. 2023-04-14T22:51:08.005Z,1681512668.005 [RudderServo](DEBUG): Initializing RudderServo. 2023-04-14T22:51:08.005Z,1681512668.005 [ThrusterHE](DEBUG): Initializing EZServoServo. 2023-04-14T22:51:08.013Z,1681512668.013 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2023-04-14T22:51:08.291Z,1681512668.291 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2023-04-14T22:51:08.291Z,1681512668.291 [DropWeight] Hardware Fault, FailCount= 1 2023-04-14T22:51:08.291Z,1681512668.291 [DropWeight](ERROR): Hardware Fault 2023-04-14T22:51:08.319Z,1681512668.319 [CommandExec](FAULT): Scheduling is paused 2023-04-14T22:51:08.328Z,1681512668.328 [CBIT](INFO): Critical error at 20230414T225108 2023-04-14T22:51:08.328Z,1681512668.328 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2023-04-14T22:51:08.331Z,1681512668.331 [CBIT](ERROR): Hardware Fault in component: DropWeight 2023-04-14T22:51:08.331Z,1681512668.331 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2023-04-14T22:51:08.670Z,1681512668.670 [CBIT](INFO): Critical error at 20230414T225108 2023-04-14T22:51:09.312Z,1681512669.312 [WetLabsBB2FL](INFO): Powering down 2023-04-14T22:51:13.749Z,1681512673.749 [ThrusterHE](ERROR): Zero Speed Commanded. 2023-04-14T22:51:18.782Z,1681512678.782 [DAT](INFO): DAT read: 2023-04-14T22:51:18.784Z,1681512678.784 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2023-04-14T22:51:20.058Z,1681512680.058 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005036 2023-04-14T22:51:20.192Z,1681512680.192 [CTD_Seabird](FAULT): Failed to initialize within timeout. 2023-04-14T22:51:20.192Z,1681512680.192 [CTD_Seabird] Communications Fault, FailCount= 1 2023-04-14T22:51:20.192Z,1681512680.192 [CTD_Seabird](ERROR): Communications Fault 2023-04-14T22:51:20.440Z,1681512680.440 [CBIT](ERROR): Communications Fault in component: CTD_Seabird 2023-04-14T22:51:20.545Z,1681512680.545 [DAT](INFO): DAT read: MF Frequency Band 2023-04-14T22:51:20.546Z,1681512680.546 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2023-04-14T22:51:20.547Z,1681512680.547 [DAT](INFO): DAT read: Apr 14 2023 22:51:15 2023-04-14T22:51:20.597Z,1681512680.597 [CTD_Seabird](INFO): Powering down 2023-04-14T22:51:21.553Z,1681512681.553 [DAT](INFO): DAT read: Features enabled [Bearing] 2023-04-14T22:51:21.554Z,1681512681.554 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC 2023-04-14T22:51:21.554Z,1681512681.554 [DAT](INFO): commRate: 1200 2023-04-14T22:51:21.632Z,1681512681.632 [CBIT](INFO): Clearing failed state for component CTD_Seabird 2023-04-14T22:51:21.632Z,1681512681.632 [CTD_Seabird] No Fault, FailCount= 1 2023-04-14T22:51:21.940Z,1681512681.940 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2023-04-14T22:51:23.624Z,1681512683.624 [DAT](INFO): entering command mode 2023-04-14T22:51:23.820Z,1681512683.820 [DAT](INFO): DAT read: 2023-04-14T22:51:23.821Z,1681512683.821 [DAT](INFO): DAT read: user:1> 2023-04-14T22:51:23.821Z,1681512683.821 [DAT](INFO): setting verbose to 3 2023-04-14T22:51:24.073Z,1681512684.073 [DAT](INFO): DAT read: user:1> 2023-04-14T22:51:24.074Z,1681512684.074 [DAT](INFO): DAT read: Verbose | 3 2023-04-14T22:51:24.074Z,1681512684.074 [DAT](INFO): set verbose to 3 2023-04-14T22:51:24.074Z,1681512684.074 [DAT](INFO): setting DatVerbose to 27440 2023-04-14T22:51:24.325Z,1681512684.325 [DAT](INFO): DAT read: user:2> 2023-04-14T22:51:24.326Z,1681512684.326 [DAT](INFO): DAT read: DatVerbose | 27440 2023-04-14T22:51:24.326Z,1681512684.326 [DAT](INFO): set DatVerbose to 27440 2023-04-14T22:51:24.326Z,1681512684.326 [DAT](INFO): setting transmit power to 8 2023-04-14T22:51:24.576Z,1681512684.576 [DAT](INFO): DAT read: user:3> 2023-04-14T22:51:24.577Z,1681512684.577 [DAT](INFO): DAT read: TxPower | 8 (Max) 2023-04-14T22:51:24.578Z,1681512684.578 [DAT](INFO): set transmit power to 8 2023-04-14T22:51:24.578Z,1681512684.578 [DAT](INFO): setting local address to 4 2023-04-14T22:51:24.828Z,1681512684.828 [DAT](INFO): DAT read: user:4> 2023-04-14T22:51:24.829Z,1681512684.829 [DAT](INFO): DAT read: LocalAddr | 4 2023-04-14T22:51:24.830Z,1681512684.830 [DAT](INFO): set local address to 4 2023-04-14T22:51:24.831Z,1681512684.831 [DAT](INFO): Setting time to: 22:51:24 And date to:4/14/2023 2023-04-14T22:51:25.081Z,1681512685.081 [DAT](INFO): DAT read: user:5> 2023-04-14T22:51:25.081Z,1681512685.081 [DAT](INFO): DAT read: Fri Apr 14, 2023 22:51:24 2023-04-14T22:51:25.082Z,1681512685.082 [DAT](INFO): Local DAT time set to Fri Apr 14, 2023 22:51:24 2023-04-14T22:51:30.491Z,1681512690.491 [DVL_micro](ERROR): Failed to parse: :SA,-03.19,-00.43,151.8 2023-04-14T22:51:34.992Z,1681512694.992 [CTD_Seabird](FAULT): Failed to initialize within timeout. 2023-04-14T22:51:34.992Z,1681512694.992 [CTD_Seabird] Communications Fault, FailCount= 2 2023-04-14T22:51:34.992Z,1681512694.992 [CTD_Seabird](ERROR): Communications Fault 2023-04-14T22:51:35.017Z,1681512695.017 [CBIT](ERROR): Communications Fault in component: CTD_Seabird 2023-04-14T22:51:35.396Z,1681512695.396 [CTD_Seabird](INFO): Powering down 2023-04-14T22:51:36.130Z,1681512696.130 [NAL9602](INFO): Powering up NAL9602 2023-04-14T22:51:36.615Z,1681512696.615 [CBIT](INFO): Clearing failed state for component CTD_Seabird 2023-04-14T22:51:36.615Z,1681512696.615 [CTD_Seabird] No Fault, FailCount= 2 2023-04-14T22:51:36.740Z,1681512696.740 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2023-04-14T22:51:47.040Z,1681512707.040 [NAL9602](INFO): NAL9602 initialized 2023-04-14T22:51:49.792Z,1681512709.792 [CTD_Seabird](FAULT): Failed to initialize within timeout. 2023-04-14T22:51:49.793Z,1681512709.793 [CTD_Seabird] Communications Fault, FailCount= 3 2023-04-14T22:51:49.793Z,1681512709.793 [CTD_Seabird](ERROR): Communications Fault 2023-04-14T22:51:49.920Z,1681512709.920 [CBIT](ERROR): Communications Fault in component: CTD_Seabird 2023-04-14T22:51:49.920Z,1681512709.920 [CBIT](FAULT): Communications Fault in component: CTD_Seabird 2023-04-14T22:51:50.196Z,1681512710.196 [CTD_Seabird](INFO): Powering down 2023-04-14T22:52:26.647Z,1681512746.647 [SBIT](IMPORTANT): Beginning Startup BIT 2023-04-14T22:52:26.652Z,1681512746.652 [CBIT](IMPORTANT): Beginning ground fault scan 2023-04-14T22:52:38.030Z,1681512758.030 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.005186 CHAN A1 (24V): 0.002499 CHAN A2 (12V): -0.005893 CHAN A3 (5V): -0.003422 CHAN B0 (3.3V): -0.001252 CHAN B1 (3.15aV): -0.001635 CHAN B2 (3.15bV): -0.001264 CHAN B3 (GND): -0.000983 OPEN: 0.001713 Full Scale: +/- 1 mA 2023-04-14T22:53:20.400Z,1681512800.400 [SBIT](FAULT): Mass: EXPECTED:-0.014830 ACTUAL:-0.015000 2023-04-14T22:53:20.401Z,1681512800.401 [SBIT](FAULT): Control surface position failure. 2023-04-14T22:53:20.863Z,1681512800.863 [SBIT](CRITICAL): SBIT FAILED 2023-04-14T22:53:20.863Z,1681512800.863 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2023-04-14T22:53:20.865Z,1681512800.865 [SBIT](IMPORTANT): CBIT.gfScanTimeout=1 hour; 2023-04-14T22:53:20.865Z,1681512800.865 [SBIT](IMPORTANT): Depth_Keller.offset=-0.8 decibar; 2023-04-14T22:53:20.865Z,1681512800.865 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=4 minute; 2023-04-14T22:53:20.865Z,1681512800.865 [SBIT](IMPORTANT): ElevatorServo.offsetAngle=1 degree; 2023-04-14T22:53:20.868Z,1681512800.868 [SBIT](IMPORTANT): Express linearApproximation VerticalHomogeneityIndexCalculator.vertical_salinity_homogeneity_index 0.050000 practical_salinity_unit; 2023-04-14T22:53:20.868Z,1681512800.868 [SBIT](IMPORTANT): Express linearApproximation VerticalHomogeneityIndexCalculator.vertical_temperature_homogeneity_index 0.050000 celsius; 2023-04-14T22:53:20.868Z,1681512800.868 [SBIT](IMPORTANT): Express none WetLabsBB2FL.BackscatteringCoeff470nm; 2023-04-14T22:53:20.868Z,1681512800.868 [SBIT](IMPORTANT): Express none WetLabsBB2FL.BackscatteringCoeff650nm; 2023-04-14T22:53:20.868Z,1681512800.868 [SBIT](IMPORTANT): StratificationFrontDetector.loadAtStartup=1 bool; 2023-04-14T22:53:20.868Z,1681512800.868 [SBIT](IMPORTANT): StratificationFrontDetector.threshold_VTHI=0.05 celsius; 2023-04-14T22:53:20.869Z,1681512800.869 [SBIT](IMPORTANT): StratificationFrontDetector.verbosity=1 count; 2023-04-14T22:53:20.869Z,1681512800.869 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=79.764107 cubic_centimeter; 2023-04-14T22:53:20.869Z,1681512800.869 [SBIT](IMPORTANT): VerticalControl.massDefault=-14.830472 millimeter; 2023-04-14T22:53:20.869Z,1681512800.869 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.depth3=20 meter; 2023-04-14T22:53:20.869Z,1681512800.869 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.depth4=30 meter; 2023-04-14T22:53:20.869Z,1681512800.869 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.loadAtStartup=1 bool; 2023-04-14T22:53:20.873Z,1681512800.873 [CBIT](INFO): Critical error at 20230414T225320 2023-04-14T22:53:21.189Z,1681512801.189 [MissionManager](IMPORTANT): Started mission Startup 2023-04-14T22:53:21.190Z,1681512801.190 [Startup] Running Loop=1 2023-04-14T22:53:21.190Z,1681512801.190 [Startup](DEBUG): Aggregate::initialize Startup 2023-04-14T22:53:21.190Z,1681512801.190 [Startup:A.GoToSurface] Running Loop=1 2023-04-14T22:53:21.190Z,1681512801.190 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2023-04-14T22:53:21.191Z,1681512801.191 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2023-04-14T22:53:21.191Z,1681512801.191 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2023-04-14T22:53:21.191Z,1681512801.191 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2023-04-14T22:53:21.208Z,1681512801.208 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2023-04-14T22:53:21.208Z,1681512801.208 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2023-04-14T22:53:21.210Z,1681512801.210 [Startup:StartupSatComms] Running Loop=1 2023-04-14T22:53:21.210Z,1681512801.210 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2023-04-14T22:53:21.210Z,1681512801.210 [Startup:StartupSatComms:A] Running Loop=1 2023-04-14T22:53:21.658Z,1681512801.658 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2023-04-14T22:54:07.693Z,1681512847.693 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2023-04-14T22:54:07.693Z,1681512847.693 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-04-14T22:54:07.703Z,1681512847.703 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-04-14T22:54:08.078Z,1681512848.078 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-04-14T22:54:08.078Z,1681512848.078 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2023-04-14T22:54:10.660Z,1681512850.660 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-04-14T22:54:20.186Z,1681512860.186 [CBIT](INFO): Clearing failed state for component CTD_Seabird 2023-04-14T22:54:20.187Z,1681512860.187 [CTD_Seabird] No Fault, FailCount= 3 2023-04-14T22:54:20.264Z,1681512860.264 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2023-04-14T22:54:21.381Z,1681512861.381 [Startup:StartupSatComms:A](INFO): Timed out from 2023-04-14T22:53:21.2Z 2023-04-14T22:54:21.381Z,1681512861.381 [Startup:StartupSatComms:A] Stopped 2023-04-14T22:54:21.382Z,1681512861.382 [Startup:StartupSatComms:B] Running Loop=1 2023-04-14T22:54:21.781Z,1681512861.781 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2023-04-14T22:54:41.788Z,1681512881.788 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-04-14T22:55:12.912Z,1681512912.912 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-04-14T22:55:21.589Z,1681512921.589 [Startup:StartupSatComms:B](INFO): Timed out from 2023-04-14T22:54:21.4Z 2023-04-14T22:55:21.589Z,1681512921.589 [Startup:StartupSatComms:B] Stopped 2023-04-14T22:55:21.590Z,1681512921.590 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2023-04-14T22:55:21.590Z,1681512921.590 [Startup:StartupSatComms] Stopped 2023-04-14T22:55:21.590Z,1681512921.590 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2023-04-14T22:55:21.590Z,1681512921.590 [Startup](INFO): Completed Startup 2023-04-14T22:55:21.591Z,1681512921.591 [MissionManager](INFO): Startup is completed. 2023-04-14T22:55:21.591Z,1681512921.591 [MissionManager](INFO): Uninitializing Mission Startup 2023-04-14T22:55:21.591Z,1681512921.591 [Startup] Stopped 2023-04-14T22:55:21.591Z,1681512921.591 [Startup](DEBUG): Aggregate::uninitialize Startup 2023-04-14T22:55:21.591Z,1681512921.591 [Startup:A.GoToSurface] Stopped 2023-04-14T22:55:21.591Z,1681512921.591 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2023-04-14T22:55:22.002Z,1681512922.002 [MissionManager](IMPORTANT): Started mission Default 2023-04-14T22:55:22.002Z,1681512922.002 [Default] Running Loop=1 2023-04-14T22:55:22.002Z,1681512922.002 [Default](DEBUG): Aggregate::initialize Default 2023-04-14T22:55:22.002Z,1681512922.002 [Default:B.GoToSurface] Running Loop=1 2023-04-14T22:55:22.002Z,1681512922.002 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2023-04-14T22:55:22.002Z,1681512922.002 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2023-04-14T22:55:22.003Z,1681512922.003 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2023-04-14T22:55:22.003Z,1681512922.003 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2023-04-14T22:55:22.003Z,1681512922.003 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2023-04-14T22:55:22.004Z,1681512922.004 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2023-04-14T22:55:22.004Z,1681512922.004 [Default:A.Wait] Running Loop=1 2023-04-14T22:55:22.004Z,1681512922.004 [Default:A.Wait](DEBUG): Initialize Wait Component. 2023-04-14T22:55:35.346Z,1681512935.346 [Default:A.Wait](INFO): Done Waiting. 2023-04-14T22:55:35.347Z,1681512935.347 [Default:A.Wait] Stopped 2023-04-14T22:55:35.347Z,1681512935.347 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2023-04-14T22:55:35.806Z,1681512935.806 [Default:CheckIn] Running Loop=1 2023-04-14T22:55:35.806Z,1681512935.806 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-04-14T22:55:35.806Z,1681512935.806 [Default:CheckIn:Read_GPS] Running Loop=1 2023-04-14T22:55:36.161Z,1681512936.161 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2023-04-14T22:55:44.048Z,1681512944.048 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-04-14T22:56:15.172Z,1681512975.172 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-04-14T22:56:18.184Z,1681512978.184 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.783417 2023-04-14T22:56:50.065Z,1681513010.065 [DVL_micro](ERROR): Failed to parse: :R99,+9999.99,+9999.99,+9999.99 2023-04-14T22:56:50.858Z,1681513010.858 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-04-14T22:56:53.621Z,1681513013.621 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003787 2023-04-14T22:57:08.653Z,1681513028.653 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2023-04-14T22:57:08.653Z,1681513028.653 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-04-14T22:57:08.664Z,1681513028.664 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-04-14T22:57:09.055Z,1681513029.055 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-04-14T22:57:09.055Z,1681513029.055 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2023-04-14T22:58:46.395Z,1681513126.395 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2023-04-14T22:58:46.399Z,1681513126.399 [BPC1](INFO): Received data from all battery sticks. 2023-04-14T22:59:57.902Z,1681513197.902 [DVL_micro](ERROR): only read 0 of 4 data items 2023-04-14T22:59:57.902Z,1681513197.902 [DVL_micro](ERROR): Failed to parse: :BI+00069,-00380,+00000,I 2023-04-14T23:00:09.649Z,1681513209.649 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2023-04-14T23:00:09.649Z,1681513209.649 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-04-14T23:00:09.659Z,1681513209.659 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-04-14T23:00:10.038Z,1681513210.038 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-04-14T23:00:10.038Z,1681513210.038 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2023-04-14T23:00:35.914Z,1681513235.914 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-04-14T22:55:35.8Z 2023-04-14T23:00:35.914Z,1681513235.914 [Default:CheckIn:Read_GPS] Stopped 2023-04-14T23:00:35.914Z,1681513235.914 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-04-14T23:00:36.303Z,1681513236.303 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2023-04-14T23:00:42.851Z,1681513242.851 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230412T164332/Courier0034.lzma 2023-04-14T23:00:43.854Z,1681513243.854 [DataOverHttps](INFO): Moved sent file to Logs/20230412T164332/Courier0034.lzma.bak 2023-04-14T23:00:43.854Z,1681513243.854 [DataOverHttps](INFO): SBD MOMSN=18222754 2023-04-14T23:00:59.536Z,1681513259.536 [DataOverHttps](INFO): Sending 261 bytes from file Logs/20230414T225056/Courier0000.lzma 2023-04-14T23:01:00.538Z,1681513260.538 [DataOverHttps](INFO): Moved sent file to Logs/20230414T225056/Courier0000.lzma.bak 2023-04-14T23:01:00.538Z,1681513260.538 [DataOverHttps](INFO): SBD MOMSN=18222759 2023-04-14T23:01:16.195Z,1681513276.195 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20230414T225056/Courier0004.lzma 2023-04-14T23:01:17.198Z,1681513277.198 [DataOverHttps](INFO): Moved sent file to Logs/20230414T225056/Courier0004.lzma.bak 2023-04-14T23:01:17.198Z,1681513277.198 [DataOverHttps](INFO): SBD MOMSN=18222765 2023-04-14T23:01:35.348Z,1681513295.348 [DataOverHttps](INFO): Sending 409 bytes from file Logs/20230412T164332/Express0035.lzma 2023-04-14T23:01:36.350Z,1681513296.350 [DataOverHttps](INFO): Moved sent file to Logs/20230412T164332/Express0035.lzma.bak 2023-04-14T23:01:36.350Z,1681513296.350 [DataOverHttps](INFO): SBD MOMSN=18222767 2023-04-14T23:01:48.218Z,1681513308.218 [NAL9602](FAULT): GPS failed to acquire within timeout. 2023-04-14T23:01:48.218Z,1681513308.218 [NAL9602] Data Fault, FailCount= 1 2023-04-14T23:01:48.218Z,1681513308.218 [NAL9602](ERROR): Data Fault 2023-04-14T23:01:48.235Z,1681513308.235 [CBIT](ERROR): Data Fault in component: NAL9602 2023-04-14T23:01:48.630Z,1681513308.630 [NAL9602](INFO): Powering down 2023-04-14T23:01:49.485Z,1681513309.485 [CBIT](INFO): Clearing failed state for component NAL9602 2023-04-14T23:01:49.486Z,1681513309.486 [NAL9602] No Fault, FailCount= 1 2023-04-14T23:01:56.466Z,1681513316.466 [DataOverHttps](INFO): Sending 1188 bytes from file Logs/20230414T225056/Express0001.lzma 2023-04-14T23:01:57.466Z,1681513317.466 [DataOverHttps](INFO): Moved sent file to Logs/20230414T225056/Express0001.lzma.bak 2023-04-14T23:01:57.466Z,1681513317.466 [DataOverHttps](INFO): SBD MOMSN=18222791 2023-04-14T23:02:13.159Z,1681513333.159 [DataOverHttps](INFO): Sending 187 bytes from file Logs/20230414T225056/Express0005.lzma 2023-04-14T23:02:14.162Z,1681513334.162 [DataOverHttps](INFO): Moved sent file to Logs/20230414T225056/Express0005.lzma.bak 2023-04-14T23:02:14.162Z,1681513334.162 [DataOverHttps](INFO): SBD MOMSN=18222825 2023-04-14T23:02:15.700Z,1681513335.700 [Default:CheckIn:Read_Iridium] Stopped 2023-04-14T23:02:15.700Z,1681513335.700 [Default:CheckIn:C.Wait] Running Loop=1 2023-04-14T23:02:15.700Z,1681513335.700 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-04-14T23:02:18.929Z,1681513338.929 [NAL9602](INFO): Powering up NAL9602 2023-04-14T23:02:29.840Z,1681513349.840 [NAL9602](INFO): NAL9602 initialized 2023-04-14T23:03:10.641Z,1681513390.641 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2023-04-14T23:03:10.641Z,1681513390.641 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-04-14T23:03:10.651Z,1681513390.651 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-04-14T23:03:11.050Z,1681513391.050 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-04-14T23:03:11.051Z,1681513391.051 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2023-04-14T23:05:09.414Z,1681513509.414 [DVL_micro](ERROR): only read 3 of 4 data items 2023-04-14T23:05:09.414Z,1681513509.414 [DVL_micro](ERROR): Failed to parse: :BI,+00000,+00014,-0000,I 2023-04-14T23:06:08.449Z,1681513568.449 [CBIT](INFO): Clearing failed state for component DropWeight 2023-04-14T23:06:08.449Z,1681513568.449 [DropWeight] No Fault, FailCount= 1 2023-04-14T23:06:11.633Z,1681513571.633 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2023-04-14T23:06:11.633Z,1681513571.633 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-04-14T23:06:11.650Z,1681513571.650 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-04-14T23:06:12.051Z,1681513572.051 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-04-14T23:06:12.051Z,1681513572.051 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2023-04-14T23:06:35.869Z,1681513595.869 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2023-04-14T23:06:35.869Z,1681513595.869 [DVL_micro](ERROR): Failed to parse: :TS,000000,35.0,+21.,1489.0,000 2023-04-14T23:07:16.318Z,1681513636.318 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-04-14T23:07:16.318Z,1681513636.318 [Default:CheckIn:C.Wait] Stopped 2023-04-14T23:07:16.318Z,1681513636.318 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-04-14T23:07:16.318Z,1681513636.318 [Default:CheckIn:D] Running Loop=1 2023-04-14T23:07:16.702Z,1681513636.702 [Default:CheckIn:D] Stopped 2023-04-14T23:07:16.702Z,1681513636.702 [Default:CheckIn:E] Running Loop=1 2023-04-14T23:07:17.090Z,1681513637.090 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.911667 min 2023-04-14T23:07:17.090Z,1681513637.090 [Default:CheckIn:E] Stopped 2023-04-14T23:07:17.090Z,1681513637.090 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-04-14T23:07:17.090Z,1681513637.090 [Default:CheckIn] Stopped 2023-04-14T23:07:17.090Z,1681513637.090 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-04-14T23:07:17.091Z,1681513637.091 [Default:CheckIn](INFO): Running loop #2 2023-04-14T23:07:17.091Z,1681513637.091 [Default:CheckIn] Running Loop=2 2023-04-14T23:07:17.091Z,1681513637.091 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-04-14T23:07:17.091Z,1681513637.091 [Default:CheckIn:Read_GPS] Running Loop=1 2023-04-14T23:07:44.586Z,1681513664.586 [CommandExec](IMPORTANT): got command get ThrusterHE.loadAtStartup 2023-04-14T23:07:44.587Z,1681513664.587 [CommandExec](IMPORTANT): ThrusterHE.loadAtStartup 1 bool 2023-04-14T23:08:25.653Z,1681513705.653 [CommandExec](IMPORTANT): got command burn on 2023-04-14T23:08:25.653Z,1681513705.653 [CommandExec](IMPORTANT): Activating dropweight wire 2023-04-14T23:08:26.561Z,1681513706.561 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2023-04-14T23:08:26.561Z,1681513706.561 [DropWeight] Hardware Fault, FailCount= 1 2023-04-14T23:08:26.561Z,1681513706.561 [DropWeight](ERROR): Hardware Fault 2023-04-14T23:08:26.621Z,1681513706.621 [CBIT](INFO): Critical error at 20230414T230826 2023-04-14T23:08:26.623Z,1681513706.623 [CBIT](ERROR): Hardware Fault in component: DropWeight 2023-04-14T23:08: