2021-12-15T16:48:19.453Z,1639586899.453 [Supervisor](DEBUG): Initializing supervisor.
2021-12-15T16:48:19.458Z,1639586899.458 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2021-12-15T16:48:19.459Z,1639586899.459 [SyncHandler](INFO): Protected caller Thread ID is 8945
2021-12-15T16:48:19.459Z,1639586899.459 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2021-12-15T16:48:19.460Z,1639586899.460 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2021-12-15T16:48:19.461Z,1639586899.461 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 8946
2021-12-15T16:48:19.465Z,1639586899.465 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2021-12-15T16:48:19.483Z,1639586899.483 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2021-12-15T16:48:19.484Z,1639586899.484 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2021-12-15T16:48:19.484Z,1639586899.484 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 8947
2021-12-15T16:48:19.489Z,1639586899.489 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2021-12-15T16:48:19.490Z,1639586899.490 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2021-12-15T16:48:19.490Z,1639586899.490 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 8948
2021-12-15T16:48:19.492Z,1639586899.492 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2021-12-15T16:48:19.493Z,1639586899.493 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2021-12-15T16:48:19.493Z,1639586899.493 [logger ThreadHandler](INFO): Protected caller Thread ID is 8949
2021-12-15T16:48:19.497Z,1639586899.497 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2021-12-15T16:48:19.498Z,1639586899.498 [Supervisor](INFO): Looking for Config files in directory: Config/
2021-12-15T16:48:19.499Z,1639586899.499 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2021-12-15T16:48:19.921Z,1639586899.921 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2021-12-15T16:48:19.921Z,1639586899.921 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2021-12-15T16:48:20.132Z,1639586900.132 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2021-12-15T16:48:20.132Z,1639586900.132 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2021-12-15T16:48:20.317Z,1639586900.317 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2021-12-15T16:48:20.318Z,1639586900.318 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2021-12-15T16:48:20.425Z,1639586900.425 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2021-12-15T16:48:20.425Z,1639586900.425 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2021-12-15T16:48:20.780Z,1639586900.780 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2021-12-15T16:48:20.780Z,1639586900.780 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2021-12-15T16:48:21.099Z,1639586901.099 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2021-12-15T16:48:21.100Z,1639586901.100 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2021-12-15T16:48:21.196Z,1639586901.196 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2021-12-15T16:48:21.197Z,1639586901.197 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2021-12-15T16:48:21.347Z,1639586901.347 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2021-12-15T16:48:21.347Z,1639586901.347 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2021-12-15T16:48:21.874Z,1639586901.874 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2021-12-15T16:48:21.874Z,1639586901.874 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2021-12-15T16:48:22.760Z,1639586902.760 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2021-12-15T16:48:22.760Z,1639586902.760 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2021-12-15T16:48:22.843Z,1639586902.843 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2021-12-15T16:48:23.051Z,1639586903.051 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2021-12-15T16:48:23.052Z,1639586903.052 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2021-12-15T16:48:23.178Z,1639586903.178 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2021-12-15T16:48:23.179Z,1639586903.179 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2021-12-15T16:48:23.846Z,1639586903.846 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2021-12-15T16:48:23.847Z,1639586903.847 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2021-12-15T16:48:23.927Z,1639586903.927 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2021-12-15T16:48:24.171Z,1639586904.171 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2021-12-15T16:48:24.173Z,1639586904.173 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-galene/
2021-12-15T16:48:24.174Z,1639586904.174 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/vehicle.cfg
2021-12-15T16:48:24.346Z,1639586904.346 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/logger.cfg
2021-12-15T16:48:24.440Z,1639586904.440 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Servo.cfg
2021-12-15T16:48:24.551Z,1639586904.551 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Control.cfg
2021-12-15T16:48:24.652Z,1639586904.652 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/secure.cfg
2021-12-15T16:48:24.736Z,1639586904.736 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Simulator.cfg
2021-12-15T16:48:24.822Z,1639586904.822 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Science.cfg
2021-12-15T16:48:24.937Z,1639586904.937 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/BIT.cfg
2021-12-15T16:48:25.036Z,1639586905.036 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Sensor.cfg
2021-12-15T16:48:25.187Z,1639586905.187 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Battery.cfg
2021-12-15T16:48:25.446Z,1639586905.446 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2021-12-15T16:48:25.447Z,1639586905.447 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Navigation.cfg
2021-12-15T16:48:25.542Z,1639586905.542 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2021-12-15T16:48:25.552Z,1639586905.552 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2021-12-15T16:48:25.868Z,1639586905.868 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2021-12-15T16:48:25.869Z,1639586905.869 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2021-12-15T16:48:25.951Z,1639586905.951 [DeadReckonUsingMultipleVelocitySources] Loaded
2021-12-15T16:48:25.951Z,1639586905.951 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2021-12-15T16:48:25.985Z,1639586905.985 [DeadReckonUsingSpeedCalculator] Loaded
2021-12-15T16:48:25.985Z,1639586905.985 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2021-12-15T16:48:25.997Z,1639586905.997 [NavChart] Loaded
2021-12-15T16:48:25.998Z,1639586905.998 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2021-12-15T16:48:26.003Z,1639586906.003 [UniversalFixResidualReporter] Loaded
2021-12-15T16:48:26.004Z,1639586906.004 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2021-12-15T16:48:26.004Z,1639586906.004 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2021-12-15T16:48:26.005Z,1639586906.005 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2021-12-15T16:48:26.015Z,1639586906.015 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2021-12-15T16:48:26.016Z,1639586906.016 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2021-12-15T16:48:26.213Z,1639586906.213 [CTD_Seabird] Loaded
2021-12-15T16:48:26.213Z,1639586906.213 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2021-12-15T16:48:26.214Z,1639586906.214 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406514E0
2021-12-15T16:48:26.215Z,1639586906.215 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 9031
2021-12-15T16:48:26.234Z,1639586906.234 [PAR_Licor] Loaded
2021-12-15T16:48:26.235Z,1639586906.235 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2021-12-15T16:48:26.265Z,1639586906.265 [WetLabsBB2FL] Loaded
2021-12-15T16:48:26.266Z,1639586906.266 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2021-12-15T16:48:26.267Z,1639586906.267 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406814E0
2021-12-15T16:48:26.267Z,1639586906.267 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 9032
2021-12-15T16:48:26.268Z,1639586906.268 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2021-12-15T16:48:26.268Z,1639586906.268 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2021-12-15T16:48:26.320Z,1639586906.320 [VerticalControl](DEBUG): Construct VerticalControl.
2021-12-15T16:48:26.381Z,1639586906.381 [VerticalControl] Loaded
2021-12-15T16:48:26.381Z,1639586906.381 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2021-12-15T16:48:26.384Z,1639586906.384 [HorizontalControl](DEBUG): Construct HorizontalControl.
2021-12-15T16:48:26.422Z,1639586906.422 [HorizontalControl] Loaded
2021-12-15T16:48:26.422Z,1639586906.422 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2021-12-15T16:48:26.425Z,1639586906.425 [SpeedControl](DEBUG): Construct SpeedControl.
2021-12-15T16:48:26.428Z,1639586906.428 [SpeedControl] Loaded
2021-12-15T16:48:26.428Z,1639586906.428 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2021-12-15T16:48:26.431Z,1639586906.431 [LoopControl](DEBUG): Construct LoopControl.
2021-12-15T16:48:26.431Z,1639586906.431 [LoopControl] Loaded
2021-12-15T16:48:26.432Z,1639586906.432 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2021-12-15T16:48:26.432Z,1639586906.432 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2021-12-15T16:48:26.433Z,1639586906.433 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2021-12-15T16:48:26.475Z,1639586906.475 [DepthRateCalculator] Loaded
2021-12-15T16:48:26.475Z,1639586906.475 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2021-12-15T16:48:26.480Z,1639586906.480 [PitchRateCalculator] Loaded
2021-12-15T16:48:26.480Z,1639586906.480 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2021-12-15T16:48:26.489Z,1639586906.489 [SpeedCalculator] Loaded
2021-12-15T16:48:26.490Z,1639586906.490 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2021-12-15T16:48:26.503Z,1639586906.503 [TempGradientCalculator] Loaded
2021-12-15T16:48:26.503Z,1639586906.503 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2021-12-15T16:48:26.508Z,1639586906.508 [YawRateCalculator] Loaded
2021-12-15T16:48:26.508Z,1639586906.508 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2021-12-15T16:48:26.525Z,1639586906.525 [ElevatorOffsetCalculator] Loaded
2021-12-15T16:48:26.525Z,1639586906.525 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2021-12-15T16:48:26.526Z,1639586906.526 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2021-12-15T16:48:26.526Z,1639586906.526 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2021-12-15T16:48:26.620Z,1639586906.620 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2021-12-15T16:48:26.620Z,1639586906.620 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2021-12-15T16:48:26.680Z,1639586906.680 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2021-12-15T16:48:26.681Z,1639586906.681 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2021-12-15T16:48:26.807Z,1639586906.807 [BuoyancyServo] Loaded
2021-12-15T16:48:26.808Z,1639586906.808 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2021-12-15T16:48:26.827Z,1639586906.827 [ElevatorServo] Loaded
2021-12-15T16:48:26.827Z,1639586906.827 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2021-12-15T16:48:26.846Z,1639586906.846 [MassServo] Loaded
2021-12-15T16:48:26.846Z,1639586906.846 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2021-12-15T16:48:26.864Z,1639586906.864 [RudderServo] Loaded
2021-12-15T16:48:26.864Z,1639586906.864 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2021-12-15T16:48:26.879Z,1639586906.879 [ThrusterHE] Loaded
2021-12-15T16:48:26.879Z,1639586906.879 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2021-12-15T16:48:26.880Z,1639586906.880 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2021-12-15T16:48:26.880Z,1639586906.880 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2021-12-15T16:48:26.984Z,1639586906.984 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2021-12-15T16:48:26.984Z,1639586906.984 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2021-12-15T16:48:27.375Z,1639586907.375 [AHRS_M2] Loaded
2021-12-15T16:48:27.376Z,1639586907.376 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2021-12-15T16:48:27.412Z,1639586907.412 [BackseatComponent] Loaded
2021-12-15T16:48:27.412Z,1639586907.412 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2021-12-15T16:48:27.413Z,1639586907.413 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 40A554E0
2021-12-15T16:48:27.413Z,1639586907.413 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 9033
2021-12-15T16:48:27.416Z,1639586907.416 [LcmUniversalReporter] Loaded
2021-12-15T16:48:27.416Z,1639586907.416 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2021-12-15T16:48:28.233Z,1639586908.233 [BPC1] Loaded
2021-12-15T16:48:28.233Z,1639586908.233 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2021-12-15T16:48:28.311Z,1639586908.311 [DataOverHttps] Loaded
2021-12-15T16:48:28.311Z,1639586908.311 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2021-12-15T16:48:28.312Z,1639586908.312 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 40A854E0
2021-12-15T16:48:28.312Z,1639586908.312 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 9034
2021-12-15T16:48:28.332Z,1639586908.332 [Depth_Keller] Loaded
2021-12-15T16:48:28.332Z,1639586908.332 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2021-12-15T16:48:28.337Z,1639586908.337 [DropWeight] Loaded
2021-12-15T16:48:28.337Z,1639586908.337 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2021-12-15T16:48:28.398Z,1639586908.398 [NAL9602] Loaded
2021-12-15T16:48:28.398Z,1639586908.398 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2021-12-15T16:48:28.427Z,1639586908.427 [Onboard] Loaded
2021-12-15T16:48:28.427Z,1639586908.427 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2021-12-15T16:48:28.428Z,1639586908.428 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40AB54E0
2021-12-15T16:48:28.428Z,1639586908.428 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 9035
2021-12-15T16:48:28.440Z,1639586908.440 [Power24vConverter] Loaded
2021-12-15T16:48:28.440Z,1639586908.440 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2021-12-15T16:48:28.453Z,1639586908.453 [Radio_Surface] Loaded
2021-12-15T16:48:28.453Z,1639586908.453 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2021-12-15T16:48:28.454Z,1639586908.454 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40AE54E0
2021-12-15T16:48:28.455Z,1639586908.455 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 9036
2021-12-15T16:48:28.539Z,1639586908.539 [DAT] Loaded
2021-12-15T16:48:28.539Z,1639586908.539 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2021-12-15T16:48:28.540Z,1639586908.540 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40B154E0
2021-12-15T16:48:28.540Z,1639586908.540 [DAT ThreadHandler](INFO): Protected caller Thread ID is 9037
2021-12-15T16:48:28.541Z,1639586908.541 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2021-12-15T16:48:28.541Z,1639586908.541 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2021-12-15T16:48:29.060Z,1639586909.060 [SBIT](DEBUG): Construct Startup Built In Test.
2021-12-15T16:48:29.069Z,1639586909.069 [SBIT] Loaded
2021-12-15T16:48:29.069Z,1639586909.069 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2021-12-15T16:48:29.072Z,1639586909.072 [IBIT](DEBUG): Construct Initiated Built In Test.
2021-12-15T16:48:29.085Z,1639586909.085 [IBIT] Loaded
2021-12-15T16:48:29.086Z,1639586909.086 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2021-12-15T16:48:29.091Z,1639586909.091 [CBIT](DEBUG): Construct Continuous Built In Test.
2021-12-15T16:48:29.198Z,1639586909.198 [CBIT] Loaded
2021-12-15T16:48:29.198Z,1639586909.198 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2021-12-15T16:48:29.199Z,1639586909.199 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2021-12-15T16:48:29.199Z,1639586909.199 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2021-12-15T16:48:29.228Z,1639586909.228 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2021-12-15T16:48:29.234Z,1639586909.234 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2021-12-15T16:48:29.237Z,1639586909.237 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2021-12-15T16:48:29.248Z,1639586909.248 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2021-12-15T16:48:29.249Z,1639586909.249 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BA04E0
2021-12-15T16:48:29.249Z,1639586909.249 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 9038
2021-12-15T16:48:29.254Z,1639586909.254 [Supervisor](INFO): Main Thread ID is 8034
2021-12-15T16:48:29.254Z,1639586909.254 [Supervisor](DEBUG): Running supervisor.
2021-12-15T16:48:29.255Z,1639586909.255 [CommandExec ThreadHandler](INFO): Handler Thread ID is 9039
2021-12-15T16:48:29.255Z,1639586909.255 [CommandExec](INFO): Initializing the command executive.
2021-12-15T16:48:29.257Z,1639586909.257 [CommandLine ThreadHandler](INFO): Handler Thread ID is 9040
2021-12-15T16:48:29.259Z,1639586909.259 [controlThread ThreadHandler](INFO): Handler Thread ID is 9041
2021-12-15T16:48:29.259Z,1639586909.259 [controlThread](DEBUG): Initializing ControlThread
2021-12-15T16:48:29.261Z,1639586909.261 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2021-12-15T16:48:29.261Z,1639586909.261 [NavChart](DEBUG): Initialize NavChart Navigation.
2021-12-15T16:48:29.262Z,1639586909.262 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2021-12-15T16:48:29.266Z,1639586909.266 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2021-12-15T16:48:29.268Z,1639586909.268 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2021-12-15T16:48:29.269Z,1639586909.269 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2021-12-15T16:48:29.269Z,1639586909.269 [LoopControl](DEBUG): Initialize LoopControlComponent.
2021-12-15T16:48:29.270Z,1639586909.270 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2021-12-15T16:48:29.270Z,1639586909.270 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2021-12-15T16:48:29.270Z,1639586909.270 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2021-12-15T16:48:29.271Z,1639586909.271 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2021-12-15T16:48:29.271Z,1639586909.271 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2021-12-15T16:48:29.272Z,1639586909.272 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2021-12-15T16:48:29.276Z,1639586909.276 [SBIT](INFO): Initialize SBIT Component.
2021-12-15T16:48:29.277Z,1639586909.277 [SBIT](IMPORTANT): git: 2021-12-15
2021-12-15T16:48:29.277Z,1639586909.277 [SBIT](INFO): git hash: 84418ad1eafed0e7cc0d1e8880438ed016edb8c4
2021-12-15T16:48:29.277Z,1639586909.277 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2021-12-15T16:48:29.278Z,1639586909.278 [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
2021-12-15T16:48:29.280Z,1639586909.280 [SBIT](INFO): Beginning SBIT in 40.000000 seconds.
2021-12-15T16:48:29.280Z,1639586909.280 [IBIT](INFO): Initialize IBIT Component.
2021-12-15T16:48:29.281Z,1639586909.281 [CBIT](DEBUG): Initialize CBIT Component.
2021-12-15T16:48:29.282Z,1639586909.282 [logger ThreadHandler](INFO): Handler Thread ID is 9042
2021-12-15T16:48:29.294Z,1639586909.294 [CBIT](DEBUG): Initialized mux pins.
2021-12-15T16:48:29.294Z,1639586909.294 [CBIT](DEBUG): Initializing the watchdog timer.
2021-12-15T16:48:29.302Z,1639586909.302 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 9043
2021-12-15T16:48:29.303Z,1639586909.303 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2021-12-15T16:48:29.308Z,1639586909.308 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 9045
2021-12-15T16:48:29.310Z,1639586909.310 [WetLabsBB2FL](INFO): Powering up
2021-12-15T16:48:29.312Z,1639586909.312 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 9047
2021-12-15T16:48:29.318Z,1639586909.318 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2021-12-15T16:48:29.319Z,1639586909.319 [CBIT](DEBUG): Initializing heartbeat.
2021-12-15T16:48:29.320Z,1639586909.320 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 9048
2021-12-15T16:48:29.321Z,1639586909.321 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2021-12-15T16:48:29.330Z,1639586909.330 [Onboard ThreadHandler](INFO): Handler Thread ID is 9049
2021-12-15T16:48:29.348Z,1639586909.348 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 9050
2021-12-15T16:48:29.370Z,1639586909.370 [DAT ThreadHandler](INFO): Handler Thread ID is 9051
2021-12-15T16:48:29.371Z,1639586909.371 [DAT](INFO): Powering up
2021-12-15T16:48:29.371Z,1639586909.371 [DAT](DEBUG): Initializing DAT.
2021-12-15T16:48:29.375Z,1639586909.375 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 9053
2021-12-15T16:48:29.381Z,1639586909.381 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2021-12-15T16:48:29.381Z,1639586909.381 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2021-12-15T16:48:29.381Z,1639586909.381 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2021-12-15T16:48:29.381Z,1639586909.381 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2021-12-15T16:48:29.381Z,1639586909.381 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2021-12-15T16:48:29.382Z,1639586909.382 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2021-12-15T16:48:29.382Z,1639586909.382 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2021-12-15T16:48:29.382Z,1639586909.382 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2021-12-15T16:48:29.383Z,1639586909.383 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2021-12-15T16:48:29.383Z,1639586909.383 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2021-12-15T16:48:29.383Z,1639586909.383 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2021-12-15T16:48:29.383Z,1639586909.383 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2021-12-15T16:48:29.383Z,1639586909.383 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2021-12-15T16:48:29.383Z,1639586909.383 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2021-12-15T16:48:29.384Z,1639586909.384 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2021-12-15T16:48:29.384Z,1639586909.384 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2021-12-15T16:48:29.390Z,1639586909.390 [CBIT](DEBUG): Deactivating GF circuits.
2021-12-15T16:48:29.390Z,1639586909.390 [CBIT](DEBUG): Deactivating emergency mode.
2021-12-15T16:48:29.426Z,1639586909.426 [CBIT](DEBUG): Backplane powered.
2021-12-15T16:48:29.427Z,1639586909.427 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2021-12-15T16:48:29.441Z,1639586909.441 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2021-12-15T16:48:29.473Z,1639586909.473 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2021-12-15T16:48:29.474Z,1639586909.474 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2021-12-15T16:48:29.552Z,1639586909.552 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2021-12-15T16:48:29.553Z,1639586909.553 [Default:A.Wait](DEBUG): Construct Wait.
2021-12-15T16:48:29.575Z,1639586909.575 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2021-12-15T16:48:29.592Z,1639586909.592 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2021-12-15T16:48:29.615Z,1639586909.615 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2021-12-15T16:48:29.629Z,1639586909.629 [Default:E.Execute](DEBUG): Construct Execute.
2021-12-15T16:48:29.633Z,1639586909.633 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

    <DefineArg Name="ElapsedSinceDefaultStarted"><Units:minute/><Value>0</Value></DefineArg>

    <Guidance:Wait>
        <Description>
            Wait a moment to see if the scheduler starts a new mission before
            starting to actually run Default.
        </Description>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Units:second/><Value>13</Value></Setting>
    </Guidance:Wait>

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn on</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>5</Value></Setting>
        </Guidance:Wait>

        <Assign><Sequence/><Arg Name="ElapsedSinceDefaultStarted"/><Elapsed><Universal:mission_started/></Elapsed></Assign>

        <Syslog Severity="Important">Default mission has been running for <Arg Name="ElapsedSinceDefaultStarted"/><Units:minute/></Syslog>

    </Aggregate>

    <Syslog Severity="Important">Restarting logs and Default mission.</Syslog>

    <Guidance:Execute>
        <Sequence/>
        <Setting><Guidance:Execute.command/><String>restart logs</String></Setting>
    </Guidance:Execute>

</Mission>


2021-12-15T16:48:29.650Z,1639586909.650 [controlThread](DEBUG): Component order: CycleStarter,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2021-12-15T16:48:29.671Z,1639586909.671 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2021-12-15T16:48:29.741Z,1639586909.741 [Power24vConverter](INFO): Powering up.
2021-12-15T16:48:29.754Z,1639586909.754 [Radio_Surface](INFO): Powering up
2021-12-15T16:48:29.806Z,1639586909.806 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2021-12-15T16:48:29.814Z,1639586909.814 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2021-12-15T16:48:29.816Z,1639586909.816 [ElevatorServo](DEBUG): Initializing EZServoServo.
2021-12-15T16:48:29.822Z,1639586909.822 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2021-12-15T16:48:29.823Z,1639586909.823 [MassServo](DEBUG): Initializing EZServoServo.
2021-12-15T16:48:29.830Z,1639586909.830 [MassServo](DEBUG): Initializing MassServo.
2021-12-15T16:48:29.831Z,1639586909.831 [RudderServo](DEBUG): Initializing EZServoServo.
2021-12-15T16:48:29.842Z,1639586909.842 [RudderServo](DEBUG): Initializing RudderServo.
2021-12-15T16:48:29.843Z,1639586909.843 [ThrusterHE](DEBUG): Initializing EZServoServo.
2021-12-15T16:48:29.850Z,1639586909.850 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2021-12-15T16:48:30.806Z,1639586910.806 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2021-12-15T16:48:30.806Z,1639586910.806 [RudderServo](FAULT): Rudder failed to initialize
2021-12-15T16:48:30.806Z,1639586910.806 [RudderServo] Communications Fault, FailCount= 1
2021-12-15T16:48:30.806Z,1639586910.806 [RudderServo](ERROR): Communications Fault
2021-12-15T16:48:30.810Z,1639586910.810 [CBIT](ERROR): Communications Fault in component: RudderServo
2021-12-15T16:48:31.019Z,1639586911.019 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2021-12-15T16:48:31.019Z,1639586911.019 [RudderServo](INFO): Powering down
2021-12-15T16:48:31.717Z,1639586911.717 [RudderServo](DEBUG): Initializing EZServoServo.
2021-12-15T16:48:31.835Z,1639586911.835 [RudderServo](DEBUG): Initializing RudderServo.
2021-12-15T16:48:31.839Z,1639586911.839 [CBIT](INFO): Clearing failed state for component RudderServo
2021-12-15T16:48:31.839Z,1639586911.839 [RudderServo] No Fault, FailCount= 1
2021-12-15T16:48:31.922Z,1639586911.922 [WetLabsBB2FL](INFO): Powering down
2021-12-15T16:48:36.339Z,1639586916.339 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2021-12-15T16:48:40.742Z,1639586920.742 [MassServo](ERROR): getPosition uart error serial timeout
2021-12-15T16:48:40.743Z,1639586920.743 [MassServo](FAULT): Invalid EZ Servo response:"\r"
2021-12-15T16:48:40.743Z,1639586920.743 [MassServo] Communications Fault, FailCount= 1
2021-12-15T16:48:40.743Z,1639586920.743 [MassServo](ERROR): Communications Fault
2021-12-15T16:48:40.747Z,1639586920.747 [CBIT](ERROR): Communications Fault in component: MassServo
2021-12-15T16:48:40.967Z,1639586920.967 [DAT](INFO): DAT read: 

2021-12-15T16:48:40.968Z,1639586920.968 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series

2021-12-15T16:48:41.025Z,1639586921.025 [MassServo](DEBUG): Uninitialize Mass Servo.
2021-12-15T16:48:41.025Z,1639586921.025 [MassServo](INFO): Powering down
2021-12-15T16:48:41.821Z,1639586921.821 [MassServo](DEBUG): Initializing EZServoServo.
2021-12-15T16:48:41.939Z,1639586921.939 [MassServo](DEBUG): Initializing MassServo.
2021-12-15T16:48:41.944Z,1639586921.944 [CBIT](INFO): Clearing failed state for component MassServo
2021-12-15T16:48:41.944Z,1639586921.944 [MassServo] No Fault, FailCount= 1
2021-12-15T16:48:42.479Z,1639586922.479 [DAT](INFO): DAT read: MF Frequency Band

2021-12-15T16:48:42.480Z,1639586922.480 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0

2021-12-15T16:48:42.481Z,1639586922.481 [DAT](INFO): DAT read: Dec 15 2021 16:48:09 

2021-12-15T16:48:43.487Z,1639586923.487 [DAT](INFO): DAT read: Features enabled [Bearing]

2021-12-15T16:48:43.488Z,1639586923.488 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2021-12-15T16:48:43.489Z,1639586923.489 [DAT](INFO): commRate: 800
2021-12-15T16:48:45.503Z,1639586925.503 [DAT](INFO): entering command mode
2021-12-15T16:48:45.754Z,1639586925.754 [DAT](INFO): DAT read: 

2021-12-15T16:48:45.755Z,1639586925.755 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:46.006Z,1639586926.006 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:46.258Z,1639586926.258 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:46.511Z,1639586926.511 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:46.763Z,1639586926.763 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:47.014Z,1639586927.014 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:47.266Z,1639586927.266 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:47.518Z,1639586927.518 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:47.771Z,1639586927.771 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:48.022Z,1639586928.022 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:48.277Z,1639586928.277 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:48.528Z,1639586928.528 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:48.779Z,1639586928.779 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:49.030Z,1639586929.030 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:49.282Z,1639586929.282 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:49.535Z,1639586929.535 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:49.786Z,1639586929.786 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:50.038Z,1639586930.038 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:50.290Z,1639586930.290 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:50.542Z,1639586930.542 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:50.794Z,1639586930.794 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:51.046Z,1639586931.046 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:51.298Z,1639586931.298 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:51.550Z,1639586931.550 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:51.802Z,1639586931.802 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:52.055Z,1639586932.055 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:52.306Z,1639586932.306 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:52.558Z,1639586932.558 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:52.811Z,1639586932.811 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:53.062Z,1639586933.062 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:53.314Z,1639586933.314 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:53.567Z,1639586933.567 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:53.818Z,1639586933.818 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:54.071Z,1639586934.071 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:54.322Z,1639586934.322 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:54.574Z,1639586934.574 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:54.826Z,1639586934.826 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:55.078Z,1639586935.078 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:55.331Z,1639586935.331 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:55.582Z,1639586935.582 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:55.834Z,1639586935.834 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:56.086Z,1639586936.086 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:56.338Z,1639586936.338 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:56.590Z,1639586936.590 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:56.845Z,1639586936.845 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:57.099Z,1639586937.099 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:57.351Z,1639586937.351 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:57.603Z,1639586937.603 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:57.854Z,1639586937.854 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:58.106Z,1639586938.106 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:58.358Z,1639586938.358 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:58.611Z,1639586938.611 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:58.756Z,1639586938.756 [NAL9602](INFO): Powering up NAL9602
2021-12-15T16:48:58.863Z,1639586938.863 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:59.114Z,1639586939.114 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:59.367Z,1639586939.367 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:59.618Z,1639586939.618 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:48:59.870Z,1639586939.870 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:49:00.122Z,1639586940.122 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:49:00.374Z,1639586940.374 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:49:00.626Z,1639586940.626 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-15T16:49:00.627Z,1639586940.627 [DAT](FAULT): failed to enter command mode
2021-12-15T16:49:00.879Z,1639586940.879 [DAT](INFO): entering command mode
2021-12-15T16:49:01.131Z,1639586941.131 [DAT](INFO): DAT read: user:1>

2021-12-15T16:49:01.131Z,1639586941.131 [DAT](INFO): DAT read: Command '+++' not found

2021-12-15T16:49:01.132Z,1639586941.132 [DAT](INFO): DAT read: Error

2021-12-15T16:49:01.132Z,1639586941.132 [DAT](INFO): setting verbose to 3
2021-12-15T16:49:01.383Z,1639586941.383 [DAT](INFO): DAT read: user:2>

2021-12-15T16:49:01.384Z,1639586941.384 [DAT](INFO): DAT read: Verbose         | 3           

2021-12-15T16:49:01.384Z,1639586941.384 [DAT](INFO): set verbose to 3
2021-12-15T16:49:01.384Z,1639586941.384 [DAT](INFO): setting DatVerbose to 27440
2021-12-15T16:49:01.635Z,1639586941.635 [DAT](INFO): DAT read: user:3>

2021-12-15T16:49:01.636Z,1639586941.636 [DAT](INFO): DAT read: DatVerbose      | 27440       

2021-12-15T16:49:01.636Z,1639586941.636 [DAT](INFO): set DatVerbose to 27440
2021-12-15T16:49:01.636Z,1639586941.636 [DAT](INFO): setting transmit power to 8
2021-12-15T16:49:01.887Z,1639586941.887 [DAT](INFO): DAT read: user:4>

2021-12-15T16:49:01.888Z,1639586941.888 [DAT](INFO): DAT read: TxPower         | 8 (Max)     

2021-12-15T16:49:01.888Z,1639586941.888 [DAT](INFO): set transmit power to 8
2021-12-15T16:49:01.888Z,1639586941.888 [DAT](INFO): setting local address to 10
2021-12-15T16:49:02.139Z,1639586942.139 [DAT](INFO): DAT read: user:5>

2021-12-15T16:49:02.140Z,1639586942.140 [DAT](INFO): DAT read: LocalAddr       | 10          

2021-12-15T16:49:02.140Z,1639586942.140 [DAT](INFO): set local address to 10
2021-12-15T16:49:09.668Z,1639586949.668 [NAL9602](INFO): NAL9602 initialized
2021-12-15T16:49:09.694Z,1639586949.694 [SBIT](IMPORTANT): Beginning Startup BIT
2021-12-15T16:49:09.722Z,1639586949.722 [CBIT](IMPORTANT): Beginning ground fault scan
2021-12-15T16:49:09.951Z,1639586949.951 [DAT](INFO): DAT read: user:6>Rx Time:16:48:38.5818

2021-12-15T16:49:10.712Z,1639586950.712 [DAT](INFO): DAT read: 16:48:38.5818 LVL= 23056, 24657, 22322, 32755, AGC= 80, IDX= 471, 0.14,-2.000,-2.140,-2.036,-2.331, PHS= 0.300, 0.165, 0.291, RAW= 146.6, -63.9, CAL= 146.7, -65.3, ROT=  63.3,  65.3

2021-12-15T16:49:10.713Z,1639586950.713 [DAT](INFO): got valid direction response:
 16:48:38.5818 LVL= 23056, 24657, 22322, 32755, AGC= 80, IDX= 471, 0.14,-2.000,-2.140,-2.036,-2.331, PHS= 0.300, 0.165, 0.291, RAW= 146.6, -63.9, CAL= 146.7, -65.3, ROT=  63.3,  65.3

2021-12-15T16:49:10.713Z,1639586950.713 [DAT](INFO): DAT read: bearing request

2021-12-15T16:49:10.713Z,1639586950.713 [DAT](INFO): received a bearing request message
2021-12-15T16:49:10.714Z,1639586950.714 [DAT](INFO): DAT read: Tx time:16:48:40.1846

2021-12-15T16:49:10.715Z,1639586950.715 [DAT](INFO): Ping request sent.
2021-12-15T16:49:10.715Z,1639586950.715 [DAT](INFO): transmitted an acoustic signal
2021-12-15T16:49:10.715Z,1639586950.715 [DAT](INFO): #Rx 1: Read direction message, but no range.
2021-12-15T16:49:10.716Z,1639586950.716 [DAT](INFO): direction in vehicle frame: [ 0.187756 forward, 0.373310 starboard, 0.908508 keelward ]
2021-12-15T16:49:10.717Z,1639586950.717 [DAT](INFO): publishing transmit ping time
2021-12-15T16:49:10.717Z,1639586950.717 [DAT](INFO): publishing range request flag
2021-12-15T16:49:10.720Z,1639586950.720 [DAT](INFO): publishing transmit ping time
2021-12-15T16:49:10.721Z,1639586950.721 [DAT](INFO): publishing range request flag
2021-12-15T16:49:20.672Z,1639586960.672 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.008169
CHAN A1 (24V): 0.001676
CHAN A2 (12V): -0.005246
CHAN A3 (5V): -0.002913
CHAN B0 (3.3V): -0.000946
CHAN B1 (3.15aV): -0.001217
CHAN B2 (3.15bV): -0.001741
CHAN B3 (GND): -0.000401
OPEN: 0.004737
Full Scale: +/- 1 mA
2021-12-15T16:49:57.799Z,1639586997.799 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-12-15T16:50:03.818Z,1639587003.818 [SBIT](IMPORTANT): SBIT PASSED
2021-12-15T16:50:03.818Z,1639587003.818 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2021-12-15T16:50:03.819Z,1639587003.819 [SBIT](IMPORTANT): BackseatComponent.needs24v=1 bool;

2021-12-15T16:50:03.819Z,1639587003.819 [SBIT](IMPORTANT): BuoyancyServo.fastPumpCoefficient=6 none;

2021-12-15T16:50:03.819Z,1639587003.819 [SBIT](IMPORTANT): CBIT.gf24Offset=149 microampere;

2021-12-15T16:50:03.820Z,1639587003.820 [SBIT](IMPORTANT): DAT.sbdAddress=21 enum;

2021-12-15T16:50:03.820Z,1639587003.820 [SBIT](IMPORTANT): DAT.verbosity=3 count;

2021-12-15T16:50:03.820Z,1639587003.820 [SBIT](IMPORTANT): IBIT.batteryCapacityThreshold=5 ampere_hour;

2021-12-15T16:50:03.820Z,1639587003.820 [SBIT](IMPORTANT): IBIT.batteryVoltageThreshold=11 volt;

2021-12-15T16:50:03.820Z,1639587003.820 [SBIT](IMPORTANT): PowerOnly.loadAtStartup=0 bool;

2021-12-15T16:50:03.820Z,1639587003.820 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=126.383040 cubic_centimeter;

2021-12-15T16:50:03.820Z,1639587003.820 [SBIT](IMPORTANT): VerticalControl.massDefault=-5.157439 millimeter;

2021-12-15T16:50:04.227Z,1639587004.227 [MissionManager](IMPORTANT): Started mission Startup
2021-12-15T16:50:04.227Z,1639587004.227 [Startup] Running Loop=1
2021-12-15T16:50:04.227Z,1639587004.227 [Startup](DEBUG): Aggregate::initialize Startup
2021-12-15T16:50:04.227Z,1639587004.227 [Startup:A.GoToSurface] Running Loop=1
2021-12-15T16:50:04.227Z,1639587004.227 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-12-15T16:50:04.228Z,1639587004.228 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-12-15T16:50:04.228Z,1639587004.228 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-12-15T16:50:04.229Z,1639587004.229 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-12-15T16:50:04.229Z,1639587004.229 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-12-15T16:50:04.229Z,1639587004.229 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-12-15T16:50:04.231Z,1639587004.231 [Startup:StartupSatComms] Running Loop=1
2021-12-15T16:50:04.231Z,1639587004.231 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2021-12-15T16:50:04.231Z,1639587004.231 [Startup:StartupSatComms:A] Running Loop=1
2021-12-15T16:50:04.624Z,1639587004.624 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2021-12-15T16:50:09.971Z,1639587009.971 [DAT](INFO): DAT read: Rx Time:16:49:38.5827

2021-12-15T16:50:09.971Z,1639587009.971 [DAT](INFO): received an acoustic signal
2021-12-15T16:50:10.732Z,1639587010.732 [DAT](INFO): DAT read: 16:49:38.5827 LVL= 19184, 20049, 17810, 24451, AGC= 80, IDX= 101,-0.26, 3.140, 3.049,-3.130, 2.860, PHS= 0.248, 0.162, 0.289, RAW= 168.1, -65.5, CAL= 170.6, -66.6, ROT=  39.4,  66.6

2021-12-15T16:50:10.733Z,1639587010.733 [DAT](INFO): got valid direction response:
 16:49:38.5827 LVL= 19184, 20049, 17810, 24451, AGC= 80, IDX= 101,-0.26, 3.140, 3.049,-3.130, 2.860, PHS= 0.248, 0.162, 0.289, RAW= 168.1, -65.5, CAL= 170.6, -66.6, ROT=  39.4,  66.6

2021-12-15T16:50:10.733Z,1639587010.733 [DAT](INFO): DAT read: bearing request

2021-12-15T16:50:10.734Z,1639587010.734 [DAT](INFO): received a bearing request message
2021-12-15T16:50:10.735Z,1639587010.735 [DAT](INFO): DAT read: Tx time:16:49:40.1855

2021-12-15T16:50:10.735Z,1639587010.735 [DAT](INFO): Ping request sent.
2021-12-15T16:50:10.735Z,1639587010.735 [DAT](INFO): transmitted an acoustic signal
2021-12-15T16:50:10.736Z,1639587010.736 [DAT](INFO): #Rx 2: Read direction message, but no range.
2021-12-15T16:50:10.737Z,1639587010.737 [DAT](INFO): direction in vehicle frame: [ 0.306890 forward, 0.252082 starboard, 0.917755 keelward ]
2021-12-15T16:50:10.737Z,1639587010.737 [DAT](INFO): publishing transmit ping time
2021-12-15T16:50:10.738Z,1639587010.738 [DAT](INFO): publishing range request flag
2021-12-15T16:50:10.741Z,1639587010.741 [DAT](INFO): publishing transmit ping time
2021-12-15T16:50:10.741Z,1639587010.741 [DAT](INFO): publishing range request flag
2021-12-15T16:50:57.329Z,1639587057.329 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005666
2021-12-15T16:51:04.425Z,1639587064.425 [Startup:StartupSatComms:A](INFO): Timed out from 2021-12-15T16:50:04.2Z
2021-12-15T16:51:04.425Z,1639587064.425 [Startup:StartupSatComms:A] Stopped
2021-12-15T16:51:04.425Z,1639587064.425 [Startup:StartupSatComms:B] Running Loop=1
2021-12-15T16:51:04.827Z,1639587064.827 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-12-15T16:51:11.035Z,1639587071.035 [DAT](INFO): DAT read: Rx Time:16:50:39.6334

2021-12-15T16:51:11.035Z,1639587071.035 [DAT](INFO): received an acoustic signal
2021-12-15T16:51:11.796Z,1639587071.796 [DAT](INFO): DAT read: 16:50:39.6335 LVL= 22672, 21265, 19666, 32755, AGC= 80, IDX= 434,-0.14,-2.609,-2.775,-2.650,-2.927, PHS= 0.287, 0.126, 0.273, RAW= 145.4, -57.4, CAL= 145.4, -59.2, ROT=  64.6,  59.2

2021-12-15T16:51:11.797Z,1639587071.797 [DAT](INFO): got valid direction response:
 16:50:39.6335 LVL= 22672, 21265, 19666, 32755, AGC= 80, IDX= 434,-0.14,-2.609,-2.775,-2.650,-2.927, PHS= 0.287, 0.126, 0.273, RAW= 145.4, -57.4, CAL= 145.4, -59.2, ROT=  64.6,  59.2

2021-12-15T16:51:11.798Z,1639587071.798 [DAT](INFO): DAT read: bearing request

2021-12-15T16:51:11.798Z,1639587071.798 [DAT](INFO): received a bearing request message
2021-12-15T16:51:11.799Z,1639587071.799 [DAT](INFO): DAT read: Tx time:16:50:41.2364

2021-12-15T16:51:11.799Z,1639587071.799 [DAT](INFO): Ping request sent.
2021-12-15T16:51:11.799Z,1639587071.799 [DAT](INFO): transmitted an acoustic signal
2021-12-15T16:51:11.799Z,1639587071.799 [DAT](INFO): #Rx 3: Read direction message, but no range.
2021-12-15T16:51:11.800Z,1639587071.800 [DAT](INFO): direction in vehicle frame: [ 0.219633 forward, 0.462546 starboard, 0.858960 keelward ]
2021-12-15T16:51:11.801Z,1639587071.801 [DAT](INFO): publishing transmit ping time
2021-12-15T16:51:11.801Z,1639587071.801 [DAT](INFO): publishing range request flag
2021-12-15T16:51:11.804Z,1639587071.804 [DAT](INFO): publishing transmit ping time
2021-12-15T16:51:11.804Z,1639587071.804 [DAT](INFO): publishing range request flag
2021-12-15T16:51:13.282Z,1639587073.282 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20211215T153121/Courier0019.lzma
2021-12-15T16:51:14.284Z,1639587074.284 [DataOverHttps](INFO): Moved sent file to Logs/20211215T153121/Courier0019.lzma.bak
2021-12-15T16:51:14.284Z,1639587074.284 [DataOverHttps](INFO): SBD MOMSN=16391277
2021-12-15T16:51:16.784Z,1639587076.784 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-12-15T16:51:29.636Z,1639587089.636 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-12-15T16:51:29.696Z,1639587089.696 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2021-12-15T16:51:29.696Z,1639587089.696 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-12-15T16:51:29.697Z,1639587089.697 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2021-12-15T16:51:29.697Z,1639587089.697 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2021-12-15T16:51:29.740Z,1639587089.740 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-12-15T16:51:29.740Z,1639587089.740 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2021-12-15T16:51:30.052Z,1639587090.052 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-12-15T16:51:30.052Z,1639587090.052 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2021-12-15T16:51:30.052Z,1639587090.052 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2021-12-15T16:51:30.052Z,1639587090.052 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2021-12-15T16:51:30.415Z,1639587090.415 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2021-12-15T16:51:37.046Z,1639587097.046 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20211215T164819/Courier0000.lzma
2021-12-15T16:51:38.056Z,1639587098.056 [DataOverHttps](INFO): Moved sent file to Logs/20211215T164819/Courier0000.lzma.bak
2021-12-15T16:51:38.056Z,1639587098.056 [DataOverHttps](INFO): SBD MOMSN=16391279
2021-12-15T16:51:56.934Z,1639587116.934 [DataOverHttps](INFO): Sending 191 bytes from file Logs/20211215T153121/Express0020.lzma
2021-12-15T16:51:57.936Z,1639587117.936 [DataOverHttps](INFO): Moved sent file to Logs/20211215T153121/Express0020.lzma.bak
2021-12-15T16:51:57.936Z,1639587117.936 [DataOverHttps](INFO): SBD MOMSN=16391282
2021-12-15T16:52:04.764Z,1639587124.764 [Startup:StartupSatComms:B](INFO): Timed out from 2021-12-15T16:51:04.4Z
2021-12-15T16:52:04.764Z,1639587124.764 [Startup:StartupSatComms:B] Stopped
2021-12-15T16:52:04.764Z,1639587124.764 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2021-12-15T16:52:04.764Z,1639587124.764 [Startup:StartupSatComms] Stopped
2021-12-15T16:52:04.764Z,1639587124.764 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2021-12-15T16:52:04.765Z,1639587124.765 [Startup](INFO): Completed Startup
2021-12-15T16:52:04.765Z,1639587124.765 [MissionManager](INFO): Startup is completed.
2021-12-15T16:52:04.766Z,1639587124.766 [MissionManager](INFO): Uninitializing Mission Startup
2021-12-15T16:52:04.766Z,1639587124.766 [Startup] Stopped
2021-12-15T16:52:04.767Z,1639587124.767 [Startup](DEBUG): Aggregate::uninitialize Startup
2021-12-15T16:52:04.767Z,1639587124.767 [Startup:A.GoToSurface] Stopped
2021-12-15T16:52:04.767Z,1639587124.767 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-12-15T16:52:05.179Z,1639587125.179 [MissionManager](IMPORTANT): Started mission Default
2021-12-15T16:52:05.180Z,1639587125.180 [Default] Running Loop=1
2021-12-15T16:52:05.180Z,1639587125.180 [Default](DEBUG): Aggregate::initialize Default
2021-12-15T16:52:05.180Z,1639587125.180 [Default:B.GoToSurface] Running Loop=1
2021-12-15T16:52:05.180Z,1639587125.180 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-12-15T16:52:05.180Z,1639587125.180 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-12-15T16:52:05.181Z,1639587125.181 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-12-15T16:52:05.181Z,1639587125.181 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-12-15T16:52:05.181Z,1639587125.181 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-12-15T16:52:05.182Z,1639587125.182 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-12-15T16:52:05.183Z,1639587125.183 [Default:A.Wait] Running Loop=1
2021-12-15T16:52:05.183Z,1639587125.183 [Default:A.Wait](DEBUG): Initialize Wait Component.
2021-12-15T16:52:10.055Z,1639587130.055 [DAT](INFO): DAT read: Rx Time:16:51:38.5842

2021-12-15T16:52:10.055Z,1639587130.055 [DAT](INFO): received an acoustic signal
2021-12-15T16:52:10.563Z,1639587130.563 [DAT](INFO): DAT read: 16:51:38.5842 LVL= 29920, 25585, 26290, 32755, AGC= 81, IDX= 446, 0.06,-1.982,-2.173,-1.953,-2.334, PHS= 0.321, 0.134, 0.377, RAW= 162.6, -53.1, CAL= 164.8, -55.5, ROT=  45.2,  55.5

2021-12-15T16:52:10.564Z,1639587130.564 [DAT](INFO): got valid direction response:
 16:51:38.5842 LVL= 29920, 25585, 26290, 32755, AGC= 81, IDX= 446, 0.06,-1.982,-2.173,-1.953,-2.334, PHS= 0.321, 0.134, 0.377, RAW= 162.6, -53.1, CAL= 164.8, -55.5, ROT=  45.2,  55.5

2021-12-15T16:52:10.565Z,1639587130.565 [DAT](INFO): DAT read: bearing request

2021-12-15T16:52:10.565Z,1639587130.565 [DAT](INFO): received a bearing request message
2021-12-15T16:52:10.567Z,1639587130.567 [DAT](INFO): DAT read: Tx time:16:51:40.1871

2021-12-15T16:52:10.567Z,1639587130.567 [DAT](INFO): Ping request sent.
2021-12-15T16:52:10.567Z,1639587130.567 [DAT](INFO): transmitted an acoustic signal
2021-12-15T16:52:10.567Z,1639587130.567 [DAT](INFO): #Rx 4: Read direction message, but no range.
2021-12-15T16:52:10.568Z,1639587130.568 [DAT](INFO): direction in vehicle frame: [ 0.399109 forward, 0.401905 starboard, 0.824126 keelward ]
2021-12-15T16:52:10.569Z,1639587130.569 [DAT](INFO): publishing transmit ping time
2021-12-15T16:52:10.569Z,1639587130.569 [DAT](INFO): publishing range request flag
2021-12-15T16:52:10.572Z,1639587130.572 [DAT](INFO): publishing transmit ping time
2021-12-15T16:52:10.572Z,1639587130.572 [DAT](INFO): publishing range request flag
2021-12-15T16:52:13.775Z,1639587133.775 [DataOverHttps](INFO): Sending 956 bytes from file Logs/20211215T164819/Express0001.lzma
2021-12-15T16:52:14.776Z,1639587134.776 [DataOverHttps](INFO): Moved sent file to Logs/20211215T164819/Express0001.lzma.bak
2021-12-15T16:52:14.776Z,1639587134.776 [DataOverHttps](INFO): SBD MOMSN=16391287
2021-12-15T16:52:18.512Z,1639587138.512 [Default:A.Wait](INFO): Done Waiting.
2021-12-15T16:52:18.512Z,1639587138.512 [Default:A.Wait] Stopped
2021-12-15T16:52:18.512Z,1639587138.512 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2021-12-15T16:52:18.924Z,1639587138.924 [Default:CheckIn] Running Loop=1
2021-12-15T16:52:18.925Z,1639587138.925 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-12-15T16:52:18.925Z,1639587138.925 [Default:CheckIn:Read_GPS] Running Loop=1
2021-12-15T16:52:19.317Z,1639587139.317 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2021-12-15T16:53:07.430Z,1639587187.430 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-12-15T16:53:10.071Z,1639587190.071 [DAT](INFO): DAT read: Rx Time:16:52:38.5850

2021-12-15T16:53:10.071Z,1639587190.071 [DAT](INFO): received an acoustic signal
2021-12-15T16:53:10.579Z,1639587190.579 [DAT](INFO): DAT read: 16:52:38.5850 LVL= 26608, 24929, 27378, 32755, AGC= 83, IDX= 187,-0.41, 2.974, 2.875, 2.894, 2.648, PHS= 0.294, 0.200, 0.241, RAW= 116.2, -72.5, CAL= 116.2, -73.1, ROT=  93.8,  73.1

2021-12-15T16:53:10.581Z,1639587190.581 [DAT](INFO): got valid direction response:
 16:52:38.5850 LVL= 26608, 24929, 27378, 32755, AGC= 83, IDX= 187,-0.41, 2.974, 2.875, 2.894, 2.648, PHS= 0.294, 0.200, 0.241, RAW= 116.2, -72.5, CAL= 116.2, -73.1, ROT=  93.8,  73.1

2021-12-15T16:53:10.581Z,1639587190.581 [DAT](INFO): DAT read: bearing request

2021-12-15T16:53:10.581Z,1639587190.581 [DAT](INFO): received a bearing request message
2021-12-15T16:53:10.582Z,1639587190.582 [DAT](INFO): DAT read: Tx time:16:52:40.1878

2021-12-15T16:53:10.582Z,1639587190.582 [DAT](INFO): Ping request sent.
2021-12-15T16:53:10.582Z,1639587190.582 [DAT](INFO): transmitted an acoustic signal
2021-12-15T16:53:10.583Z,1639587190.583 [DAT](INFO): #Rx 5: Read direction message, but no range.
2021-12-15T16:53:10.584Z,1639587190.584 [DAT](INFO): direction in vehicle frame: [ -0.019266 forward, 0.290063 starboard, 0.956814 keelward ]
2021-12-15T16:53:10.584Z,1639587190.584 [DAT](INFO): publishing transmit ping time
2021-12-15T16:53:10.585Z,1639587190.585 [DAT](INFO): publishing range request flag
2021-12-15T16:53:10.593Z,1639587190.593 [DAT](INFO): publishing transmit ping time
2021-12-15T16:53:10.593Z,1639587190.593 [DAT](INFO): publishing range request flag
2021-12-15T16:53:17.947Z,1639587197.947 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-12-15T16:53:29.270Z,1639587209.270 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-12-15T16:53:40.568Z,1639587220.568 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-12-15T16:53:51.480Z,1639587231.480 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-12-15T16:54:02.039Z,1639587242.039 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-12-15T16:54:10.107Z,1639587250.107 [DAT](INFO): DAT read: Rx Time:16:53:38.6358

2021-12-15T16:54:10.107Z,1639587250.107 [DAT](INFO): received an acoustic signal
2021-12-15T16:54:10.615Z,1639587250.615 [DAT](INFO): DAT read: 16:53:38.6358 LVL= 17632, 18033, 17282, 25955, AGC= 80, IDX= 183, 0.13,-1.510,-1.686,-1.537,-1.840, PHS= 0.299, 0.127, 0.299, RAW= 150.0, -56.1, CAL= 150.5, -58.2, ROT=  59.5,  58.2

2021-12-15T16:54:10.616Z,1639587250.616 [DAT](INFO): got valid direction response:
 16:53:38.6358 LVL= 17632, 18033, 17282, 25955, AGC= 80, IDX= 183, 0.13,-1.510,-1.686,-1.537,-1.840, PHS= 0.299, 0.127, 0.299, RAW= 150.0, -56.1, CAL= 150.5, -58.2, ROT=  59.5,  58.2

2021-12-15T16:54:10.617Z,1639587250.617 [DAT](INFO): DAT read: bearing request

2021-12-15T16:54:10.617Z,1639587250.617 [DAT](INFO): received a bearing request message
2021-12-15T16:54:10.618Z,1639587250.618 [DAT](INFO): DAT read: Tx time:16:53:40.2386

2021-12-15T16:54:10.618Z,1639587250.618 [DAT](INFO): Ping request sent.
2021-12-15T16:54:10.618Z,1639587250.618 [DAT](INFO): transmitted an acoustic signal
2021-12-15T16:54:10.619Z,1639587250.619 [DAT](INFO): #Rx 6: Read direction message, but no range.
2021-12-15T16:54:10.620Z,1639587250.620 [DAT](INFO): direction in vehicle frame: [ 0.267450 forward, 0.454040 starboard, 0.849893 keelward ]
2021-12-15T16:54:10.620Z,1639587250.620 [DAT](INFO): publishing transmit ping time
2021-12-15T16:54:10.620Z,1639587250.620 [DAT](INFO): publishing range request flag
2021-12-15T16:54:10.623Z,1639587250.623 [DAT](INFO): publishing transmit ping time
2021-12-15T16:54:10.623Z,1639587250.623 [DAT](INFO): publishing range request flag
2021-12-15T16:54:12.819Z,1639587252.819 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-12-15T16:54:13.301Z,1639587253.301 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-12-15T16:54:24.609Z,1639587264.609 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-12-15T16:54:30.631Z,1639587270.631 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2021-12-15T16:54:30.631Z,1639587270.631 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-12-15T16:54:30.632Z,1639587270.632 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2
2021-12-15T16:54:30.632Z,1639587270.632 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2021-12-15T16:54:30.644Z,1639587270.644 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-12-15T16:54:30.644Z,1639587270.644 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2021-12-15T16:54:31.017Z,1639587271.017 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-12-15T16:54:31.017Z,1639587271.017 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2021-12-15T16:54:31.017Z,1639587271.017 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2021-12-15T16:54:31.017Z,1639587271.017 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2
2021-12-15T16:54:31.438Z,1639587271.438 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2021-12-15T16:54:35.924Z,1639587275.924 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-12-15T16:54:43.186Z,1639587283.186 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-12-15T16:54:46.824Z,1639587286.824 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-12-15T16:54:57.807Z,1639587297.807 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-12-15T16:55:08.698Z,1639587308.698 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-12-15T16:55:19.556Z,1639587319.556 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-12-15T16:55:35.849Z,1639587335.849 [CommandExec](IMPORTANT): got command restart application
2021-12-15T16:55:36.852Z,1639587336.852 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2021-12-15T16:55:36.852Z,1639587336.852 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-15T16:55:36.852Z,1639587336.852 [CommandExec](INFO): Uninitializing the command executive.
2021-12-15T16:55:36.852Z,1639587336.852 [CommandExec](INFO): Uninitializing the command scheduler.
2021-12-15T16:55:36.853Z,1639587336.853 [CommandExec ThreadHandler](INFO): Thread cancelled.
2021-12-15T16:55:36.976Z,1639587336.976 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2021-12-15T16:55:36.976Z,1639587336.976 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2021-12-15T16:55:36.976Z,1639587336.976 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-12-15T16:55:36.977Z,1639587336.977 [NavChartDb](INFO): Join timeout helper Thread ID is 9099
2021-12-15T16:55:37.024Z,1639587337.024 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-15T16:55:37.024Z,1639587337.024 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-12-15T16:55:37.040Z,1639587337.040 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler
2021-12-15T16:55:37.040Z,1639587337.040 [DAT ThreadHandler](INFO): Thread cancelled.
2021-12-15T16:55:37.040Z,1639587337.040 [DAT](INFO): Join timeout helper Thread ID is 9100
2021-12-15T16:55:37.084Z,1639587337.084 [DAT](INFO): Powering down
2021-12-15T16:55:37.156Z,1639587337.156 [DAT ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-15T16:55:37.156Z,1639587337.156 [DAT](INFO): Powering down
2021-12-15T16:55:37.157Z,1639587337.157 [DAT ThreadHandler](INFO): Thread cancelled.
2021-12-15T16:55:37.160Z,1639587337.160 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2021-12-15T16:55:37.160Z,1639587337.160 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-12-15T16:55:37.160Z,1639587337.160 [Radio_Surface](INFO): Join timeout helper Thread ID is 9101
2021-12-15T16:55:37.400Z,1639587337.400 [Radio_Surface](INFO): Powering down
2021-12-15T16:55:37.401Z,1639587337.401 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-15T16:55:37.401Z,1639587337.401 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-12-15T16:55:37.408Z,1639587337.408 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2021-12-15T16:55:37.408Z,1639587337.408 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-12-15T16:55:37.408Z,1639587337.408 [Onboard](INFO): Join timeout helper Thread ID is 9102
2021-12-15T16:55:37.469Z,1639587337.469 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2021-12-15T16:55:39.664Z,1639587339.664 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-15T16:55:39.664Z,1639587339.664 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-12-15T16:55:39.676Z,1639587339.676 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2021-12-15T16:55:39.676Z,1639587339.676 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-12-15T16:55:39.676Z,1639587339.676 [DataOverHttps](INFO): Join timeout helper Thread ID is 9103
2021-12-15T16:55:40.480Z,1639587340.480 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-15T16:55:40.480Z,1639587340.480 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-12-15T16:55:40.482Z,1639587340.482 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2021-12-15T16:55:40.482Z,1639587340.482 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2021-12-15T16:55:40.482Z,1639587340.482 [BackseatComponent](INFO): Join timeout helper Thread ID is 9104
2021-12-15T16:55:40.584Z,1639587340.584 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-15T16:55:40.584Z,1639587340.584 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2021-12-15T16:55:40.593Z,1639587340.593 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2021-12-15T16:55:40.593Z,1639587340.593 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2021-12-15T16:55:40.593Z,1639587340.593 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 9105
2021-12-15T16:55:41.024Z,1639587341.024 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-15T16:55:41.024Z,1639587341.024 [WetLabsBB2FL](INFO): Powering down
2021-12-15T16:55:41.025Z,1639587341.025 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2021-12-15T16:55:41.028Z,1639587341.028 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2021-12-15T16:55:41.029Z,1639587341.029 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-12-15T16:55:41.029Z,1639587341.029 [CTD_Seabird](INFO): Join timeout helper Thread ID is 9106
2021-12-15T16:55:41.152Z,1639587341.152 [CTD_Seabird](INFO): Powering down
2021-12-15T16:55:41.164Z,1639587341.164 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-15T16:55:41.164Z,1639587341.164 [CTD_Seabird](INFO): Powering down
2021-12-15T16:55:41.176Z,1639587341.176 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-12-15T16:55:41.192Z,1639587341.192 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2021-12-15T16:55:41.193Z,1639587341.193 [logger ThreadHandler](INFO): Thread cancelled.
2021-12-15T16:55:41.193Z,1639587341.193 [logger](INFO): Join timeout helper Thread ID is 9107
2021-12-15T16:55:41.204Z,1639587341.204 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-15T16:55:41.204Z,1639587341.204 [logger ThreadHandler](INFO): Thread cancelled.
2021-12-15T16:55:41.212Z,1639587341.212 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2021-12-15T16:55:41.213Z,1639587341.213 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-12-15T16:55:41.213Z,1639587341.213 [CommandLine](INFO): Join timeout helper Thread ID is 9108
2021-12-15T16:55:41.268Z,1639587341.268 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-15T16:55:41.268Z,1639587341.268 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-12-15T16:55:41.273Z,1639587341.273 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2021-12-15T16:55:41.273Z,1639587341.273 [CommandExec ThreadHandler](INFO): Thread cancelled.
2021-12-15T16:55:41.273Z,1639587341.273 [CommandExec](INFO): Join timeout helper Thread ID is 9109
2021-12-15T16:55:41.281Z,1639587341.281 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2021-12-15T16:55:41.281Z,1639587341.281 [controlThread ThreadHandler](INFO): Thread cancelled.
2021-12-15T16:55:41.281Z,1639587341.281 [controlThread](INFO): Join timeout helper Thread ID is 9110
2021-12-15T16:55:41.301Z,1639587341.301 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-15T16:55:41.301Z,1639587341.301 [controlThread](DEBUG): Uninitializing ControlThread
2021-12-15T16:55:41.302Z,1639587341.302 [AHRS_M2](INFO): Powering down
2021-12-15T16:55:41.373Z,1639587341.373 [NAL9602](INFO): Powering down
2021-12-15T16:55:41.375Z,1639587341.375 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2021-12-15T16:55:41.376Z,1639587341.376 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2021-12-15T16:55:41.377Z,1639587341.377 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2021-12-15T16:55:41.377Z,1639587341.377 [MissionManager](INFO): Uninitializing Mission Default
2021-12-15T16:55:41.377Z,1639587341.377 [Default] Stopped
2021-12-15T16:55:41.377Z,1639587341.377 [Default](DEBUG): Aggregate::uninitialize Default
2021-12-15T16:55:41.377Z,1639587341.377 [Default:B.GoToSurface] Stopped
2021-12-15T16:55:41.378Z,1639587341.378 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-12-15T16:55:41.378Z,1639587341.378 [Default:CheckIn] Stopped
2021-12-15T16:55:41.378Z,1639587341.378 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-12-15T16:55:41.378Z,1639587341.378 [Default:CheckIn:Read_GPS] Stopped
2021-12-15T16:55:41.381Z,1639587341.381 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2021-12-15T16:55:41.381Z,1639587341.381 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2021-12-15T16:55:41.382Z,1639587341.382 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2021-12-15T16:55:41.382Z,1639587341.382 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2021-12-15T16:55:41.382Z,1639587341.382 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2021-12-15T16:55:41.382Z,1639587341.382 [BuoyancyServo](INFO): Powering down
2021-12-15T16:55:41.396Z,1639587341.396 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2021-12-15T16:55:41.396Z,1639587341.396 [ElevatorServo](INFO): Powering down
2021-12-15T16:55:41.397Z,1639587341.397 [MassServo](DEBUG): Uninitialize Mass Servo.
2021-12-15T16:55:41.397Z,1639587341.397 [MassServo](INFO): Powering down
2021-12-15T16:55:41.398Z,1639587341.398 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2021-12-15T16:55:41.398Z,1639587341.398 [RudderServo](INFO): Powering down
2021-12-15T16:55:41.399Z,1639587341.399 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2021-12-15T16:55:41.399Z,1639587341.399 [ThrusterHE](INFO): Powering down
2021-12-15T16:55:41.400Z,1639587341.400 [SBIT](DEBUG): Uninitialize SBIT Component.
2021-12-15T16:55:41.400Z,1639587341.400 [IBIT](DEBUG): Uninitialize IBIT Component.
2021-12-15T16:55:41.401Z,1639587341.401 [CBIT](DEBUG): Uninitialize CBIT Component.
2021-12-15T16:55:41.401Z,1639587341.401 [CBIT](DEBUG): Powering off loads.
2021-12-15T16:55:41.412Z,1639587341.412 [CBIT](DEBUG): Disabling WDT.
2021-12-15T16:55:41.424Z,1639587341.424 [CBIT](DEBUG): Opening all GF detection circuits.
2021-12-15T16:55:41.425Z,1639587341.425 [controlThread ThreadHandler](INFO): Thread cancelled.
2021-12-15T16:55:41.465Z,1639587341.465 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2021-12-15T16:55:41.470Z,1639587341.470 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-12-15T16:55:41.574Z,1639587341.574 [DAT ThreadHandler](INFO): Thread cancelled.
2021-12-15T16:55:41.579Z,1639587341.579 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-12-15T16:55:41.581Z,1639587341.581 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-12-15T16:55:41.587Z,1639587341.587 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-12-15T16:55:41.631Z,1639587341.631 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2021-12-15T16:55:41.670Z,1639587341.670 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-12-15T16:55:41.734Z,1639587341.734 [logger ThreadHandler](INFO): Thread cancelled.