2025-06-05T20:58:24.173Z,1749157104.173 [Supervisor](DEBUG): Initializing supervisor.
2025-06-05T20:58:24.178Z,1749157104.178 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2025-06-05T20:58:24.178Z,1749157104.178 [SyncHandler](INFO): Protected caller Thread ID is 839
2025-06-05T20:58:24.179Z,1749157104.179 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2025-06-05T20:58:24.180Z,1749157104.180 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2025-06-05T20:58:24.180Z,1749157104.180 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 840
2025-06-05T20:58:24.184Z,1749157104.184 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2025-06-05T20:58:24.204Z,1749157104.204 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2025-06-05T20:58:24.205Z,1749157104.205 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2025-06-05T20:58:24.206Z,1749157104.206 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 841
2025-06-05T20:58:24.210Z,1749157104.210 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2025-06-05T20:58:24.211Z,1749157104.211 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2025-06-05T20:58:24.211Z,1749157104.211 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 842
2025-06-05T20:58:24.214Z,1749157104.214 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2025-06-05T20:58:24.215Z,1749157104.215 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2025-06-05T20:58:24.215Z,1749157104.215 [logger ThreadHandler](INFO): Protected caller Thread ID is 843
2025-06-05T20:58:24.219Z,1749157104.219 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2025-06-05T20:58:24.219Z,1749157104.219 [Supervisor](INFO): Looking for Config files in directory: Config/
2025-06-05T20:58:24.223Z,1749157104.223 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2025-06-05T20:58:24.330Z,1749157104.330 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2025-06-05T20:58:24.331Z,1749157104.331 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2025-06-05T20:58:25.088Z,1749157105.088 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2025-06-05T20:58:25.090Z,1749157105.090 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2025-06-05T20:58:25.336Z,1749157105.336 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2025-06-05T20:58:25.338Z,1749157105.338 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2025-06-05T20:58:25.427Z,1749157105.427 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2025-06-05T20:58:25.570Z,1749157105.570 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2025-06-05T20:58:25.570Z,1749157105.570 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2025-06-05T20:58:25.672Z,1749157105.672 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Guidance
2025-06-05T20:58:25.674Z,1749157105.674 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2025-06-05T20:58:25.793Z,1749157105.793 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2025-06-05T20:58:25.793Z,1749157105.793 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2025-06-05T20:58:26.227Z,1749157106.227 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2025-06-05T20:58:26.229Z,1749157106.229 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2025-06-05T20:58:26.778Z,1749157106.778 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2025-06-05T20:58:26.780Z,1749157106.780 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2025-06-05T20:58:27.009Z,1749157107.009 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2025-06-05T20:58:27.010Z,1749157107.010 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2025-06-05T20:58:27.206Z,1749157107.206 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2025-06-05T20:58:27.207Z,1749157107.207 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2025-06-05T20:58:28.238Z,1749157108.238 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2025-06-05T20:58:28.239Z,1749157108.239 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2025-06-05T20:58:28.572Z,1749157108.572 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2025-06-05T20:58:28.574Z,1749157108.574 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2025-06-05T20:58:28.823Z,1749157108.823 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2025-06-05T20:58:28.825Z,1749157108.825 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2025-06-05T20:58:29.220Z,1749157109.220 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2025-06-05T20:58:29.221Z,1749157109.221 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2025-06-05T20:58:29.583Z,1749157109.583 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2025-06-05T20:58:29.585Z,1749157109.585 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/
2025-06-05T20:58:29.587Z,1749157109.587 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg
2025-06-05T20:58:29.681Z,1749157109.681 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg
2025-06-05T20:58:29.858Z,1749157109.858 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Dock.cfg
2025-06-05T20:58:29.974Z,1749157109.974 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/workSite.cfg
2025-06-05T20:58:30.079Z,1749157110.079 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg
2025-06-05T20:58:30.197Z,1749157110.197 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg
2025-06-05T20:58:30.293Z,1749157110.293 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg
2025-06-05T20:58:30.399Z,1749157110.399 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg
2025-06-05T20:58:30.523Z,1749157110.523 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg
2025-06-05T20:58:30.805Z,1749157110.805 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2025-06-05T20:58:30.805Z,1749157110.805 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg
2025-06-05T20:58:30.899Z,1749157110.899 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg
2025-06-05T20:58:31.002Z,1749157111.002 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg
2025-06-05T20:58:31.152Z,1749157111.152 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg
2025-06-05T20:58:31.258Z,1749157111.258 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2025-06-05T20:58:31.263Z,1749157111.263 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2025-06-05T20:58:31.450Z,1749157111.450 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2025-06-05T20:58:31.451Z,1749157111.451 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2025-06-05T20:58:31.527Z,1749157111.527 [VerticalControl](DEBUG): Construct VerticalControl.
2025-06-05T20:58:31.591Z,1749157111.591 [VerticalControl] Loaded
2025-06-05T20:58:31.592Z,1749157111.592 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2025-06-05T20:58:31.594Z,1749157111.594 [HorizontalControl](DEBUG): Construct HorizontalControl.
2025-06-05T20:58:31.643Z,1749157111.643 [HorizontalControl] Loaded
2025-06-05T20:58:31.644Z,1749157111.644 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2025-06-05T20:58:31.646Z,1749157111.646 [SpeedControl](DEBUG): Construct SpeedControl.
2025-06-05T20:58:31.649Z,1749157111.649 [SpeedControl] Loaded
2025-06-05T20:58:31.650Z,1749157111.650 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2025-06-05T20:58:31.652Z,1749157111.652 [LoopControl](DEBUG): Construct LoopControl.
2025-06-05T20:58:31.653Z,1749157111.653 [LoopControl] Loaded
2025-06-05T20:58:31.653Z,1749157111.653 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2025-06-05T20:58:31.654Z,1749157111.654 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2025-06-05T20:58:31.654Z,1749157111.654 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2025-06-05T20:58:31.729Z,1749157111.729 [DepthRateCalculator] Loaded
2025-06-05T20:58:31.729Z,1749157111.729 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2025-06-05T20:58:31.734Z,1749157111.734 [PitchRateCalculator] Loaded
2025-06-05T20:58:31.735Z,1749157111.735 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2025-06-05T20:58:31.745Z,1749157111.745 [SpeedCalculator] Loaded
2025-06-05T20:58:31.745Z,1749157111.745 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2025-06-05T20:58:31.750Z,1749157111.750 [YawRateCalculator] Loaded
2025-06-05T20:58:31.750Z,1749157111.750 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2025-06-05T20:58:31.769Z,1749157111.769 [ElevatorOffsetCalculator] Loaded
2025-06-05T20:58:31.769Z,1749157111.769 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2025-06-05T20:58:31.770Z,1749157111.770 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2025-06-05T20:58:31.772Z,1749157111.772 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2025-06-05T20:58:31.821Z,1749157111.821 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2025-06-05T20:58:31.822Z,1749157111.822 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2025-06-05T20:58:31.915Z,1749157111.915 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2025-06-05T20:58:31.916Z,1749157111.916 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2025-06-05T20:58:32.354Z,1749157112.354 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2025-06-05T20:58:32.355Z,1749157112.355 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2025-06-05T20:58:32.589Z,1749157112.589 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2025-06-05T20:58:32.590Z,1749157112.590 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2025-06-05T20:58:33.466Z,1749157113.466 [AHRS_M2] Loaded
2025-06-05T20:58:33.467Z,1749157113.467 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2025-06-05T20:58:33.885Z,1749157113.885 [BackseatComponent] Loaded
2025-06-05T20:58:33.885Z,1749157113.885 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2025-06-05T20:58:33.886Z,1749157113.886 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 409E84E0
2025-06-05T20:58:33.886Z,1749157113.886 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 931
2025-06-05T20:58:33.889Z,1749157113.889 [LcmUniversalReporter] Loaded
2025-06-05T20:58:33.890Z,1749157113.890 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2025-06-05T20:58:34.932Z,1749157114.932 [BPC1] Loaded
2025-06-05T20:58:34.933Z,1749157114.933 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2025-06-05T20:58:35.048Z,1749157115.048 [DAT] Loaded
2025-06-05T20:58:35.048Z,1749157115.048 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2025-06-05T20:58:35.049Z,1749157115.049 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40A184E0
2025-06-05T20:58:35.050Z,1749157115.050 [DAT ThreadHandler](INFO): Protected caller Thread ID is 932
2025-06-05T20:58:35.198Z,1749157115.198 [DataOverHttps] Loaded
2025-06-05T20:58:35.198Z,1749157115.198 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2025-06-05T20:58:35.199Z,1749157115.199 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 40A484E0
2025-06-05T20:58:35.200Z,1749157115.200 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 933
2025-06-05T20:58:35.223Z,1749157115.223 [Depth_Keller] Loaded
2025-06-05T20:58:35.224Z,1749157115.224 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2025-06-05T20:58:35.229Z,1749157115.229 [DropWeight] Loaded
2025-06-05T20:58:35.229Z,1749157115.229 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2025-06-05T20:58:35.297Z,1749157115.297 [NAL9602] Loaded
2025-06-05T20:58:35.297Z,1749157115.297 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2025-06-05T20:58:35.328Z,1749157115.328 [Onboard] Loaded
2025-06-05T20:58:35.329Z,1749157115.329 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2025-06-05T20:58:35.330Z,1749157115.330 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40A784E0
2025-06-05T20:58:35.330Z,1749157115.330 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 934
2025-06-05T20:58:35.345Z,1749157115.345 [Power24vConverter] Loaded
2025-06-05T20:58:35.345Z,1749157115.345 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2025-06-05T20:58:35.362Z,1749157115.362 [Radio_Surface] Loaded
2025-06-05T20:58:35.362Z,1749157115.362 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2025-06-05T20:58:35.363Z,1749157115.363 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40AA84E0
2025-06-05T20:58:35.363Z,1749157115.363 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 935
2025-06-05T20:58:35.413Z,1749157115.413 [RDI_Pathfinder] Loaded
2025-06-05T20:58:35.413Z,1749157115.413 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2025-06-05T20:58:35.429Z,1749157115.429 [Sonardyne_Nano] Loaded
2025-06-05T20:58:35.430Z,1749157115.430 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread.
2025-06-05T20:58:35.430Z,1749157115.430 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2025-06-05T20:58:35.431Z,1749157115.431 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2025-06-05T20:58:35.577Z,1749157115.577 [DeadReckonUsingMultipleVelocitySources] Loaded
2025-06-05T20:58:35.577Z,1749157115.577 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2025-06-05T20:58:35.591Z,1749157115.591 [NavChart] Loaded
2025-06-05T20:58:35.592Z,1749157115.592 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2025-06-05T20:58:35.597Z,1749157115.597 [UniversalFixResidualReporter] Loaded
2025-06-05T20:58:35.598Z,1749157115.598 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2025-06-05T20:58:35.598Z,1749157115.598 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2025-06-05T20:58:35.600Z,1749157115.600 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2025-06-05T20:58:35.813Z,1749157115.813 [SBIT](DEBUG): Construct Startup Built In Test.
2025-06-05T20:58:35.823Z,1749157115.823 [SBIT] Loaded
2025-06-05T20:58:35.823Z,1749157115.823 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2025-06-05T20:58:35.826Z,1749157115.826 [IBIT](DEBUG): Construct Initiated Built In Test.
2025-06-05T20:58:35.840Z,1749157115.840 [IBIT] Loaded
2025-06-05T20:58:35.840Z,1749157115.840 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2025-06-05T20:58:35.846Z,1749157115.846 [CBIT](DEBUG): Construct Continuous Built In Test.
2025-06-05T20:58:35.931Z,1749157115.931 [CBIT] Loaded
2025-06-05T20:58:35.931Z,1749157115.931 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2025-06-05T20:58:35.965Z,1749157115.965 [GFScanner] Loaded
2025-06-05T20:58:35.965Z,1749157115.965 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread.
2025-06-05T20:58:35.965Z,1749157115.965 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2025-06-05T20:58:35.966Z,1749157115.966 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2025-06-05T20:58:36.218Z,1749157116.218 [BuoyancyServo] Loaded
2025-06-05T20:58:36.218Z,1749157116.218 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2025-06-05T20:58:36.395Z,1749157116.395 [ElevatorServo] Loaded
2025-06-05T20:58:36.395Z,1749157116.395 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2025-06-05T20:58:36.453Z,1749157116.453 [DockingStepper] Loaded
2025-06-05T20:58:36.453Z,1749157116.453 [ComponentRegistry](DEBUG): SyncComponent "DockingStepper" handled in the control thread.
2025-06-05T20:58:36.476Z,1749157116.476 [MassServo] Loaded
2025-06-05T20:58:36.476Z,1749157116.476 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2025-06-05T20:58:36.499Z,1749157116.499 [RudderServo] Loaded
2025-06-05T20:58:36.499Z,1749157116.499 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2025-06-05T20:58:36.519Z,1749157116.519 [ThrusterServo] Loaded
2025-06-05T20:58:36.519Z,1749157116.519 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2025-06-05T20:58:36.520Z,1749157116.520 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2025-06-05T20:58:36.520Z,1749157116.520 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2025-06-05T20:58:36.536Z,1749157116.536 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2025-06-05T20:58:36.537Z,1749157116.537 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2025-06-05T20:58:36.770Z,1749157116.770 [CTD_Seabird] Loaded
2025-06-05T20:58:36.770Z,1749157116.770 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2025-06-05T20:58:36.771Z,1749157116.771 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40C0A4E0
2025-06-05T20:58:36.772Z,1749157116.772 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 936
2025-06-05T20:58:36.795Z,1749157116.795 [PAR_Licor] Loaded
2025-06-05T20:58:36.795Z,1749157116.795 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2025-06-05T20:58:36.843Z,1749157116.843 [WetLabsBB2FL] Loaded
2025-06-05T20:58:36.844Z,1749157116.844 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2025-06-05T20:58:36.845Z,1749157116.845 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40C3A4E0
2025-06-05T20:58:36.845Z,1749157116.845 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 937
2025-06-05T20:58:36.867Z,1749157116.867 [WetLabsUBAT] Loaded
2025-06-05T20:58:36.867Z,1749157116.867 [ComponentRegistry](DEBUG): Component "WetLabsUBAT" handled in its own thread.
2025-06-05T20:58:36.869Z,1749157116.869 [WetLabsUBAT ThreadHandler](DEBUG): Created PCaller Thread at 40C6A4E0
2025-06-05T20:58:36.869Z,1749157116.869 [WetLabsUBAT ThreadHandler](INFO): Protected caller Thread ID is 938
2025-06-05T20:58:36.869Z,1749157116.869 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2025-06-05T20:58:36.876Z,1749157116.876 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2025-06-05T20:58:36.879Z,1749157116.879 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2025-06-05T20:58:36.890Z,1749157116.890 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2025-06-05T20:58:36.891Z,1749157116.891 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C9A4E0
2025-06-05T20:58:36.892Z,1749157116.892 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 939
2025-06-05T20:58:36.896Z,1749157116.896 [Supervisor](INFO): Main Thread ID is 830
2025-06-05T20:58:36.896Z,1749157116.896 [Supervisor](DEBUG): Running supervisor.
2025-06-05T20:58:36.897Z,1749157116.897 [CommandExec ThreadHandler](INFO): Handler Thread ID is 940
2025-06-05T20:58:36.897Z,1749157116.897 [CommandExec](INFO): Initializing the command executive.
2025-06-05T20:58:36.899Z,1749157116.899 [CommandLine ThreadHandler](INFO): Handler Thread ID is 941
2025-06-05T20:58:36.901Z,1749157116.901 [controlThread ThreadHandler](INFO): Handler Thread ID is 942
2025-06-05T20:58:36.902Z,1749157116.902 [controlThread](DEBUG): Initializing ControlThread
2025-06-05T20:58:36.903Z,1749157116.903 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2025-06-05T20:58:36.904Z,1749157116.904 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2025-06-05T20:58:36.905Z,1749157116.905 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2025-06-05T20:58:36.905Z,1749157116.905 [LoopControl](DEBUG): Initialize LoopControlComponent.
2025-06-05T20:58:36.906Z,1749157116.906 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2025-06-05T20:58:36.906Z,1749157116.906 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2025-06-05T20:58:36.907Z,1749157116.907 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2025-06-05T20:58:36.907Z,1749157116.907 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2025-06-05T20:58:36.907Z,1749157116.907 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2025-06-05T20:58:36.911Z,1749157116.911 [NavChart](DEBUG): Initialize NavChart Navigation.
2025-06-05T20:58:36.912Z,1749157116.912 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2025-06-05T20:58:36.912Z,1749157116.912 [SBIT](INFO): Initialize SBIT Component.
2025-06-05T20:58:36.913Z,1749157116.913 [SBIT](IMPORTANT): git: 2025-06-02-8-gec96daa83
2025-06-05T20:58:36.913Z,1749157116.913 [SBIT](INFO): git hash: ec96daa838cb6ac1927da96e62739399b7e6a3fd
2025-06-05T20:58:36.913Z,1749157116.913 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2025-06-05T20:58:36.914Z,1749157116.914 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2025-06-05T20:58:36.916Z,1749157116.916 [SBIT](INFO): Beginning SBIT in 46.000000 seconds.
2025-06-05T20:58:36.916Z,1749157116.916 [IBIT](INFO): Initialize IBIT Component.
2025-06-05T20:58:36.917Z,1749157116.917 [CBIT](DEBUG): Initialize CBIT Component.
2025-06-05T20:58:36.918Z,1749157116.918 [logger ThreadHandler](INFO): Handler Thread ID is 943
2025-06-05T20:58:36.930Z,1749157116.930 [CBIT](DEBUG): Initialized mux pins.
2025-06-05T20:58:36.930Z,1749157116.930 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2025-06-05T20:58:36.930Z,1749157116.930 [CBIT](DEBUG): Initializing the watchdog timer.
2025-06-05T20:58:36.939Z,1749157116.939 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 944
2025-06-05T20:58:36.954Z,1749157116.954 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2025-06-05T20:58:36.955Z,1749157116.955 [CBIT](DEBUG): Initializing heartbeat.
2025-06-05T20:58:36.955Z,1749157116.955 [DAT ThreadHandler](INFO): Handler Thread ID is 945
2025-06-05T20:58:36.956Z,1749157116.956 [DAT](INFO): Powering up
2025-06-05T20:58:36.956Z,1749157116.956 [DAT](DEBUG): Initializing DAT.
2025-06-05T20:58:36.960Z,1749157116.960 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 947
2025-06-05T20:58:36.961Z,1749157116.961 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2025-06-05T20:58:36.983Z,1749157116.983 [Onboard ThreadHandler](INFO): Handler Thread ID is 948
2025-06-05T20:58:37.001Z,1749157117.001 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 949
2025-06-05T20:58:37.021Z,1749157117.021 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 950
2025-06-05T20:58:37.021Z,1749157117.021 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2025-06-05T20:58:37.026Z,1749157117.026 [CBIT](DEBUG): Deactivating emergency mode.
2025-06-05T20:58:37.028Z,1749157117.028 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 952
2025-06-05T20:58:37.031Z,1749157117.031 [WetLabsBB2FL](INFO): Powering up
2025-06-05T20:58:37.032Z,1749157117.032 [WetLabsUBAT ThreadHandler](INFO): Handler Thread ID is 954
2025-06-05T20:58:37.035Z,1749157117.035 [WetLabsUBAT](INFO): Powering up
2025-06-05T20:58:37.036Z,1749157117.036 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 956
2025-06-05T20:58:37.045Z,1749157117.045 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2025-06-05T20:58:37.045Z,1749157117.045 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2025-06-05T20:58:37.045Z,1749157117.045 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2025-06-05T20:58:37.045Z,1749157117.045 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2025-06-05T20:58:37.046Z,1749157117.046 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2025-06-05T20:58:37.046Z,1749157117.046 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2025-06-05T20:58:37.046Z,1749157117.046 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2025-06-05T20:58:37.046Z,1749157117.046 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2025-06-05T20:58:37.066Z,1749157117.066 [CBIT](DEBUG): Backplane powered.
2025-06-05T20:58:37.067Z,1749157117.067 [GFScanner](DEBUG): Initializing GFScanner
2025-06-05T20:58:37.067Z,1749157117.067 [GFScanner](DEBUG): Deactivating GF circuits.
2025-06-05T20:58:37.095Z,1749157117.095 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser
2025-06-05T20:58:37.096Z,1749157117.096 [MissionManager](INFO): Loading Mission from file: Missions/underIce/StartupUnder.tl
2025-06-05T20:58:37.096Z,1749157117.096 [MissionManager](DEBUG): TethyslAPI: loading: Missions/underIce/StartupUnder.tl
2025-06-05T20:58:37.103Z,1749157117.103 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/underIce/StartupUnder.tl
2025-06-05T20:58:37.135Z,1749157117.135 [MissionManager](DEBUG): TethyslAPI: Missions/underIce/StartupUnder.tl translated into:
2025-06-05T20:58:37.135Z,1749157117.135 [MissionManager](ERROR): Top node has no child nodes: Mission
2025-06-05T20:58:37.135Z,1749157117.135 [MissionManager](ERROR): Could not load startup mission.
2025-06-05T20:58:37.136Z,1749157117.136 [MissionManager](INFO): Loading Mission from file: Missions/underIce/DefaultWithUndock.tl
2025-06-05T20:58:37.136Z,1749157117.136 [MissionManager](DEBUG): TethyslAPI: loading: Missions/underIce/DefaultWithUndock.tl
2025-06-05T20:58:37.143Z,1749157117.143 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/underIce/DefaultWithUndock.tl
2025-06-05T20:58:37.406Z,1749157117.406 [Radio_Surface](INFO): Powering up
2025-06-05T20:58:37.736Z,1749157117.736 [MissionManager](DEBUG): TethyslAPI: Missions/underIce/DefaultWithUndock.tl translated into:
0
6
10
1
3
30
Timed out while trying to detach from dock at current depth of
.
Burn on
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2025-06-05T20:58:37.763Z,1749157117.763 [MissionManager](INFO): DefineArg DefaultWithUndock.ElapsedSinceDefaultStarted = 0.000000 min
2025-06-05T20:58:37.767Z,1749157117.767 [MissionManager](INFO): DefineArg DefaultWithUndock.DetachTimeout = 6.000000 h
2025-06-05T20:58:37.783Z,1749157117.783 [MissionManager](INFO): DefineArg DefaultWithUndock.TransponderCode = 50 count
2025-06-05T20:58:37.787Z,1749157117.787 [MissionManager](INFO): DefineArg DefaultWithUndock.TrackingUpdatePeriod = 10.000000 s
2025-06-05T20:58:37.811Z,1749157117.811 [MissionManager](INFO): DefineArg DefaultWithUndock.NumberOfPings = 1.000000 count
2025-06-05T20:58:37.815Z,1749157117.815 [MissionManager](INFO): DefineArg DefaultWithUndock.DriftTimeout = 3.000000 min
2025-06-05T20:58:37.816Z,1749157117.816 [DefaultWithUndock:A.Wait](DEBUG): Construct Wait.
2025-06-05T20:58:38.006Z,1749157118.006 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Construct.
2025-06-05T20:58:38.007Z,1749157118.007 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values.
2025-06-05T20:58:38.057Z,1749157118.057 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): Construct GoToSurface.
2025-06-05T20:58:38.100Z,1749157118.100 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2025-06-05T20:58:38.103Z,1749157118.103 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Construct Wait.
2025-06-05T20:58:38.129Z,1749157118.129 [DefaultWithUndock:E.Execute](DEBUG): Construct Execute.
2025-06-05T20:58:38.141Z,1749157118.141 [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 DefaultWithUndock {
arguments {
ElapsedSinceDefaultStarted = 0 minute
DetachTimeout = 6 hour
"""
Maximum time duration for the vehicle to detach form the dock.
"""
TransponderCode = Dock:Dock.transponderCode
"""
Dock transponder address.
"""
TrackingUpdatePeriod = 10 second
"""
Time duration between acoustic range queries while the mission is
detaching from the dock.
"""
NumberOfPings = 1 count
"""
Number of pings requested each time.
"""
DriftTimeout = 3 minute
"""
How long to allow vehicle to drift away from dock before retrying reverse
"""
}
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 = 30 second
}
aggregate LeaveDock {
run in sequence
timeout duration=DetachTimeout {
syslog important "Timed out while trying to detach from dock at current depth of "
+ Universal:depth~meter + "."
}
# Acoustic tracking directives
behavior Estimation:TrackAcousticContact {
run while (
Universal:depth > Control:VerticalControl.surfaceThreshold
)
set contactLabelSetting = TransponderCode
set numberOfSamplesSetting = NumberOfPings
set updatePeriodSetting = TrackingUpdatePeriod
}
# Leave the dock
behavior Dock:Undock {
run in sequence
set driftTimeout = DriftTimeout
}
}
aggregate SurfaceDefault {
run in sequence
# This mission assumes open water so from here on it's the same old default that's always used
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=P2H {
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-06-05T20:58:38.147Z,1749157118.147 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,RDI_Pathfinder,Sonardyne_Nano,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,DockingStepper,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,GFScanner,LcmUniversalReporter,Reporter,LogSplitter,
2025-06-05T20:58:38.167Z,1749157118.167 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2025-06-05T20:58:38.299Z,1749157118.299 [Depth_Keller](INFO): Initializing.
2025-06-05T20:58:38.300Z,1749157118.300 [Power24vConverter](INFO): Powering up.
2025-06-05T20:58:38.301Z,1749157118.301 [RDI_Pathfinder](IMPORTANT): Expecting PD13 message format
2025-06-05T20:58:38.307Z,1749157118.307 [Sonardyne_Nano](INFO): Initializing.
2025-06-05T20:58:38.351Z,1749157118.351 [DepthRateCalculator](ERROR): Depth measurement is not active
2025-06-05T20:58:38.381Z,1749157118.381 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2025-06-05T20:58:38.386Z,1749157118.386 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2025-06-05T20:58:38.388Z,1749157118.388 [ElevatorServo](DEBUG): Initializing EZServoServo.
2025-06-05T20:58:38.394Z,1749157118.394 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2025-06-05T20:58:38.395Z,1749157118.395 [DockingStepper](INFO): Start
2025-06-05T20:58:38.396Z,1749157118.396 [DockingStepper](DEBUG): Initializing EZServoServo.
2025-06-05T20:58:38.403Z,1749157118.403 [DockingStepper](DEBUG): Initializing DockingStepper.
2025-06-05T20:58:38.403Z,1749157118.403 [MassServo](DEBUG): Initializing EZServoServo.
2025-06-05T20:58:38.411Z,1749157118.411 [MassServo](DEBUG): Initializing MassServo.
2025-06-05T20:58:38.411Z,1749157118.411 [RudderServo](DEBUG): Initializing EZServoServo.
2025-06-05T20:58:38.418Z,1749157118.418 [RudderServo](DEBUG): Initializing RudderServo.
2025-06-05T20:58:38.419Z,1749157118.419 [ThrusterServo](DEBUG): Initializing EZServoServo.
2025-06-05T20:58:38.426Z,1749157118.426 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2025-06-05T20:58:38.428Z,1749157118.428 [CommandExec](FAULT): Scheduling is paused
2025-06-05T20:58:38.429Z,1749157118.429 [CBIT](INFO): Critical error at 20250605T205836
2025-06-05T20:58:38.429Z,1749157118.429 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2025-06-05T20:58:38.590Z,1749157118.590 [DropWeight](CRITICAL): DROP WEIGHT MISSING.
2025-06-05T20:58:38.590Z,1749157118.590 [DropWeight] Hardware Fault, FailCount= 1
2025-06-05T20:58:38.590Z,1749157118.590 [DropWeight](ERROR): Hardware Fault
2025-06-05T20:58:38.612Z,1749157118.612 [DockingStepper](INFO): Starting
2025-06-05T20:58:38.623Z,1749157118.623 [CBIT](INFO): Critical error at 20250605T205838
2025-06-05T20:58:38.625Z,1749157118.625 [CBIT](ERROR): Hardware Fault in component: DropWeight
2025-06-05T20:58:38.626Z,1749157118.626 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2025-06-05T20:58:38.991Z,1749157118.991 [DockingStepper](INFO): Starting
2025-06-05T20:58:38.993Z,1749157118.993 [CBIT](INFO): Critical error at 20250605T205838
2025-06-05T20:58:39.507Z,1749157119.507 [DockingStepper](INFO): Starting
2025-06-05T20:58:39.555Z,1749157119.555 [DockingStepper](INFO): Init string: /1z16336aE13561N3m50
2025-06-05T20:58:39.642Z,1749157119.642 [WetLabsBB2FL](INFO): Powering down
2025-06-05T20:58:39.801Z,1749157119.801 [DockingStepper](INFO): Starting
2025-06-05T20:58:40.208Z,1749157120.208 [DockingStepper](INFO): Starting
2025-06-05T20:58:40.577Z,1749157120.577 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART
2025-06-05T20:58:40.634Z,1749157120.634 [DockingStepper](INFO): Starting
2025-06-05T20:58:41.059Z,1749157121.059 [DockingStepper](INFO): Starting
2025-06-05T20:58:41.083Z,1749157121.083 [DockingStepper](INFO): Sent speed cmd:/1V10000 Response:ÿ/0@
2025-06-05T20:58:41.521Z,1749157121.521 [DockingStepper](INFO): Starting
2025-06-05T20:58:41.831Z,1749157121.831 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2103
2025-06-05T20:58:42.298Z,1749157122.298 [DockingStepper](INFO): Pause
2025-06-05T20:58:42.659Z,1749157122.659 [Radio_Surface](INFO): Checking local IP, expecting subnet 10.89.10
2025-06-05T20:58:42.659Z,1749157122.659 [Radio_Surface](INFO): No local IP found
2025-06-05T20:58:46.339Z,1749157126.339 [WetLabsUBAT](INFO): Powering down
2025-06-05T20:58:50.312Z,1749157130.312 [DAT](INFO): DAT read:
2025-06-05T20:58:50.563Z,1749157130.563 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series
2025-06-05T20:58:55.857Z,1749157135.857 [DAT](INFO): DAT read: MF Frequency Band
2025-06-05T20:58:56.108Z,1749157136.108 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.17.2
2025-06-05T20:58:56.108Z,1749157136.108 [DAT](INFO): DAT read: Jun 5 2025 20:58:08
2025-06-05T20:58:57.116Z,1749157137.116 [DAT](INFO): DAT read: Features enabled [Bearing]
2025-06-05T20:58:57.117Z,1749157137.117 [DAT](INFO): DAT read: CONNECT 00600 bits/sec 1 of 4, Rate 1/2 CC 25.00ms MGP
2025-06-05T20:58:57.117Z,1749157137.117 [DAT](INFO): commRate: 600
2025-06-05T20:58:59.182Z,1749157139.182 [DAT](INFO): entering command mode
2025-06-05T20:58:59.383Z,1749157139.383 [DAT](INFO): DAT read:
2025-06-05T20:58:59.383Z,1749157139.383 [DAT](INFO): DAT read: user:1>
2025-06-05T20:58:59.384Z,1749157139.384 [DAT](INFO): setting verbose to 3
2025-06-05T20:58:59.635Z,1749157139.635 [DAT](INFO): DAT read: user:1>
2025-06-05T20:58:59.636Z,1749157139.636 [DAT](INFO): DAT read: Verbose | 3
2025-06-05T20:58:59.636Z,1749157139.636 [DAT](INFO): set verbose to 3
2025-06-05T20:58:59.637Z,1749157139.637 [DAT](INFO): setting DatVerbose to 27440
2025-06-05T20:58:59.889Z,1749157139.889 [DAT](INFO): DAT read: user:2>
2025-06-05T20:58:59.892Z,1749157139.892 [DAT](INFO): DAT read: DatVerbose | 27440
2025-06-05T20:58:59.893Z,1749157139.893 [DAT](INFO): set DatVerbose to 27440
2025-06-05T20:58:59.894Z,1749157139.894 [DAT](INFO): setting transmit power to 8
2025-06-05T20:59:00.139Z,1749157140.139 [DAT](INFO): DAT read: user:3>
2025-06-05T20:59:00.140Z,1749157140.140 [DAT](INFO): DAT read: TxPower | 8 (Max)
2025-06-05T20:59:00.140Z,1749157140.140 [DAT](INFO): set transmit power to 8
2025-06-05T20:59:00.141Z,1749157140.141 [DAT](INFO): setting local address to 10
2025-06-05T20:59:00.391Z,1749157140.391 [DAT](INFO): DAT read: user:4>
2025-06-05T20:59:00.392Z,1749157140.392 [DAT](INFO): DAT read: LocalAddr | 10
2025-06-05T20:59:00.392Z,1749157140.392 [DAT](INFO): set local address to 10
2025-06-05T20:59:00.393Z,1749157140.393 [DAT](INFO): Setting time to: 20:59:0 And date to:6/5/2025
2025-06-05T20:59:00.643Z,1749157140.643 [DAT](INFO): DAT read: user:5>
2025-06-05T20:59:00.644Z,1749157140.644 [DAT](INFO): DAT read: Thu Jun 5, 2025 20:59:00
2025-06-05T20:59:00.644Z,1749157140.644 [DAT](INFO): Local DAT time set to Thu Jun 5, 2025 20:59:00
2025-06-05T20:59:05.680Z,1749157145.680 [NAL9602](INFO): Powering up NAL9602
2025-06-05T20:59:16.588Z,1749157156.588 [NAL9602](INFO): NAL9602 initialized
2025-06-05T20:59:23.501Z,1749157163.501 [SBIT](IMPORTANT): Beginning Startup BIT
2025-06-05T20:59:23.509Z,1749157163.509 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-06-05T20:59:28.175Z,1749157168.175 [GFScanner](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.091060
CHAN A1 (24V): 0.113695
CHAN A2 (12V): 0.050664
CHAN A3 (5V): 0.008855
CHAN B0 (3.3V): 0.006681
CHAN B1 (3.15aV): 0.005940
CHAN B2 (3.15bV): 0.005831
CHAN B3 (GND): 0.000970
OPEN: 0.002904
Full Scale: +/- 1 mA
2025-06-05T20:59:40.498Z,1749157180.498 [NAL9602](INFO): SBD MO Status=2, MOMSN=48143, MT Status=2, MTMSN=0
2025-06-05T20:59:40.498Z,1749157180.498 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-05T20:59:57.572Z,1749157197.572 [NAL9602](INFO): SBD MO Status=0, MOMSN=48143, MT Status=0, MTMSN=0
2025-06-05T20:59:57.572Z,1749157197.572 [NAL9602](INFO): No messages in MT queue
2025-06-05T20:59:58.774Z,1749157198.774 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205957.00,A,3654.37388,N,12206.68899,W,0.603,144.66,050625,,,A*72
2025-06-05T20:59:58.785Z,1749157198.785 [NAL9602](INFO): GPS fix at 20250605T205957: (36.906231, -122.111483)
2025-06-05T21:00:17.392Z,1749157217.392 [SBIT](IMPORTANT): SBIT PASSED
2025-06-05T21:00:17.393Z,1749157217.393 [SBIT](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2025-06-05T21:00:17.793Z,1749157217.793 [MissionManager](IMPORTANT): Started mission DefaultWithUndock
2025-06-05T21:00:17.794Z,1749157217.794 [DefaultWithUndock] Running Loop=1
2025-06-05T21:00:17.794Z,1749157217.794 [DefaultWithUndock](DEBUG): Aggregate::initialize DefaultWithUndock
2025-06-05T21:00:17.794Z,1749157217.794 [DefaultWithUndock:A.Wait] Running Loop=1
2025-06-05T21:00:17.794Z,1749157217.794 [DefaultWithUndock:A.Wait](DEBUG): Initialize Wait Component.
2025-06-05T21:00:31.120Z,1749157231.120 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-05T21:00:48.134Z,1749157248.134 [DefaultWithUndock:A.Wait](INFO): Done Waiting.
2025-06-05T21:00:48.134Z,1749157248.134 [DefaultWithUndock:A.Wait] Stopped
2025-06-05T21:00:48.136Z,1749157248.136 [DefaultWithUndock:A.Wait](DEBUG): Uninitialize Wait Component.
2025-06-05T21:00:48.136Z,1749157248.136 [DefaultWithUndock:LeaveDock] Running Loop=1
2025-06-05T21:00:48.136Z,1749157248.136 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::initialize DefaultWithUndock:LeaveDock
2025-06-05T21:00:48.136Z,1749157248.136 [DefaultWithUndock:LeaveDock:A.] Running Loop=1
2025-06-05T21:00:48.136Z,1749157248.136 [DefaultWithUndock:LeaveDock:A.](INFO): Initializing TrackAcousticContact.
2025-06-05T21:00:48.137Z,1749157248.137 [DefaultWithUndock:LeaveDock:B.Undock] Running Loop=1
2025-06-05T21:00:48.137Z,1749157248.137 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initialize.
2025-06-05T21:00:48.137Z,1749157248.137 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values.
2025-06-05T21:00:48.503Z,1749157248.503 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initialize.
2025-06-05T21:00:48.503Z,1749157248.503 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values.
2025-06-05T21:00:48.505Z,1749157248.505 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detached from dock at depth 0.005469 m.
2025-06-05T21:00:48.505Z,1749157248.505 [DefaultWithUndock:LeaveDock:A.] Stopped
2025-06-05T21:00:48.505Z,1749157248.505 [DefaultWithUndock:LeaveDock:A.](DEBUG): Uninitializing TrackAcousticContact.
2025-06-05T21:00:48.510Z,1749157248.510 [DockingStepper](INFO): Resume
2025-06-05T21:00:48.913Z,1749157248.913 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detected possible detachment. Starting timer.
2025-06-05T21:00:48.919Z,1749157248.919 [DockingStepper](INFO): Resuming
2025-06-05T21:00:49.335Z,1749157249.335 [DockingStepper](INFO): Start
2025-06-05T21:00:49.335Z,1749157249.335 [DockingStepper](DEBUG): Initializing EZServoServo.
2025-06-05T21:00:49.455Z,1749157249.455 [DockingStepper](DEBUG): Initializing DockingStepper.
2025-06-05T21:00:49.712Z,1749157249.712 [DockingStepper](INFO): Starting
2025-06-05T21:00:50.141Z,1749157250.141 [DockingStepper](INFO): Starting
2025-06-05T21:00:50.668Z,1749157250.668 [DockingStepper](INFO): Starting
2025-06-05T21:00:50.722Z,1749157250.722 [DockingStepper](INFO): Init string: /1z16335aE13561N3m50
2025-06-05T21:00:50.955Z,1749157250.955 [DockingStepper](INFO): Starting
2025-06-05T21:00:51.355Z,1749157251.355 [DockingStepper](INFO): Starting
2025-06-05T21:00:51.775Z,1749157251.775 [DockingStepper](INFO): Starting
2025-06-05T21:00:52.208Z,1749157252.208 [DockingStepper](INFO): Starting
2025-06-05T21:00:52.235Z,1749157252.235 [DockingStepper](INFO): Sent speed cmd:/1V10000 Response:ÿ/0@
2025-06-05T21:00:52.571Z,1749157252.571 [DockingStepper](INFO): Starting
2025-06-05T21:01:09.100Z,1749157269.100 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detached at range: nan m. Transitioning docking module to standby.
2025-06-05T21:01:09.512Z,1749157269.512 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Docking module at standby.
2025-06-05T21:01:09.967Z,1749157269.967 [DefaultWithUndock:LeaveDock:B.Undock](IMPORTANT): Undocking sequence complete.
2025-06-05T21:01:09.967Z,1749157269.967 [DefaultWithUndock:LeaveDock:B.Undock] Stopped
2025-06-05T21:01:09.967Z,1749157269.967 [DefaultWithUndock:LeaveDock](INFO): Completed DefaultWithUndock:LeaveDock
2025-06-05T21:01:09.967Z,1749157269.967 [DefaultWithUndock:LeaveDock] Stopped
2025-06-05T21:01:09.967Z,1749157269.967 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::uninitialize DefaultWithUndock:LeaveDock
2025-06-05T21:01:09.967Z,1749157269.967 [DefaultWithUndock:SurfaceDefault] Running Loop=1
2025-06-05T21:01:09.967Z,1749157269.967 [DefaultWithUndock:SurfaceDefault](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault
2025-06-05T21:01:09.967Z,1749157269.967 [DefaultWithUndock:SurfaceDefault:A.GoToSurface] Running Loop=1
2025-06-05T21:01:09.967Z,1749157269.967 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-06-05T21:01:09.968Z,1749157269.968 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-06-05T21:01:09.968Z,1749157269.968 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-06-05T21:01:09.969Z,1749157269.969 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-06-05T21:01:09.969Z,1749157269.969 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-06-05T21:01:09.969Z,1749157269.969 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-06-05T21:01:09.970Z,1749157269.970 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-06-05T21:01:10.328Z,1749157270.328 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=1
2025-06-05T21:01:10.328Z,1749157270.328 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2025-06-05T21:01:10.328Z,1749157270.328 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2025-06-05T21:01:10.476Z,1749157270.476 [DockingStepper](INFO): Pause
2025-06-05T21:01:10.725Z,1749157270.725 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-06-05T21:01:12.323Z,1749157272.323 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210111.00,A,3654.37672,N,12206.66866,W,1.205,91.61,050625,,,A*4F
2025-06-05T21:01:12.325Z,1749157272.325 [NAL9602](INFO): GPS fix at 20250605T210111: (36.906279, -122.111144)
2025-06-05T21:01:12.337Z,1749157272.337 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2025-06-05T21:01:12.337Z,1749157272.337 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2025-06-05T21:01:12.768Z,1749157272.768 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-06-05T21:01:30.671Z,1749157290.671 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-06-05T21:01:39.645Z,1749157299.645 [NAL9602](INFO): SBD MO Status=2, MOMSN=48144, MT Status=2, MTMSN=0
2025-06-05T21:01:39.645Z,1749157299.645 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-05T21:02:01.795Z,1749157321.795 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-06-05T21:02:05.570Z,1749157325.570 [NAL9602](INFO): SBD MO Status=2, MOMSN=48144, MT Status=2, MTMSN=0
2025-06-05T21:02:05.571Z,1749157325.571 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-05T21:02:29.665Z,1749157349.665 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004447
2025-06-05T21:02:37.386Z,1749157357.386 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20250605T185943/Courier0003.lzma
2025-06-05T21:02:38.388Z,1749157358.388 [DataOverHttps](INFO): Moved sent file to Logs/20250605T185943/Courier0003.lzma.bak
2025-06-05T21:02:38.388Z,1749157358.388 [DataOverHttps](INFO): SBD MOMSN=25109250
2025-06-05T21:02:40.788Z,1749157360.788 [NAL9602](INFO): SBD MO Status=2, MOMSN=48144, MT Status=2, MTMSN=0
2025-06-05T21:02:40.789Z,1749157360.789 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-05T21:02:54.843Z,1749157374.843 [DataOverHttps](INFO): Sending 403 bytes from file Logs/20250605T205824/Courier0000.lzma
2025-06-05T21:02:55.844Z,1749157375.844 [DataOverHttps](INFO): Moved sent file to Logs/20250605T205824/Courier0000.lzma.bak
2025-06-05T21:02:55.844Z,1749157375.844 [DataOverHttps](INFO): SBD MOMSN=25109252
2025-06-05T21:03:11.483Z,1749157391.483 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-05T21:03:12.206Z,1749157392.206 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20250605T185943/Express0005.lzma
2025-06-05T21:03:13.208Z,1749157393.208 [DataOverHttps](INFO): Moved sent file to Logs/20250605T185943/Express0005.lzma.bak
2025-06-05T21:03:13.208Z,1749157393.208 [DataOverHttps](INFO): SBD MOMSN=25109259
2025-06-05T21:03:29.688Z,1749157409.688 [DataOverHttps](INFO): Sending 1041 bytes from file Logs/20250605T205824/Express0001.lzma
2025-06-05T21:03:30.688Z,1749157410.688 [DataOverHttps](INFO): Moved sent file to Logs/20250605T205824/Express0001.lzma.bak
2025-06-05T21:03:30.688Z,1749157410.688 [DataOverHttps](INFO): SBD MOMSN=25109261
2025-06-05T21:03:32.123Z,1749157412.123 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2025-06-05T21:03:32.124Z,1749157412.124 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2025-06-05T21:03:32.124Z,1749157412.124 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-05T21:03:41.023Z,1749157421.023 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-06-05T21:03:49.880Z,1749157429.880 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-06-05T21:03:57.719Z,1749157437.719 [DataOverHttps](IMPORTANT): SBD MTMSN=20250605T210357
2025-06-05T21:04:06.586Z,1749157446.586 [DataOverHttps](INFO): Received command: restart sys
2025-06-05T21:04:06.648Z,1749157446.648 [CommandExec](IMPORTANT): got command restart system
2025-06-05T21:04:08.591Z,1749157448.591 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-06-05T21:04:08.823Z,1749157448.823 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2025-06-05T21:04:08.823Z,1749157448.823 [CommandExec](INFO): Uninitializing the command executive.
2025-06-05T21:04:08.823Z,1749157448.823 [CommandExec](INFO): Uninitializing the command scheduler.
2025-06-05T21:04:08.823Z,1749157448.823 [CommandExec ThreadHandler](INFO): Thread cancelled.
2025-06-05T21:04:08.946Z,1749157448.946 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2025-06-05T21:04:08.946Z,1749157448.946 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2025-06-05T21:04:08.947Z,1749157448.947 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2025-06-05T21:04:08.947Z,1749157448.947 [NavChartDb](INFO): Join timeout helper Thread ID is 995
2025-06-05T21:04:09.067Z,1749157449.067 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2025-06-05T21:04:09.068Z,1749157449.068 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2025-06-05T21:04:09.082Z,1749157449.082 [ComponentRegistry](INFO): Shutting down WetLabsUBAT Thread