2021-08-16T00:16:13.629Z,1629072973.629 [Supervisor](DEBUG): Initializing supervisor.
2021-08-16T00:16:13.633Z,1629072973.633 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2021-08-16T00:16:13.634Z,1629072973.634 [SyncHandler](INFO): Protected caller Thread ID is 834
2021-08-16T00:16:13.634Z,1629072973.634 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2021-08-16T00:16:13.635Z,1629072973.635 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2021-08-16T00:16:13.636Z,1629072973.636 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 835
2021-08-16T00:16:13.640Z,1629072973.640 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2021-08-16T00:16:13.660Z,1629072973.660 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2021-08-16T00:16:13.661Z,1629072973.661 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2021-08-16T00:16:13.661Z,1629072973.661 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 836
2021-08-16T00:16:13.663Z,1629072973.663 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2021-08-16T00:16:13.664Z,1629072973.664 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2021-08-16T00:16:13.665Z,1629072973.665 [logger ThreadHandler](INFO): Protected caller Thread ID is 837
2021-08-16T00:16:13.669Z,1629072973.669 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2021-08-16T00:16:13.669Z,1629072973.669 [Supervisor](INFO): Looking for Config files in directory: Config/
2021-08-16T00:16:13.674Z,1629072973.674 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2021-08-16T00:16:14.102Z,1629072974.102 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2021-08-16T00:16:14.103Z,1629072974.103 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2021-08-16T00:16:14.183Z,1629072974.183 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2021-08-16T00:16:14.517Z,1629072974.517 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2021-08-16T00:16:14.519Z,1629072974.519 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2021-08-16T00:16:14.627Z,1629072974.627 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2021-08-16T00:16:14.629Z,1629072974.629 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2021-08-16T00:16:14.830Z,1629072974.830 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2021-08-16T00:16:14.832Z,1629072974.832 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2021-08-16T00:16:15.355Z,1629072975.355 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2021-08-16T00:16:15.357Z,1629072975.357 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2021-08-16T00:16:15.599Z,1629072975.599 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2021-08-16T00:16:15.602Z,1629072975.602 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2021-08-16T00:16:15.757Z,1629072975.757 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2021-08-16T00:16:15.757Z,1629072975.757 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2021-08-16T00:16:15.951Z,1629072975.951 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2021-08-16T00:16:15.952Z,1629072975.952 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2021-08-16T00:16:16.049Z,1629072976.049 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2021-08-16T00:16:16.050Z,1629072976.050 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2021-08-16T00:16:16.277Z,1629072976.277 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2021-08-16T00:16:16.278Z,1629072976.278 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2021-08-16T00:16:16.689Z,1629072976.689 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2021-08-16T00:16:16.689Z,1629072976.689 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2021-08-16T00:16:16.770Z,1629072976.770 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2021-08-16T00:16:16.901Z,1629072976.901 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2021-08-16T00:16:17.473Z,1629072977.473 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2021-08-16T00:16:18.240Z,1629072978.240 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2021-08-16T00:16:18.242Z,1629072978.242 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2021-08-16T00:16:18.622Z,1629072978.622 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2021-08-16T00:16:18.624Z,1629072978.624 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-polaris/
2021-08-16T00:16:18.628Z,1629072978.628 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/vehicle.cfg
2021-08-16T00:16:18.833Z,1629072978.833 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Control.cfg
2021-08-16T00:16:18.935Z,1629072978.935 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Estimation.cfg
2021-08-16T00:16:19.035Z,1629072979.035 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/BIT.cfg
2021-08-16T00:16:19.135Z,1629072979.135 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Battery.cfg
2021-08-16T00:16:19.398Z,1629072979.398 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2021-08-16T00:16:19.399Z,1629072979.399 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Simulator.cfg
2021-08-16T00:16:19.485Z,1629072979.485 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Navigation.cfg
2021-08-16T00:16:19.581Z,1629072979.581 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Derivation.cfg
2021-08-16T00:16:19.707Z,1629072979.707 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/logger.cfg
2021-08-16T00:16:19.820Z,1629072979.820 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/secure.cfg
2021-08-16T00:16:19.907Z,1629072979.907 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Dock.cfg
2021-08-16T00:16:19.994Z,1629072979.994 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Servo.cfg
2021-08-16T00:16:20.105Z,1629072980.105 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/workSite.cfg
2021-08-16T00:16:20.204Z,1629072980.204 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Sensor.cfg
2021-08-16T00:16:20.402Z,1629072980.402 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Science.cfg
2021-08-16T00:16:20.567Z,1629072980.567 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2021-08-16T00:16:20.571Z,1629072980.571 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2021-08-16T00:16:21.271Z,1629072981.271 [AHRS_M2] Loaded
2021-08-16T00:16:21.272Z,1629072981.272 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2021-08-16T00:16:21.517Z,1629072981.517 [BackseatComponent] Loaded
2021-08-16T00:16:21.517Z,1629072981.517 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2021-08-16T00:16:21.518Z,1629072981.518 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 4079A4E0
2021-08-16T00:16:21.519Z,1629072981.519 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 931
2021-08-16T00:16:21.521Z,1629072981.521 [LcmUniversalReporter] Loaded
2021-08-16T00:16:21.522Z,1629072981.522 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2021-08-16T00:16:22.301Z,1629072982.301 [BPC1] Loaded
2021-08-16T00:16:22.301Z,1629072982.301 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2021-08-16T00:16:22.440Z,1629072982.440 [DataOverHttps] Loaded
2021-08-16T00:16:22.441Z,1629072982.441 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2021-08-16T00:16:22.442Z,1629072982.442 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407CA4E0
2021-08-16T00:16:22.442Z,1629072982.442 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 932
2021-08-16T00:16:22.464Z,1629072982.464 [DDM] Loaded
2021-08-16T00:16:22.465Z,1629072982.465 [ComponentRegistry](DEBUG): SyncComponent "DDM" handled in the control thread.
2021-08-16T00:16:22.484Z,1629072982.484 [Depth_Keller] Loaded
2021-08-16T00:16:22.484Z,1629072982.484 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2021-08-16T00:16:22.488Z,1629072982.488 [DropWeight] Loaded
2021-08-16T00:16:22.489Z,1629072982.489 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2021-08-16T00:16:22.533Z,1629072982.533 [DUSBL_Hydroid] Loaded
2021-08-16T00:16:22.533Z,1629072982.533 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2021-08-16T00:16:22.570Z,1629072982.570 [Micromodem] Loaded
2021-08-16T00:16:22.570Z,1629072982.570 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2021-08-16T00:16:22.679Z,1629072982.679 [NAL9602] Loaded
2021-08-16T00:16:22.680Z,1629072982.680 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2021-08-16T00:16:22.730Z,1629072982.730 [Onboard] Loaded
2021-08-16T00:16:22.731Z,1629072982.731 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2021-08-16T00:16:22.756Z,1629072982.756 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 407FA4E0
2021-08-16T00:16:22.756Z,1629072982.756 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 933
2021-08-16T00:16:22.763Z,1629072982.763 [PowerOnly](INFO): Adding load control power supply at /dev/loadC1
2021-08-16T00:16:22.821Z,1629072982.821 [PowerOnly] Loaded
2021-08-16T00:16:22.821Z,1629072982.821 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2021-08-16T00:16:22.913Z,1629072982.913 [Power24vConverter] Loaded
2021-08-16T00:16:22.914Z,1629072982.914 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2021-08-16T00:16:22.943Z,1629072982.943 [Radio_Surface] Loaded
2021-08-16T00:16:22.964Z,1629072982.964 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2021-08-16T00:16:22.965Z,1629072982.965 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4082A4E0
2021-08-16T00:16:22.965Z,1629072982.965 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 934
2021-08-16T00:16:23.145Z,1629072983.145 [RDI_Pathfinder] Loaded
2021-08-16T00:16:23.145Z,1629072983.145 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2021-08-16T00:16:23.258Z,1629072983.258 [RDI_PathfinderUp] Loaded
2021-08-16T00:16:23.258Z,1629072983.258 [ComponentRegistry](DEBUG): SyncComponent "RDI_PathfinderUp" handled in the control thread.
2021-08-16T00:16:23.259Z,1629072983.259 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2021-08-16T00:16:23.358Z,1629072983.358 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2021-08-16T00:16:23.375Z,1629072983.375 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2021-08-16T00:16:23.376Z,1629072983.376 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2021-08-16T00:16:23.476Z,1629072983.476 [DeadReckonUsingMultipleVelocitySources] Loaded
2021-08-16T00:16:23.476Z,1629072983.476 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2021-08-16T00:16:23.489Z,1629072983.489 [NavChart] Loaded
2021-08-16T00:16:23.490Z,1629072983.490 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2021-08-16T00:16:23.496Z,1629072983.496 [UniversalFixResidualReporter] Loaded
2021-08-16T00:16:23.496Z,1629072983.496 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2021-08-16T00:16:23.506Z,1629072983.506 [WorkSite] Loaded
2021-08-16T00:16:23.507Z,1629072983.507 [ComponentRegistry](DEBUG): SyncComponent "WorkSite" handled in the control thread.
2021-08-16T00:16:23.507Z,1629072983.507 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2021-08-16T00:16:23.508Z,1629072983.508 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2021-08-16T00:16:23.628Z,1629072983.628 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2021-08-16T00:16:23.629Z,1629072983.629 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2021-08-16T00:16:23.791Z,1629072983.791 [BuoyancyServo] Loaded
2021-08-16T00:16:23.791Z,1629072983.791 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2021-08-16T00:16:23.813Z,1629072983.813 [ElevatorServo] Loaded
2021-08-16T00:16:23.813Z,1629072983.813 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2021-08-16T00:16:23.834Z,1629072983.834 [MassServo] Loaded
2021-08-16T00:16:23.834Z,1629072983.834 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2021-08-16T00:16:23.854Z,1629072983.854 [RudderServo] Loaded
2021-08-16T00:16:23.855Z,1629072983.855 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2021-08-16T00:16:23.873Z,1629072983.873 [ThrusterServo] Loaded
2021-08-16T00:16:23.874Z,1629072983.874 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2021-08-16T00:16:23.874Z,1629072983.874 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2021-08-16T00:16:23.875Z,1629072983.875 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2021-08-16T00:16:24.101Z,1629072984.101 [CTD_Seabird] Loaded
2021-08-16T00:16:24.101Z,1629072984.101 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2021-08-16T00:16:24.102Z,1629072984.102 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409544E0
2021-08-16T00:16:24.102Z,1629072984.102 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 935
2021-08-16T00:16:24.136Z,1629072984.136 [WetLabsSeaOWL_UV_A] Loaded
2021-08-16T00:16:24.136Z,1629072984.136 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2021-08-16T00:16:24.137Z,1629072984.137 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 409844E0
2021-08-16T00:16:24.137Z,1629072984.137 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 936
2021-08-16T00:16:24.138Z,1629072984.138 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2021-08-16T00:16:24.139Z,1629072984.139 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2021-08-16T00:16:24.522Z,1629072984.522 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2021-08-16T00:16:24.524Z,1629072984.524 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2021-08-16T00:16:24.586Z,1629072984.586 [DepthRateCalculator] Loaded
2021-08-16T00:16:24.587Z,1629072984.587 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2021-08-16T00:16:24.592Z,1629072984.592 [PitchRateCalculator] Loaded
2021-08-16T00:16:24.593Z,1629072984.593 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2021-08-16T00:16:24.602Z,1629072984.602 [SpeedCalculator] Loaded
2021-08-16T00:16:24.602Z,1629072984.602 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2021-08-16T00:16:24.615Z,1629072984.615 [TempGradientCalculator] Loaded
2021-08-16T00:16:24.616Z,1629072984.616 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2021-08-16T00:16:24.631Z,1629072984.631 [VerticalHomogeneityIndexCalculator] Loaded
2021-08-16T00:16:24.632Z,1629072984.632 [ComponentRegistry](DEBUG): SyncComponent "VerticalHomogeneityIndexCalculator" handled in the control thread.
2021-08-16T00:16:24.637Z,1629072984.637 [YawRateCalculator] Loaded
2021-08-16T00:16:24.637Z,1629072984.637 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2021-08-16T00:16:24.659Z,1629072984.659 [ElevatorOffsetCalculator] Loaded
2021-08-16T00:16:24.659Z,1629072984.659 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2021-08-16T00:16:24.660Z,1629072984.660 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2021-08-16T00:16:24.661Z,1629072984.661 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2021-08-16T00:16:24.839Z,1629072984.839 [SBIT](DEBUG): Construct Startup Built In Test.
2021-08-16T00:16:24.852Z,1629072984.852 [SBIT] Loaded
2021-08-16T00:16:24.852Z,1629072984.852 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2021-08-16T00:16:24.855Z,1629072984.855 [IBIT](DEBUG): Construct Initiated Built In Test.
2021-08-16T00:16:24.869Z,1629072984.869 [IBIT] Loaded
2021-08-16T00:16:24.869Z,1629072984.869 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2021-08-16T00:16:24.875Z,1629072984.875 [CBIT](DEBUG): Construct Continuous Built In Test.
2021-08-16T00:16:24.979Z,1629072984.979 [CBIT] Loaded
2021-08-16T00:16:24.980Z,1629072984.980 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2021-08-16T00:16:24.980Z,1629072984.980 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2021-08-16T00:16:24.981Z,1629072984.981 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2021-08-16T00:16:25.078Z,1629072985.078 [StratificationFrontDetector](IMPORTANT): thresholdVTHI set to: 0.399988 degC
2021-08-16T00:16:25.078Z,1629072985.078 [StratificationFrontDetector](INFO): (re)initializing
2021-08-16T00:16:25.078Z,1629072985.078 [StratificationFrontDetector] Loaded
2021-08-16T00:16:25.078Z,1629072985.078 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2021-08-16T00:16:25.079Z,1629072985.079 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2021-08-16T00:16:25.079Z,1629072985.079 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2021-08-16T00:16:25.216Z,1629072985.216 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2021-08-16T00:16:25.217Z,1629072985.217 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2021-08-16T00:16:25.289Z,1629072985.289 [VerticalControl](DEBUG): Construct VerticalControl.
2021-08-16T00:16:25.342Z,1629072985.342 [VerticalControl] Loaded
2021-08-16T00:16:25.342Z,1629072985.342 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2021-08-16T00:16:25.346Z,1629072985.346 [HorizontalControl](DEBUG): Construct HorizontalControl.
2021-08-16T00:16:25.383Z,1629072985.383 [HorizontalControl] Loaded
2021-08-16T00:16:25.383Z,1629072985.383 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2021-08-16T00:16:25.386Z,1629072985.386 [SpeedControl](DEBUG): Construct SpeedControl.
2021-08-16T00:16:25.388Z,1629072985.388 [SpeedControl] Loaded
2021-08-16T00:16:25.388Z,1629072985.388 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2021-08-16T00:16:25.391Z,1629072985.391 [LoopControl](DEBUG): Construct LoopControl.
2021-08-16T00:16:25.391Z,1629072985.391 [LoopControl] Loaded
2021-08-16T00:16:25.392Z,1629072985.392 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2021-08-16T00:16:25.392Z,1629072985.392 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2021-08-16T00:16:25.393Z,1629072985.393 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2021-08-16T00:16:25.436Z,1629072985.436 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2021-08-16T00:16:25.442Z,1629072985.442 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2021-08-16T00:16:25.445Z,1629072985.445 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2021-08-16T00:16:25.457Z,1629072985.457 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2021-08-16T00:16:25.458Z,1629072985.458 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B324E0
2021-08-16T00:16:25.458Z,1629072985.458 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 937
2021-08-16T00:16:25.463Z,1629072985.463 [Supervisor](INFO): Main Thread ID is 828
2021-08-16T00:16:25.463Z,1629072985.463 [Supervisor](DEBUG): Running supervisor.
2021-08-16T00:16:25.463Z,1629072985.463 [CommandLine ThreadHandler](INFO): Handler Thread ID is 938
2021-08-16T00:16:25.466Z,1629072985.466 [controlThread ThreadHandler](INFO): Handler Thread ID is 939
2021-08-16T00:16:25.466Z,1629072985.466 [controlThread](DEBUG): Initializing ControlThread
2021-08-16T00:16:25.476Z,1629072985.476 [NavChart](DEBUG): Initialize NavChart Navigation.
2021-08-16T00:16:25.476Z,1629072985.476 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2021-08-16T00:16:25.477Z,1629072985.477 [WorkSite](DEBUG): Initializing WorkSite component.
2021-08-16T00:16:25.478Z,1629072985.478 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2021-08-16T00:16:25.478Z,1629072985.478 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2021-08-16T00:16:25.479Z,1629072985.479 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2021-08-16T00:16:25.479Z,1629072985.479 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2021-08-16T00:16:25.480Z,1629072985.480 [VerticalHomogeneityIndexCalculator](DEBUG): (re)initializing
2021-08-16T00:16:25.481Z,1629072985.481 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2021-08-16T00:16:25.481Z,1629072985.481 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2021-08-16T00:16:25.481Z,1629072985.481 [SBIT](INFO): Initialize SBIT Component.
2021-08-16T00:16:25.482Z,1629072985.482 [SBIT](IMPORTANT): git: 2021-08-12
2021-08-16T00:16:25.482Z,1629072985.482 [SBIT](INFO): git hash: 4ac1c7994e02762939ba6e7c4596a90b7f61f056
2021-08-16T00:16:25.483Z,1629072985.483 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2021-08-16T00:16:25.484Z,1629072985.484 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Thu Aug 6 12:04:53 PDT 2020
2021-08-16T00:16:25.485Z,1629072985.485 [SBIT](INFO): Beginning SBIT in 36.000000 seconds.
2021-08-16T00:16:25.486Z,1629072985.486 [IBIT](INFO): Initialize IBIT Component.
2021-08-16T00:16:25.486Z,1629072985.487 [CBIT](DEBUG): Initialize CBIT Component.
2021-08-16T00:16:25.487Z,1629072985.487 [logger ThreadHandler](INFO): Handler Thread ID is 940
2021-08-16T00:16:25.500Z,1629072985.500 [CBIT](DEBUG): Initialized mux pins.
2021-08-16T00:16:25.500Z,1629072985.500 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2021-08-16T00:16:25.500Z,1629072985.500 [CBIT](DEBUG): Initializing the watchdog timer.
2021-08-16T00:16:25.508Z,1629072985.508 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 941
2021-08-16T00:16:25.520Z,1629072985.520 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 942
2021-08-16T00:16:25.521Z,1629072985.521 [DataOverHttps](DEBUG): dashIP=128.128.181.155 starts with a digit so assuming it is a numeric IP
2021-08-16T00:16:25.524Z,1629072985.524 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2021-08-16T00:16:25.528Z,1629072985.528 [CBIT](FAULT): Found backtrace file:
1629072857.640386 [DataOverHttps]: SIGSEGV: address not mapped to object
1629072857.640386 [DataOverHttps]: Backtrace:
./bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x1a11d0]


2021-08-16T00:16:25.530Z,1629072985.530 [Onboard ThreadHandler](INFO): Handler Thread ID is 943
2021-08-16T00:16:25.569Z,1629072985.569 [CBIT](FAULT): Renaming backtrace file to Data/backtrace12
2021-08-16T00:16:25.570Z,1629072985.570 [CBIT](DEBUG): Initializing heartbeat.
2021-08-16T00:16:25.570Z,1629072985.570 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 944
2021-08-16T00:16:25.580Z,1629072985.580 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 945
2021-08-16T00:16:25.581Z,1629072985.581 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2021-08-16T00:16:25.585Z,1629072985.585 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 947
2021-08-16T00:16:25.586Z,1629072985.586 [WetLabsSeaOWL_UV_A](INFO): Powering down
2021-08-16T00:16:25.597Z,1629072985.597 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 948
2021-08-16T00:16:25.605Z,1629072985.605 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2021-08-16T00:16:25.605Z,1629072985.605 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2021-08-16T00:16:25.606Z,1629072985.606 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2021-08-16T00:16:25.606Z,1629072985.606 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2021-08-16T00:16:25.606Z,1629072985.606 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2021-08-16T00:16:25.606Z,1629072985.606 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2021-08-16T00:16:25.606Z,1629072985.606 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2021-08-16T00:16:25.606Z,1629072985.606 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2021-08-16T00:16:25.607Z,1629072985.607 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2021-08-16T00:16:25.607Z,1629072985.607 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2021-08-16T00:16:25.607Z,1629072985.607 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2021-08-16T00:16:25.607Z,1629072985.607 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2021-08-16T00:16:25.607Z,1629072985.607 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2021-08-16T00:16:25.608Z,1629072985.608 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2021-08-16T00:16:25.608Z,1629072985.608 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2021-08-16T00:16:25.608Z,1629072985.608 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2021-08-16T00:16:25.640Z,1629072985.640 [CBIT](DEBUG): Deactivating GF circuits.
2021-08-16T00:16:25.640Z,1629072985.640 [CBIT](DEBUG): Deactivating emergency mode.
2021-08-16T00:16:25.676Z,1629072985.676 [CBIT](DEBUG): Backplane powered.
2021-08-16T00:16:25.676Z,1629072985.676 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2021-08-16T00:16:25.678Z,1629072985.678 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2021-08-16T00:16:25.679Z,1629072985.679 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2021-08-16T00:16:25.680Z,1629072985.680 [LoopControl](DEBUG): Initialize LoopControlComponent.
2021-08-16T00:16:25.681Z,1629072985.681 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2021-08-16T00:16:25.707Z,1629072985.707 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2021-08-16T00:16:25.731Z,1629072985.731 [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-08-16T00:16:25.756Z,1629072985.756 [MissionManager](INFO): Loading Mission: Missions/underIce/DefaultWithUndock.xml
2021-08-16T00:16:25.893Z,1629072985.893 [MissionManager](INFO): DefineArg DefaultWithUndock.ElapsedSinceDefaultStarted = 0.000000 min
2021-08-16T00:16:25.905Z,1629072985.905 [MissionManager](INFO): DefineArg DefaultWithUndock.DetachTimeout = 30.000000 min
2021-08-16T00:16:25.910Z,1629072985.910 [MissionManager](INFO): DefineArg DefaultWithUndock.TransponderCode = 2.000000 count
2021-08-16T00:16:25.946Z,1629072985.946 [MissionManager](INFO): DefineArg DefaultWithUndock.TrackingUpdatePeriod = 2.500000 s
2021-08-16T00:16:25.949Z,1629072985.949 [MissionManager](INFO): DefineArg DefaultWithUndock.NumberOfPings = 1.000000 count
2021-08-16T00:16:25.966Z,1629072985.966 [MissionManager](INFO): DefineArg DefaultWithUndock.DetachModeDDM = 2.000000 count
2021-08-16T00:16:25.967Z,1629072985.967 [DefaultWithUndock:A.Wait](DEBUG): Construct Wait.
2021-08-16T00:16:25.972Z,1629072985.972 [Radio_Surface](INFO): Powering up
2021-08-16T00:16:26.106Z,1629072986.106 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Construct.
2021-08-16T00:16:26.106Z,1629072986.106 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values.
2021-08-16T00:16:26.158Z,1629072986.158 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): Construct GoToSurface.
2021-08-16T00:16:26.210Z,1629072986.210 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2021-08-16T00:16:26.221Z,1629072986.221 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Construct Wait.
2021-08-16T00:16:26.227Z,1629072986.227 [DefaultWithUndock:E.Execute](DEBUG): Construct Execute.
2021-08-16T00:16:26.256Z,1629072986.256 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Control="Tethys/Control"
         xmlns:Dock="Tethys/Dock"
         xmlns:Estimation="Tethys/Estimation"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Sensor="Tethys/Sensor"
         xmlns:Units="Tethys/Units"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                             Tethys/Dock http://okeanids.mbari.org/tethys/Xml/Dock.xsd
                             Tethys/Estimation http://okeanids.mbari.org/tethys/Xml/Estimation.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Sensor http://okeanids.mbari.org/tethys/Xml/Sensor.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="DefaultWithUndock">

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

    <DefineArg Name="DetachTimeout"><Description>
        Maximum time duration for the vehicle to detach form the dock.
    </Description><Units:minute/><Value>30</Value></DefineArg>

    <DefineArg Name="TransponderCode"><Description>
        Dock transponder address.
    </Description><Dock:Dock.transponderCode/></DefineArg>

    <DefineArg Name="TrackingUpdatePeriod"><Description>
        Time duration between acoustic range queries while the mission is
        detaching from the dock.
    </Description><Units:second/><Value>2.5</Value></DefineArg>

    <DefineArg Name="NumberOfPings"><Description>
        Number of pings requested each time.
    </Description><Units:count/><Value>1</Value></DefineArg>

    <DefineArg Name="DetachModeDDM"><Description>
        DDM DETACH mode enumeration (whiskers retracted, latch open).
    </Description><Units:count/><Value>2</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>30</Value></Setting>
    </Guidance:Wait>

    <Aggregate Id="LeaveDock">

        <Sequence/>

        <Timeout Duration="DetachTimeout">
            <Syslog Severity="Important">Timed out while trying to detach from dock at current depth of <Universal:depth/><Units:meter/>.</Syslog>
        </Timeout>

<!-- Acoustic tracking directives -->

        <Estimation:TrackAcousticContact>
            <Parallel/>
            <Setting><Estimation:TrackAcousticContact.contactLabelSetting/><Arg Name="TransponderCode"/></Setting>
            <Setting><Estimation:TrackAcousticContact.numberOfSamplesSetting/><Arg Name="NumberOfPings"/></Setting>
            <Setting><Estimation:TrackAcousticContact.updatePeriodSetting/><Arg Name="TrackingUpdatePeriod"/></Setting>
        </Estimation:TrackAcousticContact>

<!-- Leave the dock -->

        <Dock:Undock>
            <Sequence/>
        </Dock:Undock>

    </Aggregate>

    <Aggregate Id="SurfaceDefault">

        <Sequence/>

        <Aggregate Id="HoldLatchOpen">

            <While>
                <Universal:depth/>
                <Gt><Control:VerticalControl.surfaceThreshold/></Gt>
            </While>

<!-- Power the DDM -->

            <ReadData>
                <Dock:Dock.docking_state/>
            </ReadData>

<!-- Hold the DDM in DETACH mode (whiskers retracted, latch open) -->

            <Assign><Parallel/><Dock:Dock.docking_state_cmd/><Arg Name="DetachModeDDM"/></Assign>

        </Aggregate>

<!-- This mission assumes open water so from here on it's the same old default that's always used -->

        <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>

    </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-08-16T00:16:26.262Z,1629072986.262 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,DDM,Depth_Keller,DropWeight,DUSBL_Hydroid,Micromodem,NAL9602,PowerOnly,Power24vConverter,RDI_Pathfinder,RDI_PathfinderUp,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,WorkSite,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2021-08-16T00:16:26.284Z,1629072986.284 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2021-08-16T00:16:26.417Z,1629072986.417 [DDM](INFO): Powering up
2021-08-16T00:16:26.417Z,1629072986.417 [DDM](DEBUG): Initializing DDM.
2021-08-16T00:16:26.441Z,1629072986.441 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar
2021-08-16T00:16:26.441Z,1629072986.441 [DUSBL_Hydroid](INFO): Powering up
2021-08-16T00:16:26.442Z,1629072986.442 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2021-08-16T00:16:26.457Z,1629072986.457 [Power24vConverter](INFO): Powering up.
2021-08-16T00:16:26.476Z,1629072986.476 [DepthRateCalculator](ERROR): Depth measurement is not active
2021-08-16T00:16:26.505Z,1629072986.505 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2021-08-16T00:16:26.512Z,1629072986.512 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2021-08-16T00:16:26.513Z,1629072986.513 [ElevatorServo](DEBUG): Initializing EZServoServo.
2021-08-16T00:16:26.520Z,1629072986.520 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2021-08-16T00:16:26.521Z,1629072986.521 [MassServo](DEBUG): Initializing EZServoServo.
2021-08-16T00:16:26.529Z,1629072986.529 [MassServo](DEBUG): Initializing MassServo.
2021-08-16T00:16:26.529Z,1629072986.529 [RudderServo](DEBUG): Initializing EZServoServo.
2021-08-16T00:16:26.536Z,1629072986.536 [RudderServo](DEBUG): Initializing RudderServo.
2021-08-16T00:16:26.537Z,1629072986.537 [ThrusterServo](DEBUG): Initializing EZServoServo.
2021-08-16T00:16:26.544Z,1629072986.544 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2021-08-16T00:16:26.546Z,1629072986.546 [CommandLine](FAULT): Scheduling is paused
2021-08-16T00:16:26.547Z,1629072986.547 [CBIT](INFO): Critical error at 20210816T001625
2021-08-16T00:16:26.547Z,1629072986.547 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2021-08-16T00:16:26.692Z,1629072986.692 [Micromodem](INFO): Powering up
2021-08-16T00:16:26.692Z,1629072986.692 [Micromodem](DEBUG): Initializing Micromodem.
2021-08-16T00:16:27.400Z,1629072987.400 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2021-08-16T00:16:27.400Z,1629072987.400 [RudderServo](FAULT): Rudder failed to initialize
2021-08-16T00:16:27.400Z,1629072987.400 [RudderServo] Communications Fault, FailCount= 1
2021-08-16T00:16:27.400Z,1629072987.400 [RudderServo](ERROR): Communications Fault
2021-08-16T00:16:27.500Z,1629072987.500 [CBIT](ERROR): Communications Fault in component: RudderServo
2021-08-16T00:16:27.669Z,1629072987.669 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2021-08-16T00:16:27.669Z,1629072987.669 [RudderServo](INFO): Powering down
2021-08-16T00:16:28.328Z,1629072988.328 [RudderServo](DEBUG): Initializing EZServoServo.
2021-08-16T00:16:28.449Z,1629072988.449 [RudderServo](DEBUG): Initializing RudderServo.
2021-08-16T00:16:28.455Z,1629072988.455 [CBIT](INFO): Clearing failed state for component RudderServo
2021-08-16T00:16:28.455Z,1629072988.455 [RudderServo] No Fault, FailCount= 1
2021-08-16T00:16:31.595Z,1629072991.595 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33

2021-08-16T00:16:35.595Z,1629072995.595 [Micromodem](INFO): Nmea in: $CATMG,2021-08-16T00:16:34.582777Z,RTC,RTC*56

2021-08-16T00:16:35.595Z,1629072995.595 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2021-08-16T00:16:34.582777Z,RTC,RTC*56

2021-08-16T00:16:42.054Z,1629073002.054 [DDM](INFO): Dynamic Docking Module:
2021-08-16T00:16:42.894Z,1629073002.894 [Micromodem](ERROR): Nmea resend: $CCCFG,ALL,0*33

2021-08-16T00:16:43.270Z,1629073003.270 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31

2021-08-16T00:16:43.271Z,1629073003.271 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31

2021-08-16T00:16:43.674Z,1629073003.674 [Micromodem](INFO): Nmea in: $CACFG,SRC,1*33

2021-08-16T00:16:43.675Z,1629073003.675 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64

2021-08-16T00:16:44.079Z,1629073004.079 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66

2021-08-16T00:16:44.079Z,1629073004.079 [Micromodem](INFO): Nmea out: $CCCFG,pwramp.txlevel,0*2F

2021-08-16T00:16:44.486Z,1629073004.486 [DUSBL_Hydroid](INFO): DUSBL Version:O
2021-08-16T00:16:45.290Z,1629073005.290 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,0*2D

2021-08-16T00:16:45.290Z,1629073005.290 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E

2021-08-16T00:16:45.694Z,1629073005.694 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C

2021-08-16T00:16:45.694Z,1629073005.694 [Micromodem](INFO): Nmea out: $CCCFG,FC0,14500*47

2021-08-16T00:16:46.098Z,1629073006.098 [Micromodem](INFO): Nmea in: $CACFG,FC0,14500*45

2021-08-16T00:16:46.098Z,1629073006.098 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63

2021-08-16T00:16:46.502Z,1629073006.502 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61

2021-08-16T00:16:46.502Z,1629073006.502 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A

2021-08-16T00:16:46.951Z,1629073006.951 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38

2021-08-16T00:16:46.962Z,1629073006.962 [Micromodem](INFO): Nmea out: $CCCLK,2021,08,16,00,16,47*4E

2021-08-16T00:16:47.310Z,1629073007.310 [Micromodem](INFO): Nmea in: $CACLK,2021,8,16,0,16,47*4C

2021-08-16T00:16:47.714Z,1629073007.714 [Micromodem](INFO): Nmea in: $CATMS,0,2021-08-16T00:16:48Z*73

2021-08-16T00:16:47.716Z,1629073007.716 [Micromodem](INFO): Nmea in: $CATMG,2021-08-16T00:16:48.027051Z,USER_CMD,RTC*15

2021-08-16T00:16:52.983Z,1629073012.983 [NAL9602](INFO): Powering up NAL9602
2021-08-16T00:17:01.867Z,1629073021.867 [SBIT](IMPORTANT): Beginning Startup BIT
2021-08-16T00:17:01.872Z,1629073021.872 [CBIT](IMPORTANT): Beginning ground fault scan
2021-08-16T00:17:03.875Z,1629073023.875 [NAL9602](INFO): NAL9602 initialized
2021-08-16T00:17:12.854Z,1629073032.854 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.005770
CHAN A1 (24V): -0.024417
CHAN A2 (12V): -0.005840
CHAN A3 (5V): -0.002025
CHAN B0 (3.3V): 0.000202
CHAN B1 (3.15aV): 0.000505
CHAN B2 (3.15bV): 0.000614
CHAN B3 (GND): 0.001931
OPEN: 0.008529
Full Scale Calc: 4.765 mA, -1.589 mA
2021-08-16T00:17:16.820Z,1629073036.820 [NAL9602](INFO): SBD MO Status=0, MOMSN=24189, MT Status=0, MTMSN=0
2021-08-16T00:17:16.820Z,1629073036.820 [NAL9602](INFO): No messages in MT queue
2021-08-16T00:17:49.952Z,1629073069.952 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC, Data Header,2*00

2021-08-16T00:17:49.957Z,1629073069.957 [Micromodem](INFO): Nmea in: $CACST,6,1,20210816001749.592132,06,956,23,0092,0150,208,02,02,01,02,1,-01,-01,2,4,1,0,150,-18.8,1.36,01,1.64,-01,-1.26,65,14500,4000*74

2021-08-16T00:17:56.020Z,1629073076.020 [SBIT](IMPORTANT): SBIT PASSED
2021-08-16T00:17:56.021Z,1629073076.021 [SBIT](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2021-08-16T00:17:56.432Z,1629073076.432 [WorkSite](IMPORTANT): Reading workSite position from Data/workSite.cfg
2021-08-16T00:17:56.436Z,1629073076.436 [WorkSite](IMPORTANT): WorkSite fix at 20210816T001352: (41.555130, -70.712816)
2021-08-16T00:17:56.438Z,1629073076.438 [MissionManager](IMPORTANT): Started mission Startup
2021-08-16T00:17:56.438Z,1629073076.438 [Startup] Running Loop=1
2021-08-16T00:17:56.438Z,1629073076.438 [Startup](DEBUG): Aggregate::initialize Startup
2021-08-16T00:17:56.439Z,1629073076.439 [Startup:A.GoToSurface] Running Loop=1
2021-08-16T00:17:56.439Z,1629073076.439 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-08-16T00:17:56.439Z,1629073076.439 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-08-16T00:17:56.472Z,1629073076.472 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-08-16T00:17:56.473Z,1629073076.473 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-08-16T00:17:56.473Z,1629073076.473 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-08-16T00:17:56.473Z,1629073076.473 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-08-16T00:17:56.475Z,1629073076.475 [Startup:StartupSatComms] Running Loop=1
2021-08-16T00:17:56.475Z,1629073076.475 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2021-08-16T00:17:56.475Z,1629073076.475 [Startup:StartupSatComms:A] Running Loop=1
2021-08-16T00:17:56.899Z,1629073076.899 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2021-08-16T00:17:57.639Z,1629073077.639 [Micromodem](INFO): Nmea in: $CAMSG,Error accessing coproc,4*51

2021-08-16T00:17:57.658Z,1629073077.658 [Micromodem](INFO): Nmea in: $CACST,6,1,20210816001757.593590,06,214,23,0091,0150,194,02,02,00,02,-1,-01,-01,4,3,0,0,-999,-99.9,-9.99,-999,-9.99,-01,0.00,-999,14500,4000*57

2021-08-16T00:18:26.701Z,1629073106.701 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,001825.00,A,4133.32051,N,07042.80866,W,0.564,231.50,160821,,,A*7D
2021-08-16T00:18:26.704Z,1629073106.704 [NAL9602](INFO): GPS fix at 20210816T001825: (41.555342, -70.713478)
2021-08-16T00:18:26.715Z,1629073106.715 [Startup:StartupSatComms:A] Stopped
2021-08-16T00:18:26.715Z,1629073106.715 [Startup:StartupSatComms:B] Running Loop=1
2021-08-16T00:18:27.166Z,1629073107.166 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-08-16T00:18:46.856Z,1629073126.856 [NAL9602](INFO): SBD MO Status=1, MOMSN=24190, MT Status=0, MTMSN=0
2021-08-16T00:18:46.901Z,1629073126.901 [NAL9602](INFO): Sent 52 bytes from file Logs/20210816T001014/Courier0007.lzma
2021-08-16T00:18:46.902Z,1629073126.902 [NAL9602](INFO): Packets left to send: 0
2021-08-16T00:19:06.137Z,1629073146.137 [NAL9602](INFO): SBD MO Status=2, MOMSN=24191, MT Status=2, MTMSN=0
2021-08-16T00:19:06.137Z,1629073146.137 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-08-16T00:19:25.454Z,1629073165.454 [NAL9602](INFO): SBD MO Status=2, MOMSN=24191, MT Status=2, MTMSN=0
2021-08-16T00:19:25.455Z,1629073165.455 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-08-16T00:19:26.720Z,1629073166.720 [Startup:StartupSatComms:B](INFO): Timed out from 2021-08-16T00:18:26.7Z
2021-08-16T00:19:26.721Z,1629073166.721 [Startup:StartupSatComms:B] Stopped
2021-08-16T00:19:26.721Z,1629073166.721 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2021-08-16T00:19:26.721Z,1629073166.721 [Startup:StartupSatComms] Stopped
2021-08-16T00:19:26.721Z,1629073166.721 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2021-08-16T00:19:26.722Z,1629073166.722 [Startup](INFO): Completed Startup
2021-08-16T00:19:26.722Z,1629073166.722 [MissionManager](INFO): Startup is completed.
2021-08-16T00:19:26.722Z,1629073166.722 [MissionManager](INFO): Uninitializing Mission Startup
2021-08-16T00:19:26.722Z,1629073166.722 [Startup] Stopped
2021-08-16T00:19:26.722Z,1629073166.722 [Startup](DEBUG): Aggregate::uninitialize Startup
2021-08-16T00:19:26.722Z,1629073166.722 [Startup:A.GoToSurface] Stopped
2021-08-16T00:19:26.723Z,1629073166.723 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-08-16T00:19:27.131Z,1629073167.131 [MissionManager](IMPORTANT): Started mission DefaultWithUndock
2021-08-16T00:19:27.131Z,1629073167.131 [DefaultWithUndock] Running Loop=1
2021-08-16T00:19:27.131Z,1629073167.131 [DefaultWithUndock](DEBUG): Aggregate::initialize DefaultWithUndock
2021-08-16T00:19:27.131Z,1629073167.131 [DefaultWithUndock:A.Wait] Running Loop=1
2021-08-16T00:19:27.131Z,1629073167.131 [DefaultWithUndock:A.Wait](DEBUG): Initialize Wait Component.
2021-08-16T00:19:36.546Z,1629073176.546 [NAL9602](INFO): SBD MO Status=1, MOMSN=24191, MT Status=0, MTMSN=0
2021-08-16T00:19:36.608Z,1629073176.608 [NAL9602](INFO): Sent 18 bytes from file Logs/20210816T001014/Courier0013.lzma
2021-08-16T00:19:36.608Z,1629073176.608 [NAL9602](INFO): Packets left to send: 0
2021-08-16T00:19:48.358Z,1629073188.358 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004755
2021-08-16T00:19:57.169Z,1629073197.169 [DefaultWithUndock:A.Wait](INFO): Done Waiting.
2021-08-16T00:19:57.170Z,1629073197.170 [DefaultWithUndock:A.Wait] Stopped
2021-08-16T00:19:57.170Z,1629073197.170 [DefaultWithUndock:A.Wait](DEBUG): Uninitialize Wait Component.
2021-08-16T00:19:57.170Z,1629073197.170 [DefaultWithUndock:LeaveDock] Running Loop=1
2021-08-16T00:19:57.170Z,1629073197.170 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::initialize DefaultWithUndock:LeaveDock
2021-08-16T00:19:57.171Z,1629073197.171 [DefaultWithUndock:LeaveDock:A.] Running Loop=1
2021-08-16T00:19:57.171Z,1629073197.171 [DefaultWithUndock:LeaveDock:A.](INFO): Initializing TrackAcousticContact.
2021-08-16T00:19:57.172Z,1629073197.172 [DefaultWithUndock:LeaveDock:B.Undock] Running Loop=1
2021-08-16T00:19:57.172Z,1629073197.172 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initialize.
2021-08-16T00:19:57.173Z,1629073197.173 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values.
2021-08-16T00:19:57.595Z,1629073197.595 [DefaultWithUndock:LeaveDock:A.] Running Loop=1
2021-08-16T00:19:57.956Z,1629073197.956 [PowerOnly](INFO): Powering up loadControl
2021-08-16T00:19:59.680Z,1629073199.680 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2021-08-16T00:20:00.415Z,1629073200.415 [Micromodem](INFO): Nmea out: $CCPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*76

2021-08-16T00:20:00.833Z,1629073200.833 [Micromodem](INFO): Nmea in: $SNPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6B

2021-08-16T00:20:01.658Z,1629073201.658 [Micromodem](INFO): Nmea in: $SNTTA,,,,,002000.89*5D

2021-08-16T00:20:01.670Z,1629073201.670 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detaching from dock.
2021-08-16T00:20:02.036Z,1629073202.036 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detected possible detachment. Starting timer.
2021-08-16T00:20:02.459Z,1629073202.459 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2021-08-16T00:20:04.045Z,1629073204.045 [DUSBL_Hydroid](ERROR): No response from remote modem.
2021-08-16T00:20:05.330Z,1629073205.330 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2021-08-16T00:20:06.067Z,1629073206.067 [Micromodem](INFO): Nmea out: $CCPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*76

2021-08-16T00:20:06.464Z,1629073206.464 [Micromodem](INFO): Nmea in: $SNPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6B

2021-08-16T00:20:07.386Z,1629073207.386 [Micromodem](INFO): Nmea in: $SNTTA,,,,,002006.57*58

2021-08-16T00:20:07.398Z,1629073207.398 [NAL9602](INFO): Not Powering down - fast GPS
2021-08-16T00:20:08.102Z,1629073208.102 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2021-08-16T00:20:09.702Z,1629073209.702 [DUSBL_Hydroid](ERROR): No response from remote modem.
2021-08-16T00:20:11.013Z,1629073211.013 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2021-08-16T00:20:11.718Z,1629073211.718 [Micromodem](INFO): Nmea out: $CCPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*76

2021-08-16T00:20:12.133Z,1629073212.133 [Micromodem](INFO): Nmea in: $SNPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6B

2021-08-16T00:20:12.946Z,1629073212.946 [Micromodem](INFO): Nmea in: $SNTTA,,,,,002012.20*5D

2021-08-16T00:20:16.175Z,1629073216.175 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2021-08-16T00:20:17.026Z,1629073217.026 [Micromodem](INFO): Nmea out: $CCPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*76

2021-08-16T00:20:17.386Z,1629073217.386 [Micromodem](INFO): Nmea in: $SNPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6B

2021-08-16T00:20:18.586Z,1629073218.586 [Micromodem](INFO): Nmea in: $SNTTA,,,,,002017.51*5E

2021-08-16T00:20:19.024Z,1629073219.024 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2021-08-16T00:20:20.669Z,1629073220.669 [DUSBL_Hydroid](ERROR): No response from remote modem.
2021-08-16T00:20:21.842Z,1629073221.842 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2021-08-16T00:20:22.258Z,1629073222.258 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detached at range: 588.06 m. Transitioning DDM to standby.
2021-08-16T00:20:22.630Z,1629073222.630 [Micromodem](INFO): Nmea out: $CCPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*76

2021-08-16T00:20:23.032Z,1629073223.032 [Micromodem](INFO): Nmea in: $SNPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6B

2021-08-16T00:20:23.850Z,1629073223.850 [Micromodem](INFO): Nmea in: $SNTTA,,,,,002023.11*5D

2021-08-16T00:20:24.741Z,1629073224.741 [DefaultWithUndock:LeaveDock:B.Undock](INFO): DDM at standby.
2021-08-16T00:20:24.742Z,1629073224.742 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2021-08-16T00:20:25.061Z,1629073225.061 [DefaultWithUndock:LeaveDock:B.Undock](IMPORTANT): Undocking sequence complete.
2021-08-16T00:20:25.061Z,1629073225.061 [DefaultWithUndock:LeaveDock:B.Undock] Stopped
2021-08-16T00:20:25.061Z,1629073225.061 [DefaultWithUndock:LeaveDock](INFO): Completed DefaultWithUndock:LeaveDock
2021-08-16T00:20:25.061Z,1629073225.061 [DefaultWithUndock:LeaveDock] Stopped
2021-08-16T00:20:25.062Z,1629073225.062 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::uninitialize DefaultWithUndock:LeaveDock
2021-08-16T00:20:25.062Z,1629073225.062 [DefaultWithUndock:LeaveDock:A.] Stopped
2021-08-16T00:20:25.062Z,1629073225.062 [DefaultWithUndock:SurfaceDefault] Running Loop=1
2021-08-16T00:20:25.062Z,1629073225.062 [DefaultWithUndock:SurfaceDefault](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault
2021-08-16T00:20:25.062Z,1629073225.062 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen] Running Loop=1
2021-08-16T00:20:25.062Z,1629073225.062 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:HoldLatchOpen
2021-08-16T00:20:25.062Z,1629073225.062 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:A] Running Loop=1
2021-08-16T00:20:25.062Z,1629073225.062 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:B] Running Loop=1
2021-08-16T00:20:25.062Z,1629073225.062 [DefaultWithUndock:SurfaceDefault:B.GoToSurface] Running Loop=1
2021-08-16T00:20:25.062Z,1629073225.062 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-08-16T00:20:25.063Z,1629073225.063 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-08-16T00:20:25.063Z,1629073225.063 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-08-16T00:20:25.064Z,1629073225.064 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-08-16T00:20:25.064Z,1629073225.064 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-08-16T00:20:25.064Z,1629073225.064 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-08-16T00:20:25.493Z,1629073225.493 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=1
2021-08-16T00:20:25.493Z,1629073225.493 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2021-08-16T00:20:25.493Z,1629073225.493 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2021-08-16T00:20:25.493Z,1629073225.493 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen] Stopped
2021-08-16T00:20:25.493Z,1629073225.493 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:HoldLatchOpen
2021-08-16T00:20:25.493Z,1629073225.493 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:A] Stopped
2021-08-16T00:20:25.493Z,1629073225.493 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:B] Stopped
2021-08-16T00:20:25.870Z,1629073225.870 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2021-08-16T00:20:27.464Z,1629073227.464 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,002026.00,A,4133.32564,N,07042.82619,W,0.505,231.50,160821,,,A*75
2021-08-16T00:20:27.466Z,1629073227.466 [NAL9602](INFO): GPS fix at 20210816T002026: (41.555427, -70.713770)
2021-08-16T00:20:27.526Z,1629073227.526 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2021-08-16T00:20:27.526Z,1629073227.526 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2021-08-16T00:20:27.903Z,1629073227.903 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-08-16T00:20:31.804Z,1629073231.804 [DataOverHttps](INFO): Sending 317 bytes from file Logs/20210816T001613/Courier0000.lzma
2021-08-16T00:20:32.806Z,1629073232.806 [DataOverHttps](INFO): Moved sent file to Logs/20210816T001613/Courier0000.lzma.bak
2021-08-16T00:20:32.806Z,1629073232.806 [DataOverHttps](INFO): SBD MOMSN=445208
2021-08-16T00:20:41.843Z,1629073241.843 [DataOverHttps](INFO): Sending 79 bytes from file Logs/20210816T001613/Courier0004.lzma
2021-08-16T00:20:42.858Z,1629073242.858 [DataOverHttps](INFO): Moved sent file to Logs/20210816T001613/Courier0004.lzma.bak
2021-08-16T00:20:42.858Z,1629073242.858 [DataOverHttps](INFO): SBD MOMSN=445213
2021-08-16T00:20:43.608Z,1629073243.608 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=24192, MT Status=1, MTMSN=838
2021-08-16T00:20:43.608Z,1629073243.608 [NAL9602](INFO): Data available in MT queue
2021-08-16T00:20:44.269Z,1629073244.269 [NAL9602](INFO): Received command:configSet lineCapture.rolloutTimeout 10 min persist
2021-08-16T00:20:44.610Z,1629073244.610 [CommandLine](IMPORTANT): got command configSet LineCapture.rolloutTimeout 10.000000 minute persist
2021-08-16T00:20:44.611Z,1629073244.611 [CommandLine](FAULT): Not allowing to overwrite existing Data/persisted.cfg after unclean shutdown.
2021-08-16T00:20:51.899Z,1629073251.899 [DataOverHttps](INFO): Sending 1050 bytes from file Logs/20210816T001014/Express0001.lzma
2021-08-16T00:20:52.897Z,1629073252.897 [DataOverHttps](INFO): Moved sent file to Logs/20210816T001014/Express0001.lzma.bak
2021-08-16T00:20:52.898Z,1629073252.898 [DataOverHttps](INFO): SBD MOMSN=445216
2021-08-16T00:21:01.938Z,1629073261.938 [DataOverHttps](INFO): Sending 552 bytes from file Logs/20210816T001014/Express0005.lzma
2021-08-16T00:21:02.938Z,1629073262.938 [DataOverHttps](INFO): Moved sent file to Logs/20210816T001014/Express0005.lzma.bak
2021-08-16T00:21:02.938Z,1629073262.938 [DataOverHttps](INFO): SBD MOMSN=445242
2021-08-16T00:21:11.977Z,1629073271.977 [DataOverHttps](INFO): Sending 253 bytes from file Logs/20210816T001014/Express0011.lzma
2021-08-16T00:21:12.978Z,1629073272.978 [DataOverHttps](INFO): Moved sent file to Logs/20210816T001014/Express0011.lzma.bak
2021-08-16T00:21:12.978Z,1629073272.978 [DataOverHttps](INFO): SBD MOMSN=445251
2021-08-16T00:21:15.030Z,1629073275.030 [NAL9602](INFO): Not Powering down - fast GPS
2021-08-16T00:21:22.015Z,1629073282.015 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20210816T001014/Express0014.lzma
2021-08-16T00:21:23.017Z,1629073283.017 [DataOverHttps](INFO): Moved sent file to Logs/20210816T001014/Express0014.lzma.bak
2021-08-16T00:21:23.018Z,1629073283.018 [DataOverHttps](INFO): SBD MOMSN=445257
2021-08-16T00:21:29.570Z,1629073289.570 [PowerOnly](INFO): Powering down loadControl
2021-08-16T00:21:32.058Z,1629073292.058 [DataOverHttps](INFO): Sending 1033 bytes from file Logs/20210816T001613/Express0001.lzma
2021-08-16T00:21:33.057Z,1629073293.057 [DataOverHttps](INFO): Moved sent file to Logs/20210816T001613/Express0001.lzma.bak
2021-08-16T00:21:33.058Z,1629073293.058 [DataOverHttps](INFO): SBD MOMSN=445259
2021-08-16T00:21:43.108Z,1629073303.108 [DataOverHttps](INFO): Sending 276 bytes from file Logs/20210816T001613/Express0005.lzma
2021-08-16T00:21:44.106Z,1629073304.106 [DataOverHttps](INFO): Moved sent file to Logs/20210816T001613/Express0005.lzma.bak
2021-08-16T00:21:44.106Z,1629073304.106 [DataOverHttps](INFO): SBD MOMSN=445279
2021-08-16T00:21:45.746Z,1629073305.746 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2021-08-16T00:21:45.746Z,1629073305.746 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2021-08-16T00:21:45.747Z,1629073305.747 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-08-16T00:21:47.827Z,1629073307.827 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2021-08-16T00:21:48.150Z,1629073308.150 [Micromodem](INFO): Nmea in: $CACST,6,1,20210816002147.573369,06,1275,25,0106,0150,134,03,03,01,03,-1,-01,-01,1,3,7,0,150,13.1,-0.46,-100,3.46,-01,-1.20,55,14500,4000*71

2021-08-16T00:22:29.895Z,1629073349.895 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2021-08-16T00:22:29.899Z,1629073349.899 [Micromodem](INFO): Nmea in: $CACST,6,1,20210816002229.589538,06,1771,26,0128,0150,134,02,02,01,02,-1,-01,-01,1,3,3,0,150,18.4,-3.99,-100,6.99,-01,-0.89,56,14500,4000*7F

2021-08-16T00:23:00.567Z,1629073380.567 [Micromodem](INFO): Nmea in: $CACYC,1,234,37,3,1,1*68

2021-08-16T00:23:00.569Z,1629073380.569 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC,1*20

2021-08-16T00:23:00.977Z,1629073380.977 [Micromodem](INFO): Nmea in: $CACST,6,1,20210816002257.593735,06,401,26,0131,0150,149,03,03,00,03,3,234,037,3,3,1,1,150,3.4,-4.57,02,7.57,-01,-4.36,56,14500,4000*48

2021-08-16T00:23:03.812Z,1629073383.812 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2021-08-16T00:23:04.217Z,1629073384.217 [Micromodem](INFO): Nmea in: $CACST,6,1,20210816002303.604493,06,331,19,0130,0150,156,01,01,01,01,-1,-01,-01,1,3,2,0,150,19.4,0.08,-100,2.92,-01,-3.99,57,14500,4000*69

2021-08-16T00:23:08.692Z,1629073388.692 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2021-08-16T00:23:08.695Z,1629073388.695 [BPC1](INFO): Received data from all battery sticks.
2021-08-16T00:23:28.042Z,1629073408.042 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2021-08-16T00:23:31.280Z,1629073411.280 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2021-08-16T00:23:51.482Z,1629073431.482 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2021-08-16T00:23:53.905Z,1629073433.905 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2021-08-16T00:23:53.910Z,1629073433.910 [Micromodem](INFO): Nmea in: $CACST,6,1,20210816002353.589230,06,145,21,0111,0150,149,02,02,00,02,-1,-01,-01,1,3,5,0,150,-10.3,-0.04,-100,3.04,-01,-0.35,73,14500,4000*68

2021-08-16T00:25:00.152Z,1629073500.152 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error

2021-08-16T00:25:00.152Z,1629073500.152 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error
 expected 41
2021-08-16T00:25:00.154Z,1629073500.154 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2021-08-16T00:25:00.562Z,1629073500.562 [Micromodem](INFO): Nmea in: $CACST,6,1,20210816002459.582770,06,1100,24,0206,0150,194,02,02,01,02,-1,-01,-01,1,3,1,0,150,-100.0,0.09,-100,2.91,-01,-1.10,-2147483648,14500,4000*6E

2021-08-16T00:25:23.987Z,1629073523.987 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2021-08-16T00:25:24.006Z,1629073524.006 [Micromodem](INFO): Nmea in: $CACST,6,1,20210816002523.583478,06,235,23,0379,0150,208,02,02,00,02,-1,-01,-01,1,3,1,0,150,7.4,-0.43,-100,3.43,-01,0.77,65,14500,4000*51

2021-08-16T00:26:46.434Z,1629073606.434 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](INFO): Done Waiting.
2021-08-16T00:26:46.435Z,1629073606.435 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Stopped
2021-08-16T00:26:46.435Z,1629073606.435 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-08-16T00:26:46.435Z,1629073606.435 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Running Loop=1
2021-08-16T00:26:46.831Z,1629073606.831 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Stopped
2021-08-16T00:26:46.831Z,1629073606.831 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Running Loop=1
2021-08-16T00:26:47.276Z,1629073607.276 [DefaultWithUndock:SurfaceDefault:CheckIn:E](IMPORTANT): Default mission has been running for 7.328334 min 
2021-08-16T00:26:47.276Z,1629073607.276 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Stopped
2021-08-16T00:26:47.277Z,1629073607.277 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Completed DefaultWithUndock:SurfaceDefault:CheckIn
2021-08-16T00:26:47.277Z,1629073607.277 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped
2021-08-16T00:26:47.277Z,1629073607.277 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn
2021-08-16T00:26:47.277Z,1629073607.277 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Running loop #2
2021-08-16T00:26:47.277Z,1629073607.277 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=2
2021-08-16T00:26:47.277Z,1629073607.277 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2021-08-16T00:26:47.277Z,1629073607.277 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2021-08-16T00:26:49.246Z,1629073609.246 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,002648.00,A,4133.34226,N,07042.88288,W,0.292,334.46,160821,,,A*70
2021-08-16T00:26:49.249Z,1629073609.249 [NAL9602](INFO): GPS fix at 20210816T002648: (41.555704, -70.714715)
2021-08-16T00:26:49.314Z,1629073609.314 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2021-08-16T00:26:49.315Z,1629073609.315 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2021-08-16T00:26:53.435Z,1629073613.435 [DataOverHttps](INFO): Sending 201 bytes from file Logs/20210816T001613/Courier0007.lzma
2021-08-16T00:26:54.437Z,1629073614.437 [DataOverHttps](INFO): Moved sent file to Logs/20210816T001613/Courier0007.lzma.bak
2021-08-16T00:26:54.438Z,1629073614.438 [DataOverHttps](INFO): SBD MOMSN=445284
2021-08-16T00:26:56.100Z,1629073616.100 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error

2021-08-16T00:26:56.100Z,1629073616.100 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error
 expected 41
2021-08-16T00:26:56.519Z,1629073616.519 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2021-08-16T00:26:56.920Z,1629073616.920 [Micromodem](INFO): Nmea in: $CACST,6,1,20210816002655.568845,06,1631,26,0105,0150,208,02,02,01,02,-1,-01,-01,1,3,1,0,150,-100.0,0.05,-100,2.95,-01,-1.03,-2147483648,14500,4000*66

2021-08-16T00:27:03.476Z,1629073623.476 [DataOverHttps](INFO): Sending 350 bytes from file Logs/20210816T001613/Express0008.lzma
2021-08-16T00:27:04.477Z,1629073624.477 [DataOverHttps](INFO): Moved sent file to Logs/20210816T001613/Express0008.lzma.bak
2021-08-16T00:27:04.477Z,1629073624.477 [DataOverHttps](INFO): SBD MOMSN=445288
2021-08-16T00:27:06.220Z,1629073626.220 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2021-08-16T00:27:06.220Z,1629073626.220 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2021-08-16T00:27:06.220Z,1629073626.220 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-08-16T00:27:17.928Z,1629073637.928 [NAL9602](INFO): SBD MO Status=0, MOMSN=24193, MT Status=0, MTMSN=0
2021-08-16T00:27:17.928Z,1629073637.928 [NAL9602](INFO): No messages in MT queue
2021-08-16T00:27:48.641Z,1629073668.641 [NAL9602](INFO): Not Powering down - fast GPS
2021-08-16T00:27:49.657Z,1629073669.657 [DataOverHttps](IMPORTANT): SBD MTMSN=20210816T002749
2021-08-16T00:27:55.694Z,1629073675.694 [DataOverHttps](INFO): Received command:restart sys
2021-08-16T00:27:55.716Z,1629073675.716 [CommandLine](IMPORTANT): got command restart system
2021-08-16T00:27:57.824Z,1629073677.824 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2021-08-16T00:27:57.824Z,1629073677.824 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-08-16T00:27:57.936Z,1629073677.936 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2021-08-16T00:27:57.936Z,1629073677.936 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-08-16T00:27:57.937Z,1629073677.937 [CommandLine](INFO): Join timeout helper Thread ID is 1003
2021-08-16T00:27:57.944Z,1629073677.944 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2021-08-16T00:27:57.944Z,1629073677.944 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-08-16T00:27:57.944Z,1629073677.944 [NavChartDb](INFO): Join timeout helper Thread ID is 1004
2021-08-16T00:27:58.112Z,1629073678.112 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2021-08-16T00:27:58.112Z,1629073678.112 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-08-16T00:27:58.132Z,1629073678.132 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2021-08-16T00:27:58.132Z,1629073678.132 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2021-08-16T00:27:58.132Z,1629073678.132 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 1005
2021-08-16T00:27:58.440Z,1629073678.440 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2021-08-16T00:27:58.440Z,1629073678.440 [WetLabsSeaOWL_UV_A](INFO): Powering down
2021-08-16T00:27:58.441Z,1629073678.441 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2021-08-16T00:27:58.452Z,1629073678.452 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2021-08-16T00:27:58.452Z,1629073678.452 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-08-16T00:27:58.452Z,1629073678.452 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1006
2021-08-16T00:27:58.753Z,1629073678.753 [CTD_Seabird](INFO): Powering down
2021-08-16T00:27:58.768Z,1629073678.768 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2021-08-16T00:27:58.769Z,1629073678.769 [CTD_Seabird](INFO): Powering down
2021-08-16T00:27:58.792Z,1629073678.792 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-08-16T00:27:58.796Z,1629073678.796 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2021-08-16T00:27:58.796Z,1629073678.796 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-08-16T00:27:58.796Z,1629073678.796 [Radio_Surface](INFO): Join timeout helper Thread ID is 1007
2021-08-16T00:27:58.880Z,1629073678.880 [Radio_Surface](INFO): Powering down
2021-08-16T00:27:58.881Z,1629073678.881 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2021-08-16T00:27:58.881Z,1629073678.881 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-08-16T00:27:58.896Z,1629073678.896 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2021-08-16T00:27:58.896Z,1629073678.896 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-08-16T00:27:58.897Z,1629073678.897 [Onboard](INFO): Join timeout helper Thread ID is 1008
2021-08-16T00:27:59.696Z,1629073679.696 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2021-08-16T00:28:01.368Z,1629073681.368 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2021-08-16T00:28:01.368Z,1629073681.368 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-08-16T00:28:01.372Z,1629073681.372 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2021-08-16T00:28:01.372Z,1629073681.372 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-08-16T00:28:01.373Z,1629073681.373 [DataOverHttps](INFO): Join timeout helper Thread ID is 1009
2021-08-16T00:28:01.704Z,1629073681.704 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2021-08-16T00:28:01.704Z,1629073681.704 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-08-16T00:28:01.724Z,1629073681.724 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2021-08-16T00:28:01.724Z,1629073681.724 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2021-08-16T00:28:01.725Z,1629073681.725 [BackseatComponent](INFO): Join timeout helper Thread ID is 1010
2021-08-16T00:28:01.812Z,1629073681.812 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2021-08-16T00:28:01.812Z,1629073681.812 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2021-08-16T00:28:01.824Z,1629073681.824 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2021-08-16T00:28:01.825Z,1629073681.825 [logger ThreadHandler](INFO): Thread cancelled.
2021-08-16T00:28:01.825Z,1629073681.825 [logger](INFO): Join timeout helper Thread ID is 1011
2021-08-16T00:28:01.857Z,1629073681.857 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2021-08-16T00:28:01.858Z,1629073681.858 [logger ThreadHandler](INFO): Thread cancelled.
2021-08-16T00:28:01.864Z,1629073681.864 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2021-08-16T00:28:01.864Z,1629073681.864 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-08-16T00:28:01.865Z,1629073681.865 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2021-08-16T00:28:01.865Z,1629073681.865 [controlThread ThreadHandler](INFO): Thread cancelled.
2021-08-16T00:28:01.865Z,1629073681.865 [controlThread](INFO): Join timeout helper Thread ID is 1012
2021-08-16T00:28:01.952Z,1629073681.952 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2021-08-16T00:28:01.952Z,1629073681.952 [controlThread](DEBUG): Uninitializing ControlThread
2021-08-16T00:28:01.953Z,1629073681.953 [AHRS_M2](INFO): Powering down
2021-08-16T00:28:02.024Z,1629073682.024 [DDM](INFO): Powering down
2021-08-16T00:28:02.096Z,1629073682.096 [DUSBL_Hydroid](INFO): Powering down
2021-08-16T00:28:02.168Z,1629073682.168 [Micromodem](INFO): Powering down
2021-08-16T00:28:02.265Z,1629073682.265 [NAL9602](INFO): Powering down
2021-08-16T00:28:02.340Z,1629073682.340 [RDI_Pathfinder](INFO): Powering down
2021-08-16T00:28:02.412Z,1629073682.412 [RDI_PathfinderUp](INFO): Powering down
2021-08-16T00:28:02.413Z,1629073682.413 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2021-08-16T00:28:02.414Z,1629073682.414 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2021-08-16T00:28:02.415Z,1629073682.415 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2021-08-16T00:28:02.415Z,1629073682.415 [MissionManager](INFO): Uninitializing Mission DefaultWithUndock
2021-08-16T00:28:02.416Z,1629073682.416 [DefaultWithUndock] Stopped
2021-08-16T00:28:02.416Z,1629073682.416 [DefaultWithUndock](DEBUG): Aggregate::uninitialize DefaultWithUndock
2021-08-16T00:28:02.416Z,1629073682.416 [DefaultWithUndock:SurfaceDefault] Stopped
2021-08-16T00:28:02.416Z,1629073682.416 [DefaultWithUndock:SurfaceDefault](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault
2021-08-16T00:28:02.416Z,1629073682.416 [DefaultWithUndock:SurfaceDefault:B.GoToSurface] Stopped
2021-08-16T00:28:02.416Z,1629073682.416 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-08-16T00:28:02.416Z,1629073682.416 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped
2021-08-16T00:28:02.416Z,1629073682.416 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn
2021-08-16T00:28:02.417Z,1629073682.417 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] St