2022-05-06T21:16:31.345Z,1651871791.345 [Supervisor](DEBUG): Initializing supervisor.
2022-05-06T21:16:31.349Z,1651871791.349 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2022-05-06T21:16:31.350Z,1651871791.350 [SyncHandler](INFO): Protected caller Thread ID is 1704
2022-05-06T21:16:31.350Z,1651871791.350 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2022-05-06T21:16:31.351Z,1651871791.351 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2022-05-06T21:16:31.351Z,1651871791.351 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1705
2022-05-06T21:16:31.355Z,1651871791.355 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2022-05-06T21:16:31.373Z,1651871791.373 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2022-05-06T21:16:31.374Z,1651871791.374 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2022-05-06T21:16:31.375Z,1651871791.375 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 1706
2022-05-06T21:16:31.379Z,1651871791.379 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2022-05-06T21:16:31.380Z,1651871791.380 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2022-05-06T21:16:31.380Z,1651871791.380 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1707
2022-05-06T21:16:31.382Z,1651871791.382 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2022-05-06T21:16:31.383Z,1651871791.383 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2022-05-06T21:16:31.383Z,1651871791.383 [logger ThreadHandler](INFO): Protected caller Thread ID is 1708
2022-05-06T21:16:31.387Z,1651871791.387 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2022-05-06T21:16:31.387Z,1651871791.387 [Supervisor](INFO): Looking for Config files in directory: Config/
2022-05-06T21:16:31.389Z,1651871791.389 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2022-05-06T21:16:31.766Z,1651871791.766 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2022-05-06T21:16:31.766Z,1651871791.766 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2022-05-06T21:16:32.409Z,1651871792.409 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2022-05-06T21:16:32.410Z,1651871792.410 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2022-05-06T21:16:32.516Z,1651871792.516 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2022-05-06T21:16:32.517Z,1651871792.517 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2022-05-06T21:16:33.143Z,1651871793.143 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2022-05-06T21:16:33.144Z,1651871793.144 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2022-05-06T21:16:33.239Z,1651871793.239 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2022-05-06T21:16:33.240Z,1651871793.240 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2022-05-06T21:16:33.319Z,1651871793.319 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2022-05-06T21:16:33.925Z,1651871793.925 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2022-05-06T21:16:33.926Z,1651871793.926 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2022-05-06T21:16:34.141Z,1651871794.141 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2022-05-06T21:16:34.142Z,1651871794.142 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2022-05-06T21:16:34.267Z,1651871794.267 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2022-05-06T21:16:34.267Z,1651871794.267 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2022-05-06T21:16:34.488Z,1651871794.488 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2022-05-06T21:16:34.489Z,1651871794.489 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2022-05-06T21:16:34.958Z,1651871794.958 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2022-05-06T21:16:34.959Z,1651871794.959 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2022-05-06T21:16:35.314Z,1651871795.314 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2022-05-06T21:16:35.314Z,1651871795.314 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2022-05-06T21:16:35.393Z,1651871795.393 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2022-05-06T21:16:35.583Z,1651871795.583 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2022-05-06T21:16:35.584Z,1651871795.584 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2022-05-06T21:16:35.801Z,1651871795.801 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2022-05-06T21:16:35.801Z,1651871795.801 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2022-05-06T21:16:36.095Z,1651871796.095 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2022-05-06T21:16:36.097Z,1651871796.097 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-brizo/
2022-05-06T21:16:36.098Z,1651871796.098 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Control.cfg
2022-05-06T21:16:36.204Z,1651871796.204 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Sensor.cfg
2022-05-06T21:16:36.346Z,1651871796.346 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Simulator.cfg
2022-05-06T21:16:36.430Z,1651871796.430 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/secure.cfg
2022-05-06T21:16:36.512Z,1651871796.512 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Servo.cfg
2022-05-06T21:16:36.622Z,1651871796.622 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/vehicle.cfg
2022-05-06T21:16:36.794Z,1651871796.794 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Battery.cfg
2022-05-06T21:16:37.057Z,1651871797.057 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2022-05-06T21:16:37.058Z,1651871797.058 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Science.cfg
2022-05-06T21:16:37.187Z,1651871797.187 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/logger.cfg
2022-05-06T21:16:37.279Z,1651871797.279 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/BIT.cfg
2022-05-06T21:16:37.381Z,1651871797.381 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Navigation.cfg
2022-05-06T21:16:37.480Z,1651871797.480 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-brizo/root/
2022-05-06T21:16:37.480Z,1651871797.480 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2022-05-06T21:16:37.491Z,1651871797.491 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2022-05-06T21:16:37.591Z,1651871797.591 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2022-05-06T21:16:37.592Z,1651871797.592 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2022-05-06T21:16:37.602Z,1651871797.602 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2022-05-06T21:16:37.603Z,1651871797.603 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2022-05-06T21:16:37.656Z,1651871797.656 [DepthRateCalculator] Loaded
2022-05-06T21:16:37.656Z,1651871797.656 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2022-05-06T21:16:37.661Z,1651871797.661 [PitchRateCalculator] Loaded
2022-05-06T21:16:37.662Z,1651871797.662 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2022-05-06T21:16:37.672Z,1651871797.672 [SpeedCalculator] Loaded
2022-05-06T21:16:37.672Z,1651871797.672 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2022-05-06T21:16:37.677Z,1651871797.677 [YawRateCalculator] Loaded
2022-05-06T21:16:37.677Z,1651871797.677 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2022-05-06T21:16:37.697Z,1651871797.697 [ElevatorOffsetCalculator] Loaded
2022-05-06T21:16:37.698Z,1651871797.698 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2022-05-06T21:16:37.698Z,1651871797.698 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2022-05-06T21:16:37.699Z,1651871797.699 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2022-05-06T21:16:37.751Z,1651871797.751 [VerticalControl](DEBUG): Construct VerticalControl.
2022-05-06T21:16:37.806Z,1651871797.806 [VerticalControl] Loaded
2022-05-06T21:16:37.806Z,1651871797.806 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2022-05-06T21:16:37.809Z,1651871797.809 [HorizontalControl](DEBUG): Construct HorizontalControl.
2022-05-06T21:16:37.847Z,1651871797.847 [HorizontalControl] Loaded
2022-05-06T21:16:37.847Z,1651871797.847 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2022-05-06T21:16:37.850Z,1651871797.850 [SpeedControl](DEBUG): Construct SpeedControl.
2022-05-06T21:16:37.853Z,1651871797.853 [SpeedControl] Loaded
2022-05-06T21:16:37.853Z,1651871797.853 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2022-05-06T21:16:37.855Z,1651871797.855 [LoopControl](DEBUG): Construct LoopControl.
2022-05-06T21:16:37.856Z,1651871797.856 [LoopControl] Loaded
2022-05-06T21:16:37.856Z,1651871797.856 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2022-05-06T21:16:37.856Z,1651871797.856 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2022-05-06T21:16:37.857Z,1651871797.857 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2022-05-06T21:16:37.967Z,1651871797.967 [DeadReckonUsingMultipleVelocitySources] Loaded
2022-05-06T21:16:37.967Z,1651871797.967 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2022-05-06T21:16:37.980Z,1651871797.980 [NavChart] Loaded
2022-05-06T21:16:37.981Z,1651871797.981 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2022-05-06T21:16:37.986Z,1651871797.986 [UniversalFixResidualReporter] Loaded
2022-05-06T21:16:37.987Z,1651871797.987 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2022-05-06T21:16:37.987Z,1651871797.987 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2022-05-06T21:16:37.988Z,1651871797.988 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2022-05-06T21:16:38.097Z,1651871798.097 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2022-05-06T21:16:38.098Z,1651871798.098 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2022-05-06T21:16:38.496Z,1651871798.496 [AHRS_M2] Loaded
2022-05-06T21:16:38.496Z,1651871798.496 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2022-05-06T21:16:38.531Z,1651871798.531 [BackseatComponent] Loaded
2022-05-06T21:16:38.531Z,1651871798.531 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2022-05-06T21:16:38.533Z,1651871798.533 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408DD4E0
2022-05-06T21:16:38.533Z,1651871798.533 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 1791
2022-05-06T21:16:38.535Z,1651871798.535 [LcmUniversalReporter] Loaded
2022-05-06T21:16:38.536Z,1651871798.536 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2022-05-06T21:16:38.610Z,1651871798.610 [DataOverHttps] Loaded
2022-05-06T21:16:38.610Z,1651871798.610 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2022-05-06T21:16:38.611Z,1651871798.611 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4090D4E0
2022-05-06T21:16:38.611Z,1651871798.611 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1792
2022-05-06T21:16:38.631Z,1651871798.631 [Depth_Keller] Loaded
2022-05-06T21:16:38.631Z,1651871798.631 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2022-05-06T21:16:38.636Z,1651871798.636 [DropWeight] Loaded
2022-05-06T21:16:38.636Z,1651871798.636 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2022-05-06T21:16:38.672Z,1651871798.672 [DVL_micro] Loaded
2022-05-06T21:16:38.673Z,1651871798.673 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2022-05-06T21:16:38.732Z,1651871798.732 [NAL9602] Loaded
2022-05-06T21:16:38.732Z,1651871798.732 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2022-05-06T21:16:38.761Z,1651871798.761 [Onboard] Loaded
2022-05-06T21:16:38.761Z,1651871798.761 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2022-05-06T21:16:38.762Z,1651871798.762 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4093D4E0
2022-05-06T21:16:38.762Z,1651871798.762 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 1793
2022-05-06T21:16:38.774Z,1651871798.774 [Power24vConverter] Loaded
2022-05-06T21:16:38.774Z,1651871798.774 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2022-05-06T21:16:38.787Z,1651871798.787 [Radio_Surface] Loaded
2022-05-06T21:16:38.787Z,1651871798.787 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2022-05-06T21:16:38.788Z,1651871798.788 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4096D4E0
2022-05-06T21:16:38.788Z,1651871798.788 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1794
2022-05-06T21:16:38.874Z,1651871798.874 [DAT] Loaded
2022-05-06T21:16:38.874Z,1651871798.874 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2022-05-06T21:16:38.875Z,1651871798.875 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 4099D4E0
2022-05-06T21:16:38.876Z,1651871798.876 [DAT ThreadHandler](INFO): Protected caller Thread ID is 1795
2022-05-06T21:16:38.876Z,1651871798.876 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2022-05-06T21:16:38.877Z,1651871798.877 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2022-05-06T21:16:39.003Z,1651871799.003 [BuoyancyServo] Loaded
2022-05-06T21:16:39.003Z,1651871799.003 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2022-05-06T21:16:39.023Z,1651871799.023 [ElevatorServo] Loaded
2022-05-06T21:16:39.023Z,1651871799.023 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2022-05-06T21:16:39.042Z,1651871799.042 [MassServo] Loaded
2022-05-06T21:16:39.042Z,1651871799.042 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2022-05-06T21:16:39.060Z,1651871799.060 [RudderServo] Loaded
2022-05-06T21:16:39.060Z,1651871799.060 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2022-05-06T21:16:39.075Z,1651871799.075 [ThrusterHE] Loaded
2022-05-06T21:16:39.075Z,1651871799.075 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2022-05-06T21:16:39.076Z,1651871799.076 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2022-05-06T21:16:39.076Z,1651871799.076 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2022-05-06T21:16:39.209Z,1651871799.209 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2022-05-06T21:16:39.210Z,1651871799.210 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2022-05-06T21:16:39.269Z,1651871799.269 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2022-05-06T21:16:39.270Z,1651871799.270 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2022-05-06T21:16:39.974Z,1651871799.974 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2022-05-06T21:16:39.974Z,1651871799.974 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2022-05-06T21:16:40.146Z,1651871800.146 [CTD_Seabird] Loaded
2022-05-06T21:16:40.146Z,1651871800.146 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2022-05-06T21:16:40.147Z,1651871800.147 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40B394E0
2022-05-06T21:16:40.147Z,1651871800.147 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1796
2022-05-06T21:16:40.179Z,1651871800.179 [ESPComponent] Loaded
2022-05-06T21:16:40.179Z,1651871800.179 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2022-05-06T21:16:40.199Z,1651871800.199 [PAR_Licor] Loaded
2022-05-06T21:16:40.199Z,1651871800.199 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2022-05-06T21:16:40.230Z,1651871800.230 [WetLabsBB2FL] Loaded
2022-05-06T21:16:40.230Z,1651871800.230 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2022-05-06T21:16:40.231Z,1651871800.231 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40B694E0
2022-05-06T21:16:40.231Z,1651871800.231 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1797
2022-05-06T21:16:40.232Z,1651871800.232 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2022-05-06T21:16:40.233Z,1651871800.233 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2022-05-06T21:16:40.377Z,1651871800.377 [SBIT](DEBUG): Construct Startup Built In Test.
2022-05-06T21:16:40.386Z,1651871800.386 [SBIT] Loaded
2022-05-06T21:16:40.386Z,1651871800.386 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2022-05-06T21:16:40.389Z,1651871800.389 [IBIT](DEBUG): Construct Initiated Built In Test.
2022-05-06T21:16:40.402Z,1651871800.402 [IBIT] Loaded
2022-05-06T21:16:40.402Z,1651871800.402 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2022-05-06T21:16:40.408Z,1651871800.408 [CBIT](DEBUG): Construct Continuous Built In Test.
2022-05-06T21:16:40.635Z,1651871800.635 [CBIT] Loaded
2022-05-06T21:16:40.635Z,1651871800.635 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2022-05-06T21:16:40.635Z,1651871800.635 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2022-05-06T21:16:40.642Z,1651871800.642 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2022-05-06T21:16:40.644Z,1651871800.644 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2022-05-06T21:16:40.655Z,1651871800.655 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2022-05-06T21:16:40.656Z,1651871800.656 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BD74E0
2022-05-06T21:16:40.656Z,1651871800.656 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1798
2022-05-06T21:16:40.661Z,1651871800.661 [Supervisor](INFO): Main Thread ID is 1703
2022-05-06T21:16:40.661Z,1651871800.661 [Supervisor](DEBUG): Running supervisor.
2022-05-06T21:16:40.661Z,1651871800.661 [CommandExec ThreadHandler](INFO): Handler Thread ID is 1799
2022-05-06T21:16:40.662Z,1651871800.662 [CommandExec](INFO): Initializing the command executive.
2022-05-06T21:16:40.663Z,1651871800.663 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1800
2022-05-06T21:16:40.665Z,1651871800.665 [controlThread ThreadHandler](INFO): Handler Thread ID is 1801
2022-05-06T21:16:40.666Z,1651871800.666 [controlThread](DEBUG): Initializing ControlThread
2022-05-06T21:16:40.667Z,1651871800.667 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2022-05-06T21:16:40.667Z,1651871800.667 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2022-05-06T21:16:40.667Z,1651871800.667 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2022-05-06T21:16:40.668Z,1651871800.668 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2022-05-06T21:16:40.669Z,1651871800.669 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2022-05-06T21:16:40.669Z,1651871800.669 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2022-05-06T21:16:40.671Z,1651871800.671 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2022-05-06T21:16:40.671Z,1651871800.671 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2022-05-06T21:16:40.672Z,1651871800.672 [LoopControl](DEBUG): Initialize LoopControlComponent.
2022-05-06T21:16:40.673Z,1651871800.673 [NavChart](DEBUG): Initialize NavChart Navigation.
2022-05-06T21:16:40.673Z,1651871800.673 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2022-05-06T21:16:40.680Z,1651871800.680 [SBIT](INFO): Initialize SBIT Component.
2022-05-06T21:16:40.681Z,1651871800.681 [SBIT](IMPORTANT): git: 2022-04-25-37-g2a944135f
2022-05-06T21:16:40.681Z,1651871800.681 [SBIT](INFO): git hash: 2a944135f4713de004d013a6b17eee164aec7a5a
2022-05-06T21:16:40.681Z,1651871800.681 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2022-05-06T21:16:40.682Z,1651871800.682 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Tue Sep 24 11:12:27 PDT 2019
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2022-05-06T21:16:40.683Z,1651871800.683 [SBIT](INFO): Beginning SBIT in 20.000000 seconds.
2022-05-06T21:16:40.684Z,1651871800.684 [IBIT](INFO): Initialize IBIT Component.
2022-05-06T21:16:40.685Z,1651871800.685 [CBIT](DEBUG): Initialize CBIT Component.
2022-05-06T21:16:40.686Z,1651871800.686 [logger ThreadHandler](INFO): Handler Thread ID is 1802
2022-05-06T21:16:40.696Z,1651871800.696 [CBIT](DEBUG): Initialized mux pins.
2022-05-06T21:16:40.696Z,1651871800.696 [CBIT](DEBUG): Initializing the watchdog timer.
2022-05-06T21:16:40.704Z,1651871800.704 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 1803
2022-05-06T21:16:40.716Z,1651871800.716 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1804
2022-05-06T21:16:40.717Z,1651871800.717 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2022-05-06T21:16:40.720Z,1651871800.720 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2022-05-06T21:16:40.721Z,1651871800.721 [CBIT](DEBUG): Initializing heartbeat.
2022-05-06T21:16:40.728Z,1651871800.728 [Onboard ThreadHandler](INFO): Handler Thread ID is 1805
2022-05-06T21:16:40.746Z,1651871800.746 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1806
2022-05-06T21:16:40.765Z,1651871800.765 [DAT ThreadHandler](INFO): Handler Thread ID is 1807
2022-05-06T21:16:40.766Z,1651871800.766 [DAT](INFO): Powering up
2022-05-06T21:16:40.766Z,1651871800.766 [DAT](DEBUG): Initializing DAT.
2022-05-06T21:16:40.769Z,1651871800.769 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1809
2022-05-06T21:16:40.770Z,1651871800.770 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2022-05-06T21:16:40.773Z,1651871800.773 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1811
2022-05-06T21:16:40.776Z,1651871800.776 [WetLabsBB2FL](INFO): Powering up
2022-05-06T21:16:40.778Z,1651871800.778 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1813
2022-05-06T21:16:40.781Z,1651871800.781 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2022-05-06T21:16:40.786Z,1651871800.786 [NavChartDb](FAULT): Change detected in ENC collection. Wiping NavChart Directory
2022-05-06T21:16:40.792Z,1651871800.792 [CBIT](DEBUG): Deactivating GF circuits.
2022-05-06T21:16:40.792Z,1651871800.792 [CBIT](DEBUG): Deactivating emergency mode.
2022-05-06T21:16:40.828Z,1651871800.828 [CBIT](DEBUG): Backplane powered.
2022-05-06T21:16:40.829Z,1651871800.829 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2022-05-06T21:16:40.841Z,1651871800.841 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2022-05-06T21:16:40.866Z,1651871800.866 [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>


2022-05-06T21:16:40.867Z,1651871800.867 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2022-05-06T21:16:40.870Z,1651871800.870 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2022-05-06T21:16:40.871Z,1651871800.871 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US1WC07M.000
2022-05-06T21:16:40.872Z,1651871800.872 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2022-05-06T21:16:40.873Z,1651871800.873 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US2WC11M.000
2022-05-06T21:16:40.873Z,1651871800.873 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2022-05-06T21:16:40.875Z,1651871800.875 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US3CA52M.000
2022-05-06T21:16:40.875Z,1651871800.875 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2022-05-06T21:16:40.892Z,1651871800.892 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA50M.000
2022-05-06T21:16:40.893Z,1651871800.893 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA69M.000
2022-05-06T21:16:40.894Z,1651871800.894 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US3CA69M.000
2022-05-06T21:16:40.919Z,1651871800.919 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2022-05-06T21:16:40.936Z,1651871800.936 [Default:A.Wait](DEBUG): Construct Wait.
2022-05-06T21:16:40.939Z,1651871800.939 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2022-05-06T21:16:40.957Z,1651871800.957 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2022-05-06T21:16:40.963Z,1651871800.963 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2022-05-06T21:16:40.978Z,1651871800.978 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US5CA50M.000
2022-05-06T21:16:40.987Z,1651871800.987 [Default:E.Execute](DEBUG): Construct Execute.
2022-05-06T21:16:41.001Z,1651871801.001 [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>


2022-05-06T21:16:41.022Z,1651871801.022 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2022-05-06T21:16:41.032Z,1651871801.032 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2022-05-06T21:16:41.065Z,1651871801.065 [Depth_Keller](ERROR): Pressure reading out of range: 1829.595459 decibar
2022-05-06T21:16:41.073Z,1651871801.073 [Power24vConverter](INFO): Powering up.
2022-05-06T21:16:41.094Z,1651871801.094 [DepthRateCalculator](ERROR): Depth measurement is not active
2022-05-06T21:16:41.134Z,1651871801.134 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2022-05-06T21:16:41.148Z,1651871801.148 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2022-05-06T21:16:41.149Z,1651871801.149 [ElevatorServo](DEBUG): Initializing EZServoServo.
2022-05-06T21:16:41.152Z,1651871801.152 [Radio_Surface](INFO): Powering up
2022-05-06T21:16:41.172Z,1651871801.172 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2022-05-06T21:16:41.173Z,1651871801.173 [MassServo](DEBUG): Initializing EZServoServo.
2022-05-06T21:16:41.200Z,1651871801.200 [MassServo](DEBUG): Initializing MassServo.
2022-05-06T21:16:41.201Z,1651871801.201 [RudderServo](DEBUG): Initializing EZServoServo.
2022-05-06T21:16:41.208Z,1651871801.208 [RudderServo](DEBUG): Initializing RudderServo.
2022-05-06T21:16:41.209Z,1651871801.209 [ThrusterHE](DEBUG): Initializing EZServoServo.
2022-05-06T21:16:41.216Z,1651871801.216 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2022-05-06T21:16:41.454Z,1651871801.454 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2022-05-06T21:16:41.454Z,1651871801.454 [DropWeight] Hardware Fault, FailCount= 1
2022-05-06T21:16:41.454Z,1651871801.454 [DropWeight](ERROR): Hardware Fault
2022-05-06T21:16:41.489Z,1651871801.489 [CommandExec](FAULT): Scheduling is paused
2022-05-06T21:16:41.490Z,1651871801.490 [CBIT](INFO): Critical error at 20220506T211641
2022-05-06T21:16:41.490Z,1651871801.490 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2022-05-06T21:16:41.512Z,1651871801.512 [CBIT](ERROR): Hardware Fault in component: DropWeight
2022-05-06T21:16:41.513Z,1651871801.513 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2022-05-06T21:16:42.172Z,1651871802.172 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2022-05-06T21:16:42.172Z,1651871802.172 [RudderServo](FAULT): Rudder failed to initialize
2022-05-06T21:16:42.172Z,1651871802.172 [RudderServo] Communications Fault, FailCount= 1
2022-05-06T21:16:42.172Z,1651871802.172 [RudderServo](ERROR): Communications Fault
2022-05-06T21:16:42.174Z,1651871802.174 [CBIT](INFO): Critical error at 20220506T211641
2022-05-06T21:16:42.176Z,1651871802.176 [CBIT](ERROR): Communications Fault in component: RudderServo
2022-05-06T21:16:42.405Z,1651871802.405 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-05-06T21:16:42.405Z,1651871802.405 [RudderServo](INFO): Powering down
2022-05-06T21:16:43.068Z,1651871803.068 [RudderServo](DEBUG): Initializing EZServoServo.
2022-05-06T21:16:43.192Z,1651871803.192 [RudderServo](DEBUG): Initializing RudderServo.
2022-05-06T21:16:43.196Z,1651871803.196 [CBIT](INFO): Clearing failed state for component RudderServo
2022-05-06T21:16:43.197Z,1651871803.197 [RudderServo] No Fault, FailCount= 1
2022-05-06T21:16:43.396Z,1651871803.396 [WetLabsBB2FL](INFO): Powering down
2022-05-06T21:16:46.969Z,1651871806.969 [ThrusterHE](ERROR): Zero Speed Commanded.
2022-05-06T21:16:47.977Z,1651871807.977 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US5CA50M.000
2022-05-06T21:16:50.850Z,1651871810.850 [CBIT](CRITICAL): Environmental Failure. Press:14.710738 PSI. Humidity:48%. Temp:22 C. ABORTING MISSION
2022-05-06T21:16:51.187Z,1651871811.187 [CBIT](INFO): Critical error at 20220506T211650
2022-05-06T21:16:53.078Z,1651871813.078 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004630
2022-05-06T21:16:55.134Z,1651871815.134 [DAT](INFO): commRate: 800
2022-05-06T21:16:57.200Z,1651871817.200 [DAT](INFO): entering command mode
2022-05-06T21:16:57.401Z,1651871817.401 [DAT](INFO): setting verbose to 3
2022-05-06T21:16:57.654Z,1651871817.654 [DAT](INFO): set verbose to 3
2022-05-06T21:16:57.654Z,1651871817.654 [DAT](INFO): setting DatVerbose to 27440
2022-05-06T21:16:57.906Z,1651871817.906 [DAT](INFO): set DatVerbose to 27440
2022-05-06T21:16:57.906Z,1651871817.906 [DAT](INFO): setting transmit power to 8
2022-05-06T21:16:58.158Z,1651871818.158 [DAT](INFO): set transmit power to 8
2022-05-06T21:16:58.158Z,1651871818.158 [DAT](INFO): setting local address to 8
2022-05-06T21:16:58.409Z,1651871818.409 [DAT](INFO): set local address to 8
2022-05-06T21:16:58.410Z,1651871818.410 [DAT](INFO): Setting time to: 21:16:58 And date to:5/6/2022
2022-05-06T21:16:58.662Z,1651871818.662 [DAT](INFO): Local DAT time set to Fri May 6, 2022  21:16:58  

2022-05-06T21:17:01.277Z,1651871821.277 [SBIT](IMPORTANT): Beginning Startup BIT
2022-05-06T21:17:01.282Z,1651871821.282 [CBIT](IMPORTANT): Beginning ground fault scan
2022-05-06T21:17:05.040Z,1651871825.040 [NavChartDb](INFO): # of records loaded: 5000
2022-05-06T21:17:08.944Z,1651871828.944 [NAL9602](INFO): Powering up NAL9602
2022-05-06T21:17:12.320Z,1651871832.320 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.004816
CHAN A1 (24V): -0.002410
CHAN A2 (12V): -0.001225
CHAN A3 (5V): -0.000169
CHAN B0 (3.3V): 0.000984
CHAN B1 (3.15aV): -0.000074
CHAN B2 (3.15bV): -0.000032
CHAN B3 (GND): 0.000922
OPEN: -0.000995
Full Scale: +/- 1 mA
2022-05-06T21:17:13.517Z,1651871833.517 [NavChartDb](INFO): # of records loaded: 10000
2022-05-06T21:17:19.838Z,1651871839.838 [NAL9602](INFO): NAL9602 initialized
2022-05-06T21:17:23.824Z,1651871843.824 [NavChartDb](INFO): # of records loaded: 15000
2022-05-06T21:17:32.291Z,1651871852.291 [NavChartDb](INFO): # of records loaded: 20000
2022-05-06T21:17:39.514Z,1651871859.514 [NavChartDb](INFO): # of records loaded: 25000
2022-05-06T21:17:47.291Z,1651871867.291 [NavChartDb](INFO): # of records loaded: 30000
2022-05-06T21:17:54.730Z,1651871874.730 [SBIT](FAULT): Mass: EXPECTED:0.000000 ACTUAL:-0.001273
2022-05-06T21:17:54.730Z,1651871874.730 [SBIT](FAULT): Control surface position failure.
2022-05-06T21:17:55.125Z,1651871875.125 [SBIT](CRITICAL): SBIT FAILED
2022-05-06T21:17:55.126Z,1651871875.126 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2022-05-06T21:17:55.126Z,1651871875.126 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count;

2022-05-06T21:17:55.126Z,1651871875.126 [SBIT](IMPORTANT): BackseatComponent.loadAtStartup=1 bool;

2022-05-06T21:17:55.127Z,1651871875.127 [SBIT](IMPORTANT): ESPComponent.processCompleteTimeout=120 minute;

2022-05-06T21:17:55.127Z,1651871875.127 [SBIT](IMPORTANT): Express linearApproximation CBIT.ampHoursUsed 1.000000 ampere_hour;

2022-05-06T21:17:55.127Z,1651871875.127 [SBIT](IMPORTANT): Express linearApproximation CTD_Seabird.bin_median_sea_water_salinity 0.010000 practical_salinity_unit;

2022-05-06T21:17:55.127Z,1651871875.127 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water;

2022-05-06T21:17:55.127Z,1651871875.127 [SBIT](IMPORTANT): Express linearApproximation WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water 0.200000 microgram_per_liter;

2022-05-06T21:17:55.127Z,1651871875.127 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=438.149052 cubic_centimeter;

2022-05-06T21:17:55.127Z,1651871875.127 [SBIT](IMPORTANT): VerticalControl.massDefault=0 centimeter;

2022-05-06T21:17:55.127Z,1651871875.127 [SBIT](IMPORTANT): VerticalControl.massPositionLimitAft=-49 millimeter;

2022-05-06T21:17:55.128Z,1651871875.128 [SBIT](IMPORTANT): VerticalControl.massPositionLimitFwd=32 millimeter;

2022-05-06T21:17:55.129Z,1651871875.129 [CBIT](INFO): Critical error at 20220506T211755
2022-05-06T21:17:55.444Z,1651871875.444 [MissionManager](IMPORTANT): Started mission Startup
2022-05-06T21:17:55.445Z,1651871875.445 [Startup] Running Loop=1
2022-05-06T21:17:55.445Z,1651871875.445 [Startup](DEBUG): Aggregate::initialize Startup
2022-05-06T21:17:55.445Z,1651871875.445 [Startup:A.GoToSurface] Running Loop=1
2022-05-06T21:17:55.445Z,1651871875.445 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-05-06T21:17:55.445Z,1651871875.445 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-05-06T21:17:55.446Z,1651871875.446 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-05-06T21:17:55.446Z,1651871875.446 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-05-06T21:17:55.446Z,1651871875.446 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-05-06T21:17:55.447Z,1651871875.447 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-05-06T21:17:55.460Z,1651871875.460 [Startup:StartupSatComms] Running Loop=1
2022-05-06T21:17:55.461Z,1651871875.461 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2022-05-06T21:17:55.461Z,1651871875.461 [Startup:StartupSatComms:A] Running Loop=1
2022-05-06T21:17:55.878Z,1651871875.878 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2022-05-06T21:17:58.375Z,1651871878.375 [NavChartDb](INFO): # of records loaded: 35000
2022-05-06T21:18:08.752Z,1651871888.752 [NavChartDb](INFO): # of records loaded: 40000
2022-05-06T21:18:16.662Z,1651871896.662 [NavChartDb](INFO): # of records loaded: 45000
2022-05-06T21:18:24.019Z,1651871904.019 [NavChartDb](INFO): # of records loaded: 50000
2022-05-06T21:18:36.878Z,1651871916.878 [NavChartDb](INFO): # of records loaded: 55000
2022-05-06T21:18:38.446Z,1651871918.446 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US5CA50M.000
2022-05-06T21:18:42.923Z,1651871922.923 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US5CA50M.000
2022-05-06T21:18:47.282Z,1651871927.282 [NavChartDb](INFO): # of records loaded: 60000
2022-05-06T21:18:55.627Z,1651871935.627 [Startup:StartupSatComms:A](INFO): Timed out from 2022-05-06T21:17:55.5Z
2022-05-06T21:18:55.627Z,1651871935.627 [Startup:StartupSatComms:A] Stopped
2022-05-06T21:18:55.627Z,1651871935.627 [Startup:StartupSatComms:B] Running Loop=1
2022-05-06T21:18:56.034Z,1651871936.034 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-05-06T21:18:59.340Z,1651871939.340 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US5CA50M.000
2022-05-06T21:18:59.420Z,1651871939.420 [NavChartDb](INFO): # of records loaded: 62026
2022-05-06T21:18:59.433Z,1651871939.433 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US5CA50M.000
2022-05-06T21:18:59.444Z,1651871939.444 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US3CA69M.000
2022-05-06T21:18:59.448Z,1651871939.448 [NavChartDb](FAULT): Error opening file: Resources/ElectronicNavigationCharts/US3CA69M.000
2022-05-06T21:18:59.448Z,1651871939.448 [NavChartDb](INFO): # of records loaded: 0
2022-05-06T21:18:59.450Z,1651871939.450 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US3CA69M.000
2022-05-06T21:18:59.548Z,1651871939.548 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US3CA52M.000
2022-05-06T21:19:03.863Z,1651871943.863 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US3CA52M.000
2022-05-06T21:19:05.461Z,1651871945.461 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220506T190917/Courier0010.lzma
2022-05-06T21:19:06.462Z,1651871946.462 [DataOverHttps](INFO): Moved sent file to Logs/20220506T190917/Courier0010.lzma.bak
2022-05-06T21:19:06.462Z,1651871946.462 [DataOverHttps](INFO): SBD MOMSN=16725487
2022-05-06T21:19:17.281Z,1651871957.281 [NavChartDb](INFO): # of records loaded: 5000
2022-05-06T21:19:28.532Z,1651871968.532 [DataOverHttps](INFO): Sending 340 bytes from file Logs/20220506T211631/Courier0000.lzma
2022-05-06T21:19:29.469Z,1651871969.469 [NavChartDb](INFO): # of records loaded: 10000
2022-05-06T21:19:29.534Z,1651871969.534 [DataOverHttps](INFO): Moved sent file to Logs/20220506T211631/Courier0000.lzma.bak
2022-05-06T21:19:29.534Z,1651871969.534 [DataOverHttps](INFO): SBD MOMSN=16725496
2022-05-06T21:19:34.149Z,1651871974.149 [NavChartDb](INFO): # of records loaded: 15000
2022-05-06T21:19:39.117Z,1651871979.117 [NavChartDb](INFO): # of records loaded: 20000
2022-05-06T21:19:40.917Z,1651871980.917 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2022-05-06T21:19:40.917Z,1651871980.917 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-05-06T21:19:40.969Z,1651871980.969 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-05-06T21:19:41.293Z,1651871981.293 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-05-06T21:19:41.293Z,1651871981.293 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2022-05-06T21:19:45.177Z,1651871985.177 [NavChartDb](INFO): # of records loaded: 25000
2022-05-06T21:19:53.132Z,1651871993.132 [NavChartDb](INFO): # of records loaded: 30000
2022-05-06T21:19:53.772Z,1651871993.772 [DataOverHttps](INFO): Sending 242 bytes from file Logs/20220506T190917/Express0011.lzma
2022-05-06T21:19:54.758Z,1651871994.758 [DataOverHttps](INFO): Moved sent file to Logs/20220506T190917/Express0011.lzma.bak
2022-05-06T21:19:54.758Z,1651871994.758 [DataOverHttps](INFO): SBD MOMSN=16725676
2022-05-06T21:19:55.532Z,1651871995.532 [NavChartDb](INFO): # of records loaded: 35000
2022-05-06T21:19:55.850Z,1651871995.850 [Startup:StartupSatComms:B](INFO): Timed out from 2022-05-06T21:18:55.6Z
2022-05-06T21:19:55.850Z,1651871995.850 [Startup:StartupSatComms:B] Stopped
2022-05-06T21:19:55.850Z,1651871995.850 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2022-05-06T21:19:55.850Z,1651871995.850 [Startup:StartupSatComms] Stopped
2022-05-06T21:19:55.850Z,1651871995.850 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2022-05-06T21:19:55.851Z,1651871995.851 [Startup](INFO): Completed Startup
2022-05-06T21:19:55.851Z,1651871995.851 [MissionManager](INFO): Startup is completed.
2022-05-06T21:19:55.851Z,1651871995.851 [MissionManager](INFO): Uninitializing Mission Startup
2022-05-06T21:19:55.851Z,1651871995.851 [Startup] Stopped
2022-05-06T21:19:55.851Z,1651871995.851 [Startup](DEBUG): Aggregate::uninitialize Startup
2022-05-06T21:19:55.851Z,1651871995.851 [Startup:A.GoToSurface] Stopped
2022-05-06T21:19:55.851Z,1651871995.851 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-05-06T21:19:56.249Z,1651871996.249 [MissionManager](IMPORTANT): Started mission Default
2022-05-06T21:19:56.249Z,1651871996.249 [Default] Running Loop=1
2022-05-06T21:19:56.249Z,1651871996.249 [Default](DEBUG): Aggregate::initialize Default
2022-05-06T21:19:56.249Z,1651871996.249 [Default:B.GoToSurface] Running Loop=1
2022-05-06T21:19:56.249Z,1651871996.249 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-05-06T21:19:56.250Z,1651871996.250 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-05-06T21:19:56.250Z,1651871996.250 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-05-06T21:19:56.250Z,1651871996.250 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-05-06T21:19:56.251Z,1651871996.251 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-05-06T21:19:56.251Z,1651871996.251 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-05-06T21:19:56.251Z,1651871996.251 [Default:A.Wait] Running Loop=1
2022-05-06T21:19:56.251Z,1651871996.251 [Default:A.Wait](DEBUG): Initialize Wait Component.
2022-05-06T21:20:03.182Z,1651872003.182 [NavChartDb](INFO): # of records loaded: 40000
2022-05-06T21:20:09.550Z,1651872009.550 [Default:A.Wait](INFO): Done Waiting.
2022-05-06T21:20:09.550Z,1651872009.550 [Default:A.Wait] Stopped
2022-05-06T21:20:09.550Z,1651872009.550 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2022-05-06T21:20:09.962Z,1651872009.962 [Default:CheckIn] Running Loop=1
2022-05-06T21:20:09.962Z,1651872009.962 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-05-06T21:20:09.962Z,1651872009.962 [Default:CheckIn:Read_GPS] Running Loop=1
2022-05-06T21:20:10.366Z,1651872010.366 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2022-05-06T21:20:11.774Z,1651872011.774 [NavChartDb](INFO): # of records loaded: 45000
2022-05-06T21:20:18.934Z,1651872018.934 [NavChartDb](INFO): # of records loaded: 50000
2022-05-06T21:20:24.994Z,1651872024.994 [NavChartDb](INFO): # of records loaded: 55000
2022-05-06T21:20:29.906Z,1651872029.906 [NavChartDb](INFO): # of records loaded: 60000
2022-05-06T21:20:34.074Z,1651872034.074 [NavChartDb](INFO): # of records loaded: 65000
2022-05-06T21:20:40.069Z,1651872040.069 [NavChartDb](INFO): # of records loaded: 70000
2022-05-06T21:20:42.965Z,1651872042.965 [DataOverHttps](INFO): Sending 1188 bytes from file Logs/20220506T211631/Express0001.lzma
2022-05-06T21:20:44.002Z,1651872044.002 [DataOverHttps](INFO): Moved sent file to Logs/20220506T211631/Express0001.lzma.bak
2022-05-06T21:20:44.002Z,1651872044.002 [DataOverHttps](INFO): SBD MOMSN=16725773
2022-05-06T21:20:47.967Z,1651872047.967 [NavChartDb](INFO): # of records loaded: 75000
2022-05-06T21:20:54.844Z,1651872054.844 [NavChartDb](INFO): # of records loaded: 80000
2022-05-06T21:20:59.123Z,1651872059.123 [NavChartDb](INFO): # of records loaded: 85000
2022-05-06T21:21:05.808Z,1651872065.808 [NavChartDb](INFO): # of records loaded: 90000
2022-05-06T21:21:12.329Z,1651872072.329 [NavChartDb](INFO): # of records loaded: 95000
2022-05-06T21:21:19.020Z,1651872079.020 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2022-05-06T21:21:19.020Z,1651872079.020 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000,+20.4,0000.0,1489.0,000
2022-05-06T21:21:22.604Z,1651872082.604 [NavChartDb](INFO): # of records loaded: 100000
2022-05-06T21:21:30.156Z,1651872090.156 [NavChartDb](INFO): # of records loaded: 105000
2022-05-06T21:21:37.733Z,1651872097.733 [NavChartDb](INFO): # of records loaded: 110000
2022-05-06T21:21:46.383Z,1651872106.383 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US3CA52M.000
2022-05-06T21:21:48.889Z,1651872108.889 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US3CA52M.000
2022-05-06T21:21:56.583Z,1651872116.583 [NavChartDb](INFO): # of records loaded: 115000
2022-05-06T21:22:07.149Z,1651872127.149 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US3CA52M.000
2022-05-06T21:22:07.469Z,1651872127.469 [NavChartDb](INFO): # of records loaded: 117290
2022-05-06T21:22:07.477Z,1651872127.477 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US3CA52M.000
2022-05-06T21:22:07.478Z,1651872127.478 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US2WC11M.000
2022-05-06T21:22:10.330Z,1651872130.330 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US2WC11M.000
2022-05-06T21:22:17.741Z,1651872137.741 [NavChartDb](INFO): # of records loaded: 5000
2022-05-06T21:22:23.410Z,1651872143.410 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-05-06T21:22:28.442Z,1651872148.442 [NavChartDb](INFO): # of records loaded: 10000
2022-05-06T21:22:35.922Z,1651872155.922 [NavChartDb](INFO): # of records loaded: 15000
2022-05-06T21:22:42.060Z,1651872162.060 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2022-05-06T21:22:42.060Z,1651872162.060 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-05-06T21:22:42.074Z,1651872162.074 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-05-06T21:22:42.437Z,1651872162.437 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-05-06T21:22:42.438Z,1651872162.438 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2022-05-06T21:22:43.369Z,1651872163.369 [NavChartDb](INFO): # of records loaded: 20000
2022-05-06T21:22:51.482Z,1651872171.482 [NavChartDb](INFO): # of records loaded: 25000
2022-05-06T21:23:01.517Z,1651872181.517 [NavChartDb](INFO): # of records loaded: 30000
2022-05-06T21:23:11.712Z,1651872191.712 [NavChartDb](INFO): # of records loaded: 35000
2022-05-06T21:23:19.598Z,1651872199.598 [NavChartDb](INFO): # of records loaded: 40000
2022-05-06T21:23:21.422Z,1651872201.422 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US2WC11M.000
2022-05-06T21:23:22.132Z,1651872202.132 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US2WC11M.000
2022-05-06T21:23:30.152Z,1651872210.152 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US2WC11M.000
2022-05-06T21:23:30.213Z,1651872210.213 [NavChartDb](INFO): # of records loaded: 44880
2022-05-06T21:23:30.218Z,1651872210.218 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US2WC11M.000
2022-05-06T21:23:30.219Z,1651872210.219 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US1WC07M.000
2022-05-06T21:23:35.035Z,1651872215.035 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US1WC07M.000
2022-05-06T21:23:45.803Z,1651872225.803 [NavChartDb](INFO): # of records loaded: 5000
2022-05-06T21:23:54.329Z,1651872234.329 [DVL_micro](ERROR): Failed to parse:
:R99,+9999.99,+9999.99,+9999.99
2022-05-06T21:23:54.811Z,1651872234.811 [NavChartDb](INFO): # of records loaded: 10000
2022-05-06T21:24:03.932Z,1651872243.932 [NavChartDb](INFO): # of records loaded: 15000
2022-05-06T21:24:16.441Z,1651872256.441 [NavChartDb](INFO): # of records loaded: 20000
2022-05-06T21:24:18.491Z,1651872258.491 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US1WC07M.000
2022-05-06T21:24:19.643Z,1651872259.643 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US1WC07M.000
2022-05-06T21:24:38.205Z,1651872278.205 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US1WC07M.000
2022-05-06T21:24:38.533Z,1651872278.533 [NavChartDb](INFO): # of records loaded: 24424
2022-05-06T21:24:38.542Z,1651872278.542 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US1WC07M.000
2022-05-06T21:24:39.940Z,1651872279.940 [NavChartDb](INFO): Creating index for soundings
2022-05-06T21:24:44.562Z,1651872284.562 [NavChartDb](INFO): Creating index for 0p0
2022-05-06T21:24:47.165Z,1651872287.165 [NavChartDb](INFO): Creating index for 1p8
2022-05-06T21:24:47.461Z,1651872287.461 [NavChartDb](INFO): Creating index for 3p6
2022-05-06T21:24:48.072Z,1651872288.072 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2022-05-06T21:24:48.072Z,1651872288.072 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+200,1489.0,000
2022-05-06T21:24:48.729Z,1651872288.729 [NavChartDb](INFO): Creating index for 5p4
2022-05-06T21:24:49.434Z,1651872289.434 [NavChartDb](INFO): Creating index for 9p1
2022-05-06T21:24:49.499Z,1651872289.499 [NavChartDb](INFO): Creating index for 10p9
2022-05-06T21:24:50.295Z,1651872290.295 [NavChartDb](INFO): Creating index for 18p2
2022-05-06T21:24:51.387Z,1651872291.387 [NavChartDb](INFO): Creating index for 36p5
2022-05-06T21:24:52.735Z,1651872292.735 [NavChartDb](INFO): Creating index for 54p8
2022-05-06T21:24:53.913Z,1651872293.913 [NavChartDb](INFO): Creating index for 73p1
2022-05-06T21:24:55.258Z,1651872295.258 [NavChartDb](INFO): Creating index for 91p4
2022-05-06T21:24:57.220Z,1651872297.220 [NavChartDb](INFO): Creating index for 182p8
2022-05-06T21:24:58.766Z,1651872298.766 [NavChartDb](INFO): Creating index for 365p7
2022-05-06T21:25:00.149Z,1651872300.149 [NavChartDb](INFO): Creating index for 548p6
2022-05-06T21:25:01.373Z,1651872301.373 [NavChartDb](INFO): Creating index for 731p5
2022-05-06T21:25:03.637Z,1651872303.637 [NavChartDb](INFO): Creating index for 914p4
2022-05-06T21:25:05.282Z,1651872305.282 [NavChartDb](INFO): Creating index for 1097p2
2022-05-06T21:25:06.303Z,1651872306.303 [NavChartDb](INFO): Creating index for 1280p1
2022-05-06T21:25:07.110Z,1651872307.110 [NavChartDb](INFO): Creating index for 1463p0
2022-05-06T21:25:07.766Z,1651872307.766 [NavChartDb](INFO): Creating index for 1645p9
2022-05-06T21:25:09.943Z,1651872309.943 [NavChartDb](INFO): Creating index for 1828p8
2022-05-06T21:25:10.310Z,1651872310.310 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-05-06T21:20:09.0Z
2022-05-06T21:25:10.310Z,1651872310.310 [Default:CheckIn:Read_GPS] Stopped
2022-05-06T21:25:10.310Z,1651872310.310 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-05-06T21:25:10.727Z,1651872310.727 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-05-06T21:25:11.427Z,1651872311.427 [NavChartDb](INFO): Creating index for 2011p6
2022-05-06T21:25:12.186Z,1651872312.186 [NavChartDb](INFO): Creating index for 2194p5
2022-05-06T21:25:12.853Z,1651872312.853 [NavChartDb](INFO): Creating index for 2377p4
2022-05-06T21:25:13.317Z,1651872313.317 [NavChartDb](INFO): Creating index for 2560p3
2022-05-06T21:25:14.345Z,1651872314.345 [NavChartDb](INFO): Creating index for 2743p2
2022-05-06T21:25:15.656Z,1651872315.656 [NavChartDb](INFO): Creating index for 2926p0
2022-05-06T21:25:16.628Z,1651872316.628 [NavChartDb](INFO): Creating index for 3108p9
2022-05-06T21:25:17.519Z,1651872317.519 [NavChartDb](INFO): Creating index for 3291p8
2022-05-06T21:25:18.149Z,1651872318.149 [NavChartDb](INFO): Creating index for 3474p7
2022-05-06T21:25:21.353Z,1651872321.353 [DAT](INFO): unknown deviceResponse_: Acoustic Wakeup

2022-05-06T21:25:21.355Z,1651872321.355 [DAT](INFO): commRate: 800
2022-05-06T21:25:21.735Z,1651872321.735 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220506T211631/Courier0004.lzma
2022-05-06T21:25:22.738Z,1651872322.738 [DataOverHttps](INFO): Moved sent file to Logs/20220506T211631/Courier0004.lzma.bak
2022-05-06T21:25:22.738Z,1651872322.738 [DataOverHttps](INFO): SBD MOMSN=16725808
2022-05-06T21:25:22.869Z,1651872322.869 [DAT](INFO): Received command: Pbub@
2022-05-06T21:25:22.873Z,1651872322.873 [CommandExec](IMPORTANT): got command burn
2022-05-06T21:25:22.873Z,1651872322.873 [CommandExec](FAULT): Incomplete syntax. Try: help burn
2022-05-06T21:25:23.727Z,1651872323.727 [NavChartDb](INFO): Creating index for 3657p6
2022-05-06T21:25:40.788Z,1651872340.788 [DataOverHttps](INFO): Sending 327 bytes from file Logs/20220506T211631/Express0005.lzma
2022-05-06T21:25:41.790Z,1651872341.790 [DataOverHttps](INFO): Moved sent file to Logs/20220506T211631/Express0005.lzma.bak
2022-05-06T21:25:41.790Z,1651872341.790 [DataOverHttps](INFO): SBD MOMSN=16726144
2022-05-06T21:25:43.188Z,1651872343.188 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2022-05-06T21:25:43.188Z,1651872343.188 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-05-06T21:25:43.203Z,1651872343.203 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-05-06T21:25:43.585Z,1651872343.585 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-05-06T21:25:43.585Z,1651872343.585 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2022-05-06T21:25:44.371Z,1651872344.371 [Default:CheckIn:Read_Iridium] Stopped
2022-05-06T21:25:44.371Z,1651872344.371 [Default:CheckIn:C.Wait] Running Loop=1
2022-05-06T21:25:44.371Z,1651872344.371 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-05-06T21:27:22.526Z,1651872442.526 [NAL9602](FAULT): GPS failed to acquire within timeout.
2022-05-06T21:27:22.526Z,1651872442.526 [NAL9602] Data Fault, FailCount= 1
2022-05-06T21:27:22.526Z,1651872442.526 [NAL9602](ERROR): Data Fault
2022-05-06T21:27:22.547Z,1651872442.547 [CBIT](ERROR): Data Fault in component: NAL9602
2022-05-06T21:27:22.938Z,1651872442.938 [NAL9602](INFO): Powering down
2022-05-06T21:27:23.759Z,1651872443.759 [CBIT](INFO): Clearing failed state for component NAL9602
2022-05-06T21:27:23.759Z,1651872443.759 [NAL9602] No Fault, FailCount= 1
2022-05-06T21:27:53.234Z,1651872473.234 [NAL9602](INFO): Powering up NAL9602
2022-05-06T21:28:04.152Z,1651872484.152 [NAL9602](INFO): NAL9602 initialized
2022-05-06T21:28:22.653Z,1651872502.653 [DAT](INFO): unknown deviceResponse_: Lowpower

2022-05-06T21:28:44.144Z,1651872524.144 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2022-05-06T21:28:44.144Z,1651872524.144 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-05-06T21:28:44.155Z,1651872524.155 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-05-06T21:28:44.558Z,1651872524.558 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-05-06T21:28:44.558Z,1651872524.558 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2022-05-06T21:30:06.557Z,1651872606.557 [DVL_micro](ERROR): only read 3 of 4 data items
2022-05-06T21:30:06.557Z,1651872606.557 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+99999.99,+9999.99
2022-05-06T21:30:44.984Z,1651872644.984 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-05-06T21:30:44.985Z,1651872644.985 [Default:CheckIn:C.Wait] Stopped
2022-05-06T21:30:44.985Z,1651872644.985 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-05-06T21:30:44.985Z,1651872644.985 [Default:CheckIn:D] Running Loop=1
2022-05-06T21:30:45.363Z,1651872645.363 [Default:CheckIn:D] Stopped
2022-05-06T21:30:45.363Z,1651872645.363 [Default:CheckIn:E] Running Loop=1
2022-05-06T21:30:45.752Z,1651872645.752 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.818557 min 
2022-05-06T21:30:45.752Z,1651872645.752 [Default:CheckIn:E] Stopped
2022-05-06T21:30:45.752Z,1651872645.752 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-05-06T21:30:45.752Z,1651872645.752 [Default:CheckIn] Stopped
2022-05-06T21:30:45.752Z,1651872645.752 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-05-06T21:30:45.752Z,1651872645.752 [Default:CheckIn](INFO): Running loop #2
2022-05-06T21:30:45.753Z,1651872645.753 [Default:CheckIn] Running Loop=2
2022-05-06T21:30:45.753Z,1651872645.753 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-05-06T21:30:45.753Z,1651872645.753 [Default:CheckIn:Read_GPS] Running Loop=1
2022-05-06T21:31:41.575Z,1651872701.575 [CBIT](INFO): Clearing failed state for component DropWeight
2022-05-06T21:31:41.575Z,1651872701.575 [DropWeight] No Fault, FailCount= 1
2022-05-06T21:31:45.137Z,1651872705.137 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2022-05-06T21:31:45.137Z,1651872705.137 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-05-06T21:31:45.148Z,1651872705.148 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-05-06T21:31:45.554Z,1651872705.554 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-05-06T21:31:45.554Z,1651872705.554 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2022-05-06T21:32:21.899Z,1651872741.899 [DVL_micro](ERROR): Failed to parse:
:BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00
2022-05-06T21:33:02.702Z,1651872782.702 [DVL_micro](ERROR): only read 3 of 4 data items
2022-05-06T21:33:02.702Z,1651872782.702 [DVL_micro](ERROR): Failed to parse:
:BI,+00588,+00285,+0080,I
2022-05-06T21:33:15.126Z,1651872795.126 [CommandExec](IMPORTANT): got command show variable limitFwd
2022-05-06T21:33:15.142Z,1651872795.142 [CommandExec](IMPORTANT): VerticalControl.massPositionLimitFwd (millimeter)
2022-05-06T21:33:22.432Z,1651872802.432 [CommandExec](IMPORTANT): got command get VerticalControl.massPositionLimitFwd
2022-05-06T21:33:22.433Z,1651872802.433 [CommandExec](IMPORTANT): VerticalControl.massPositionLimitFwd 32.000000 mm
2022-05-06T21:33:37.487Z,1651872817.487 [CommandExec](IMPORTANT): got command maintain control VerticalControl.massPositionAction 32 millimeter
2022-05-06T21:33:37.525Z,1651872817.525 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.massPositionAction" handled in the control thread.
2022-05-06T21:33:37.541Z,1651872817.541 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.massPositionAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2022-05-06T21:34:34.574Z,1651872874.574 [CommandExec](IMPORTANT): got command get VerticalControl.massPositionLimitAft
2022-05-06T21:34:34.575Z,1651872874.575 [CommandExec](IMPORTANT): VerticalControl.massPositionLimitAft -49.000000 mm
2022-05-06T21:34:39.264Z,1651872879.264 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2022-05-06T21:34:39.265Z,1651872879.265 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+20.7,0000.0,00
2022-05-06T21:34:46.156Z,1651872886.156 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2022-05-06T21:34:46.156Z,1651872886.156 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-05-06T21:34:46.199Z,1651872886.199 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-05-06T21:34:46.610Z,1651872886.610 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-05-06T21:34:46.610Z,1651872886.610 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2022-05-06T21:34:47.084Z,1651872887.084 [CommandExec](IMPORTANT): got command maintain control VerticalControl.massPositionAction -49 millimeter
2022-05-06T21:35:31.291Z,1651872931.291 [DAT](INFO): unknown deviceResponse_: Acoustic Wakeup

2022-05-06T21:35:31.294Z,1651872931.294 [DAT](INFO): commRate: 800
2022-05-06T21:35:33.057Z,1651872933.057 [DAT](INFO): unknown deviceResponse_: CRC:Fail {0001} MPD:18.0 PSNR:09.7 AGC:79 SPD:-0.3 CCERR:006

2022-05-06T21:35:45.962Z,1651872945.962 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-05-06T21:30:45.8Z
2022-05-06T21:35:45.962Z,1651872945.962 [Default:CheckIn:Read_GPS] Stopped
2022-05-06T21:35:45.963Z,1651872945.963 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-05-06T21:35:53.215Z,1651872953.215 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220506T211631/Courier0007.lzma
2022-05-06T21:35:54.218Z,1651872954.218 [DataOverHttps](INFO): Moved sent file to Logs/20220506T211631/Courier0007.lzma.bak
2022-05-06T21:35:54.218Z,1651872954.218 [DataOverHttps](INFO): SBD MOMSN=16726160
2022-05-06T21:36:03.756Z,1651872963.756 [DVL_micro](ERROR): DVL uart error: serial timeout
2022-05-06T21:36:03.756Z,1651872963.756 [DVL_micro] Communications Fault, FailCount= 1
2022-05-06T21:36:03.756Z,1651872963.756 [DVL_micro](ERROR): Communications Fault
2022-05-06T21:36:03.756Z,1651872963.756 [DVL_micro](ERROR): Failed to parse:
2022-05-06T21:36:03.836Z,1651872963.836 [CBIT](ERROR): Communications Fault in component: DVL_micro
2022-05-06T21:36:04.164Z,1651872964.164 [DVL_micro](INFO): Powering down
2022-05-06T21:36:04.978Z,1651872964.978 [CBIT](INFO): Clearing failed state for component DVL_micro
2022-05-06T21:36:04.978Z,1651872964.978 [DVL_micro] No Fault, FailCount= 1
2022-05-06T21:36:10.236Z,1651872970.236 [DataOverHttps](INFO): Sending 500 bytes from file Logs/20220506T211631/Express0008.lzma
2022-05-06T21:36:11.238Z,1651872971.238 [DataOverHttps](INFO): Moved sent file to Logs/20220506T211631/Express0008.lzma.bak
2022-05-06T21:36:11.238Z,1651872971.238 [DataOverHttps](INFO): SBD MOMSN=16726747
2022-05-06T21:36:13.810Z,1651872973.810 [Default:CheckIn:Read_Iridium] Stopped
2022-05-06T21:36:13.810Z,1651872973.810 [Default:CheckIn:C.Wait] Running Loop=1
2022-05-06T21:36:13.810Z,1651872973.810 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-05-06T21:36:33.371Z,1651872993.371 [CommandExec](IMPORTANT): got command get VerticalControl.massPositionLimitAft
2022-05-06T21:36:33.372Z,1651872993.372 [CommandExec](IMPORTANT): VerticalControl.massPositionLimitAft -49.000000 mm
2022-05-06T21:37:04.573Z,1651873024.573 [CommandExec](IMPORTANT): got command maintain control VerticalControl.massPositionAction -62 millimeter
2022-05-06T21:37:47.134Z,1651873067.134 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2022-05-06T21:37:47.134Z,1651873067.134 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-05-06T21:37:47.220Z,1651873067.220 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-05-06T21:37:47.613Z,1651873067.613 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-05-06T21:37:47.613Z,1651873067.613 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2022-05-06T21:38:06.511Z,1651873086.511 [NAL9602](FAULT): GPS failed to acquire within timeout.
2022-05-06T21:38:06.511Z,1651873086.511 [NAL9602] Data Fault, FailCount= 2
2022-05-06T21:38:06.511Z,1651873086.511 [NAL9602](ERROR): Data Fault
2022-05-06T21:38:06.589Z,1651873086.589 [CBIT](ERROR): Data Fault in component: NAL9602
2022-05-06T21:38:06.910Z,1651873086.910 [NAL9602](INFO): Powering down
2022-05-06T21:38:07.792Z,1651873087.792 [CBIT](INFO): Clearing failed state for component NAL9602
2022-05-06T21:38:07.792Z,1651873087.792 [NAL9602] No Fault, FailCount= 2
2022-05-06T21:38:10.886Z,1651873090.886 [CommandExec](IMPORTANT): got command show variable limitAft
2022-05-06T21:38:10.906Z,1651873090.906 [CommandExec](IMPORTANT): VerticalControl.massPositionLimitAft (millimeter)
2022-05-06T21:38:20.209Z,1651873100.209 [CommandExec](IMPORTANT): got command get VerticalControl.massPositionLimitAft
2022-05-06T21:38:20.210Z,1651873100.210 [CommandExec](IMPORTANT): VerticalControl.massPositionLimitAft -49.000000 mm
2022-05-06T21:38:33.073Z,1651873113.073 [DAT](INFO): unknown deviceResponse_: Lowpower

2022-05-06T21:38:33.289Z,1651873113.289 [CommandExec](IMPORTANT): got command configSet VerticalControl.massPositionLimitAft -62 millimeter persist
2022-05-06T21:38:37.210Z,1651873117.210 [NAL9602](INFO): Powering up NAL9602
2022-05-06T21:38:41.405Z,1651873121.405 [CommandExec](IMPORTANT): got command maintain
2022-05-06T21:38:41.406Z,1651873121.406 [Maintain_VerticalControl.massPositionAction](INFO): VerticalControl.massPositionAction maintaining -62.000000 mm
2022-05-06T21:38:48.133Z,1651873128.133 [NAL9602](INFO): NAL9602 initialized
2022-05-06T21:40:48.139Z,1651873248.139 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2022-05-06T21:40:48.139Z,1651873248.139 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-05-06T21:40:48.205Z,1651873248.205 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-05-06T21:40:48.597Z,1651873248.597 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-05-06T21:40:48.597Z,1651873248.597 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2022-05-06T21:41:14.400Z,1651873274.400 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-05-06T21:41:14.400Z,1651873274.400 [Default:CheckIn:C.Wait] Stopped
2022-05-06T21:41:14.400Z,1651873274.400 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-05-06T21:41:14.400Z,1651873274.400 [Default:CheckIn:D] Running Loop=1
2022-05-06T21:41:14.778Z,1651873274.778 [Default:CheckIn:D] Stopped
2022-05-06T21:41:14.778Z,1651873274.778 [Default:CheckIn:E] Running Loop=1
2022-05-06T21:41:15.187Z,1651873275.187 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.308805 min 
2022-05-06T21:41:15.187Z,1651873275.187 [Default:CheckIn:E] Stopped
2022-05-06T21:41:15.187Z,1651873275.187 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-05-06T21:41:15.187Z,1651873275.187 [Default:CheckIn] Stopped
2022-05-06T21:41:15.187Z,1651873275.187 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-05-06T21:41:15.187Z,1651873275.187 [Default:CheckIn](INFO): Running loop #3
2022-05-06T21:41:15.187Z,1651873275.187 [Default:CheckIn] Running Loop=3
2022-05-06T21:41:15.187Z,1651873275.187 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-05-06T21:41:15.188Z,1651873275.188 [Default:CheckIn:Read_GPS] Running Loop=1
2022-05-06T21:41:46.696Z,1651873306.696 [DVL_micro](ERROR): Failed to parse:
:WI,-01201,-00042,+01742,+00000,A
2022-05-06T21:43:03.452Z,1651873383.452 [DVL_micro](ERROR): Failed to parse:
:WI,+00866,-00341,+01313,+00000,A
2022-05-06T21:43:49.130Z,1651873429.130 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2022-05-06T21:43:49.130Z,1651873429.130 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-05-06T21:43:49.201Z,1651873429.201 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-05-06T21:43:49.585Z,1651873429.585 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-05-06T21:43:49.585Z,1651873429.585 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2022-05-06T21:45:12.125Z,1651873512.125 [CommandExec](IMPORTANT): got command restart application
2022-05-06T21:45:13.128Z,1651873513.128 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2022-05-06T21:45:13.128Z,1651873513.128 [CommandExec](INFO): Uninitializing the command executive.
2022-05-06T21:45:13.128Z,1651873513.128 [CommandExec](INFO): Uninitializing the command scheduler.
2022-05-06T21:45:13.128Z,1651873513.128 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-05-06T21:45:13.248Z,1651873513.248 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2022-05-06T21:45:13.249Z,1651873513.249 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2022-05-06T21:45:13.250Z,1651873513.250 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-05-06T21:45:13.251Z,1651873513.251 [NavChartDb](INFO): Join timeout helper Thread ID is 1855
2022-05-06T21:45:13.293Z,1651873513.293 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2022-05-06T21:45:13.293Z,1651873513.293 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-05-06T21:45:13.300Z,1651873513.300 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2022-05-06T21:45:13.301Z,1651873513.301 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2022-05-06T21:45:13.301Z,1651873513.301 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1856
2022-05-06T21:45:13.732Z,1651873513.732 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2022-05-06T21:45:13.732Z,1651873513.732 [WetLabsBB2FL](INFO): Powering down
2022-05-06T21:45:13.733Z,1651873513.733 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2022-05-06T21:45:13.740Z,1651873513.740 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2022-05-06T21:45:13.740Z,1651873513.740 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-05-06T21:45:13.740Z,1651873513.740 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1857
2022-05-06T21:45:14.052Z,1651873514.052 [CTD_Seabird](INFO): Powering down
2022-05-06T21:45:14.068Z,1651873514.068 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2022-05-06T21:45:14.068Z,1651873514.068 [CTD_Seabird](INFO): Powering down
2022-05-06T21:45:14.080Z,1651873514.080 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-05-06T21:45:14.080Z,1651873514.080 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler
2022-05-06T21:45:14.080Z,1651873514.080 [DAT ThreadHandler](INFO): Thread cancelled.
2022-05-06T21:45:14.081Z,1651873514.081 [DAT](INFO): Join timeout helper Thread ID is 1858
2022-05-06T21:45:14.260Z,1651873514.260 [DAT](INFO): Powering down
2022-05-06T21:45:14.344Z,1651873514.344 [DAT ThreadHandler](INFO): Uninitializing protected caller thread.
2022-05-06T21:45:14.344Z,1651873514.344 [DAT](INFO): Powering down
2022-05-06T21:45:14.345Z,1651873514.345 [DAT ThreadHandler](INFO): Thread cancelled.
2022-05-06T21:45:14.346Z,1651873514.346 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2022-05-06T21:45:14.346Z,1651873514.346 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-05-06T21:45:14.346Z,1651873514.346 [Radio_Surface](INFO): Join timeout helper Thread ID is 1859
2022-05-06T21:45:14.492Z,1651873514.492 [Radio_Surface](INFO): Powering down
2022-05-06T21:45:14.493Z,1651873514.493 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2022-05-06T21:45:14.493Z,1651873514.493 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-05-06T21:45:14.505Z,1651873514.505 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2022-05-06T21:45:14.505Z,1651873514.505 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-05-06T21:45:14.505Z,1651873514.505 [Onboard](INFO): Join timeout helper Thread ID is 1860
2022-05-06T21:45:14.933Z,1651873514.933 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2022-05-06T21:45:17.176Z,1651873517.176 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2022-05-06T21:45:17.177Z,1651873517.177 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-05-06T21:45:17.178Z,1651873517.178 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2022-05-06T21:45:17.178Z,1651873517.178 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-05-06T21:45:17.178Z,1651873517.178 [DataOverHttps](INFO): Join timeout helper Thread ID is 1861
2022-05-06T21:45:17.944Z,1651873517.944 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2022-05-06T21:45:17.944Z,1651873517.944 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-05-06T21:45:17.961Z,1651873517.961 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2022-05-06T21:45:17.961Z,1651873517.961 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-05-06T21:45:17.962Z,1651873517.962 [BackseatComponent](INFO): Join timeout helper Thread ID is 1862
2022-05-06T21:45:17.992Z,1651873517.992 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2022-05-06T21:45:17.993Z,1651873517.993 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-05-06T21:45:17.994Z,1651873517.994 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2022-05-06T21:45:17.994Z,1651873517.994 [logger ThreadHandler](INFO): Thread cancelled.
2022-05-06T21:45:17.994Z,1651873517.994 [logger](INFO): Join timeout helper Thread ID is 1863
2022-05-06T21:45:17.999Z,1651873517.999 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2022-05-06T21:45:17.999Z,1651873517.999 [logger ThreadHandler](INFO): Thread cancelled.
2022-05-06T21:45:18.001Z,1651873518.001 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2022-05-06T21:45:18.001Z,1651873518.001 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-05-06T21:45:18.001Z,1651873518.001 [CommandLine](INFO): Join timeout helper Thread ID is 1864
2022-05-06T21:45:18.012Z,1651873518.012 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2022-05-06T21:45:18.013Z,1651873518.013 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-05-06T21:45:18.025Z,1651873518.025 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2022-05-06T21:45:18.025Z,1651873518.025 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-05-06T21:45:18.025Z,1651873518.025 [CommandExec](INFO): Join timeout helper Thread ID is 1865
2022-05-06T21:45:18.026Z,1651873518.026 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2022-05-06T21:45:18.026Z,1651873518.026 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-05-06T21:45:18.027Z,1651873518.027 [controlThread](INFO): Join timeout helper Thread ID is 1866
2022-05-06T21:45:18.082Z,1651873518.082 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2022-05-06T21:45:18.082Z,1651873518.082 [controlThread](DEBUG): Uninitializing ControlThread
2022-05-06T21:45:18.082Z,1651873518.082 [AHRS_M2](INFO): Powering down
2022-05-06T21:45:18.224Z,1651873518.224 [DVL_micro](INFO): Powering down
2022-05-06T21:45:18.225Z,1651873518.225 [NAL9602](INFO): Powering down
2022-05-06T21:45:18.228Z,1651873518.228 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2022-05-06T21:45:18.229Z,1651873518.229 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2022-05-06T21:45:18.230Z,1651873518.230 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2022-05-06T21:45:18.230Z,1651873518.230 [MissionManager](INFO): Uninitializing Mission Default
2022-05-06T21:45:18.230Z,1651873518.230 [Default] Stopped
2022-05-06T21:45:18.230Z,1651873518.230 [Default](DEBUG): Aggregate::uninitialize Default
2022-05-06T21:45:18.230Z,1651873518.230 [Default:B.GoToSurface] Stopped
2022-05-06T21:45:18.230Z,1651873518.230 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-05-06T21:45:18.231Z,1651873518.231 [Default:CheckIn] Stopped
2022-05-06T21:45:18.231Z,1651873518.231 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-05-06T21:45:18.231Z,1651873518.231 [Default:CheckIn:Read_GPS] Stopped
2022-05-06T21:45:18.233Z,1651873518.233 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2022-05-06T21:45:18.234Z,1651873518.234 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2022-05-06T21:45:18.234Z,1651873518.234 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2022-05-06T21:45:18.234Z,1651873518.234 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2022-05-06T21:45:18.235Z,1651873518.235 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2022-05-06T21:45:18.235Z,1651873518.235 [BuoyancyServo](INFO): Powering down
2022-05-06T21:45:18.248Z,1651873518.248 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2022-05-06T21:45:18.248Z,1651873518.248 [ElevatorServo](INFO): Powering down
2022-05-06T21:45:18.249Z,1651873518.249 [MassServo](DEBUG): Uninitialize Mass Servo.
2022-05-06T21:45:18.249Z,1651873518.249 [MassServo](INFO): Powering down
2022-05-06T21:45:18.250Z,1651873518.250 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-05-06T21:45:18.250Z,1651873518.250 [RudderServo](INFO): Powering down
2022-05-06T21:45:18.251Z,1651873518.251 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2022-05-06T21:45:18.251Z,1651873518.251 [ThrusterHE](INFO): Powering down
2022-05-06T21:45:18.252Z,1651873518.252 [SBIT](DEBUG): Uninitialize SBIT Component.
2022-05-06T21:45:18.252Z,1651873518.252 [IBIT](DEBUG): Uninitialize IBIT Component.
2022-05-06T21:45:18.253Z,1651873518.253 [CBIT](DEBUG): Uninitialize CBIT Component.
2022-05-06T21:45:18.253Z,1651873518.253 [CBIT](DEBUG): Powering off loads.
2022-05-06T21:45:18.264Z,1651873518.264 [CBIT](DEBUG): Disabling WDT.
2022-05-06T21:45:18.276Z,1651873518.276 [CBIT](DEBUG): Opening all GF detection circuits.
2022-05-06T21:45:18.277Z,1651873518.277 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-05-06T21:45:18.319Z,1651873518.319 [DAT ThreadHandler](INFO): Thread cancelled.
2022-05-06T21:45:18.324Z,1651873518.324 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-05-06T21:45:18.326Z,1651873518.326 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-05-06T21:45:18.334Z,1651873518.334 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-05-06T21:45:18.340Z,1651873518.340 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-05-06T21:45:18.508Z,1651873518.508 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2022-05-06T21:45:18.513Z,1651873518.513 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-05-06T21:45:18.534Z,1651873518.534 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-05-06T21:45:18.599Z,1651873518.599 [logger ThreadHandler](INFO): Thread cancelled.