2021-08-16T00:40:33.716Z,1629074433.716 [Supervisor](DEBUG): Initializing supervisor.
2021-08-16T00:40:33.721Z,1629074433.721 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2021-08-16T00:40:33.721Z,1629074433.721 [SyncHandler](INFO): Protected caller Thread ID is 835
2021-08-16T00:40:33.722Z,1629074433.722 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2021-08-16T00:40:33.723Z,1629074433.723 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2021-08-16T00:40:33.723Z,1629074433.723 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 836
2021-08-16T00:40:33.727Z,1629074433.727 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2021-08-16T00:40:33.749Z,1629074433.749 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2021-08-16T00:40:33.750Z,1629074433.750 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2021-08-16T00:40:33.750Z,1629074433.750 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 837
2021-08-16T00:40:33.753Z,1629074433.753 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2021-08-16T00:40:33.754Z,1629074433.754 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2021-08-16T00:40:33.754Z,1629074433.754 [logger ThreadHandler](INFO): Protected caller Thread ID is 838
2021-08-16T00:40:33.759Z,1629074433.759 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2021-08-16T00:40:33.759Z,1629074433.759 [Supervisor](INFO): Looking for Config files in directory: Config/
2021-08-16T00:40:33.764Z,1629074433.764 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2021-08-16T00:40:34.203Z,1629074434.203 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2021-08-16T00:40:34.204Z,1629074434.204 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2021-08-16T00:40:34.285Z,1629074434.285 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2021-08-16T00:40:34.634Z,1629074434.634 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2021-08-16T00:40:34.636Z,1629074434.636 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2021-08-16T00:40:34.747Z,1629074434.747 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2021-08-16T00:40:34.749Z,1629074434.749 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2021-08-16T00:40:34.959Z,1629074434.959 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2021-08-16T00:40:34.961Z,1629074434.961 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2021-08-16T00:40:35.506Z,1629074435.506 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2021-08-16T00:40:35.508Z,1629074435.508 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2021-08-16T00:40:35.761Z,1629074435.761 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2021-08-16T00:40:35.763Z,1629074435.763 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2021-08-16T00:40:35.924Z,1629074435.924 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2021-08-16T00:40:35.925Z,1629074435.925 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2021-08-16T00:40:36.128Z,1629074436.128 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2021-08-16T00:40:36.129Z,1629074436.129 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2021-08-16T00:40:36.228Z,1629074436.228 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2021-08-16T00:40:36.229Z,1629074436.229 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2021-08-16T00:40:36.465Z,1629074436.465 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2021-08-16T00:40:36.466Z,1629074436.466 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2021-08-16T00:40:36.870Z,1629074436.870 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2021-08-16T00:40:36.871Z,1629074436.871 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2021-08-16T00:40:36.953Z,1629074436.953 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2021-08-16T00:40:37.374Z,1629074437.374 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2021-08-16T00:40:37.521Z,1629074437.521 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2021-08-16T00:40:38.409Z,1629074438.409 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2021-08-16T00:40:38.411Z,1629074438.411 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2021-08-16T00:40:38.804Z,1629074438.804 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2021-08-16T00:40:38.806Z,1629074438.806 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-polaris/
2021-08-16T00:40:38.811Z,1629074438.811 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/vehicle.cfg
2021-08-16T00:40:39.024Z,1629074439.024 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Control.cfg
2021-08-16T00:40:39.128Z,1629074439.128 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Estimation.cfg
2021-08-16T00:40:39.231Z,1629074439.231 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/BIT.cfg
2021-08-16T00:40:39.333Z,1629074439.333 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Battery.cfg
2021-08-16T00:40:39.601Z,1629074439.601 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2021-08-16T00:40:39.602Z,1629074439.602 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Simulator.cfg
2021-08-16T00:40:39.689Z,1629074439.689 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Navigation.cfg
2021-08-16T00:40:39.787Z,1629074439.787 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Derivation.cfg
2021-08-16T00:40:39.917Z,1629074439.917 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/logger.cfg
2021-08-16T00:40:40.033Z,1629074440.033 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/secure.cfg
2021-08-16T00:40:40.121Z,1629074440.121 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Dock.cfg
2021-08-16T00:40:40.209Z,1629074440.209 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Servo.cfg
2021-08-16T00:40:40.323Z,1629074440.323 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/workSite.cfg
2021-08-16T00:40:40.424Z,1629074440.424 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Sensor.cfg
2021-08-16T00:40:40.632Z,1629074440.632 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Science.cfg
2021-08-16T00:40:40.804Z,1629074440.804 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2021-08-16T00:40:40.808Z,1629074440.808 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2021-08-16T00:40:41.515Z,1629074441.515 [AHRS_M2] Loaded
2021-08-16T00:40:41.516Z,1629074441.516 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2021-08-16T00:40:41.761Z,1629074441.761 [BackseatComponent] Loaded
2021-08-16T00:40:41.761Z,1629074441.761 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2021-08-16T00:40:41.762Z,1629074441.762 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 4079A4E0
2021-08-16T00:40:41.763Z,1629074441.763 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 932
2021-08-16T00:40:41.765Z,1629074441.765 [LcmUniversalReporter] Loaded
2021-08-16T00:40:41.766Z,1629074441.766 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2021-08-16T00:40:42.558Z,1629074442.558 [BPC1] Loaded
2021-08-16T00:40:42.558Z,1629074442.558 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2021-08-16T00:40:42.698Z,1629074442.698 [DataOverHttps] Loaded
2021-08-16T00:40:42.698Z,1629074442.698 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2021-08-16T00:40:42.699Z,1629074442.699 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407CA4E0
2021-08-16T00:40:42.700Z,1629074442.700 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 933
2021-08-16T00:40:42.723Z,1629074442.723 [DDM] Loaded
2021-08-16T00:40:42.723Z,1629074442.723 [ComponentRegistry](DEBUG): SyncComponent "DDM" handled in the control thread.
2021-08-16T00:40:42.742Z,1629074442.742 [Depth_Keller] Loaded
2021-08-16T00:40:42.743Z,1629074442.743 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2021-08-16T00:40:42.747Z,1629074442.747 [DropWeight] Loaded
2021-08-16T00:40:42.748Z,1629074442.748 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2021-08-16T00:40:43.016Z,1629074443.016 [DUSBL_Hydroid] Loaded
2021-08-16T00:40:43.017Z,1629074443.017 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2021-08-16T00:40:43.155Z,1629074443.155 [Micromodem] Loaded
2021-08-16T00:40:43.161Z,1629074443.161 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2021-08-16T00:40:43.283Z,1629074443.283 [NAL9602] Loaded
2021-08-16T00:40:43.283Z,1629074443.283 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2021-08-16T00:40:43.312Z,1629074443.312 [Onboard] Loaded
2021-08-16T00:40:43.313Z,1629074443.313 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2021-08-16T00:40:43.314Z,1629074443.314 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 407FA4E0
2021-08-16T00:40:43.314Z,1629074443.314 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 934
2021-08-16T00:40:43.322Z,1629074443.322 [PowerOnly](INFO): Adding load control power supply at /dev/loadC1
2021-08-16T00:40:43.332Z,1629074443.332 [PowerOnly] Loaded
2021-08-16T00:40:43.333Z,1629074443.333 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2021-08-16T00:40:43.407Z,1629074443.407 [Power24vConverter] Loaded
2021-08-16T00:40:43.408Z,1629074443.408 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2021-08-16T00:40:43.425Z,1629074443.425 [Radio_Surface] Loaded
2021-08-16T00:40:43.425Z,1629074443.425 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2021-08-16T00:40:43.426Z,1629074443.426 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4082A4E0
2021-08-16T00:40:43.427Z,1629074443.427 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 935
2021-08-16T00:40:43.470Z,1629074443.470 [RDI_Pathfinder] Loaded
2021-08-16T00:40:43.471Z,1629074443.471 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2021-08-16T00:40:43.498Z,1629074443.498 [RDI_PathfinderUp] Loaded
2021-08-16T00:40:43.498Z,1629074443.498 [ComponentRegistry](DEBUG): SyncComponent "RDI_PathfinderUp" handled in the control thread.
2021-08-16T00:40:43.499Z,1629074443.499 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2021-08-16T00:40:43.501Z,1629074443.501 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2021-08-16T00:40:43.517Z,1629074443.517 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2021-08-16T00:40:43.518Z,1629074443.518 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2021-08-16T00:40:43.620Z,1629074443.620 [DeadReckonUsingMultipleVelocitySources] Loaded
2021-08-16T00:40:43.620Z,1629074443.620 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2021-08-16T00:40:43.634Z,1629074443.634 [NavChart] Loaded
2021-08-16T00:40:43.634Z,1629074443.634 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2021-08-16T00:40:43.640Z,1629074443.640 [UniversalFixResidualReporter] Loaded
2021-08-16T00:40:43.641Z,1629074443.641 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2021-08-16T00:40:43.652Z,1629074443.652 [WorkSite] Loaded
2021-08-16T00:40:43.652Z,1629074443.652 [ComponentRegistry](DEBUG): SyncComponent "WorkSite" handled in the control thread.
2021-08-16T00:40:43.652Z,1629074443.652 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2021-08-16T00:40:43.653Z,1629074443.653 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2021-08-16T00:40:43.776Z,1629074443.776 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2021-08-16T00:40:43.777Z,1629074443.777 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2021-08-16T00:40:43.942Z,1629074443.942 [BuoyancyServo] Loaded
2021-08-16T00:40:43.943Z,1629074443.943 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2021-08-16T00:40:43.965Z,1629074443.965 [ElevatorServo] Loaded
2021-08-16T00:40:43.965Z,1629074443.965 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2021-08-16T00:40:43.987Z,1629074443.987 [MassServo] Loaded
2021-08-16T00:40:43.988Z,1629074443.988 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2021-08-16T00:40:44.008Z,1629074444.008 [RudderServo] Loaded
2021-08-16T00:40:44.009Z,1629074444.009 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2021-08-16T00:40:44.030Z,1629074444.030 [ThrusterServo] Loaded
2021-08-16T00:40:44.030Z,1629074444.030 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2021-08-16T00:40:44.030Z,1629074444.030 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2021-08-16T00:40:44.031Z,1629074444.031 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2021-08-16T00:40:44.262Z,1629074444.262 [CTD_Seabird] Loaded
2021-08-16T00:40:44.262Z,1629074444.262 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2021-08-16T00:40:44.264Z,1629074444.264 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409544E0
2021-08-16T00:40:44.264Z,1629074444.264 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 936
2021-08-16T00:40:44.299Z,1629074444.299 [WetLabsSeaOWL_UV_A] Loaded
2021-08-16T00:40:44.299Z,1629074444.299 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2021-08-16T00:40:44.300Z,1629074444.300 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 409844E0
2021-08-16T00:40:44.300Z,1629074444.300 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 937
2021-08-16T00:40:44.301Z,1629074444.301 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2021-08-16T00:40:44.302Z,1629074444.302 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2021-08-16T00:40:44.694Z,1629074444.694 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2021-08-16T00:40:44.696Z,1629074444.696 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2021-08-16T00:40:44.760Z,1629074444.760 [DepthRateCalculator] Loaded
2021-08-16T00:40:44.760Z,1629074444.760 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2021-08-16T00:40:44.766Z,1629074444.766 [PitchRateCalculator] Loaded
2021-08-16T00:40:44.766Z,1629074444.766 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2021-08-16T00:40:44.776Z,1629074444.776 [SpeedCalculator] Loaded
2021-08-16T00:40:44.776Z,1629074444.776 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2021-08-16T00:40:44.790Z,1629074444.790 [TempGradientCalculator] Loaded
2021-08-16T00:40:44.791Z,1629074444.791 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2021-08-16T00:40:44.808Z,1629074444.808 [VerticalHomogeneityIndexCalculator] Loaded
2021-08-16T00:40:44.808Z,1629074444.808 [ComponentRegistry](DEBUG): SyncComponent "VerticalHomogeneityIndexCalculator" handled in the control thread.
2021-08-16T00:40:44.813Z,1629074444.813 [YawRateCalculator] Loaded
2021-08-16T00:40:44.813Z,1629074444.813 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2021-08-16T00:40:44.836Z,1629074444.836 [ElevatorOffsetCalculator] Loaded
2021-08-16T00:40:44.836Z,1629074444.836 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2021-08-16T00:40:44.837Z,1629074444.837 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2021-08-16T00:40:44.837Z,1629074444.837 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2021-08-16T00:40:45.019Z,1629074445.019 [SBIT](DEBUG): Construct Startup Built In Test.
2021-08-16T00:40:45.032Z,1629074445.032 [SBIT] Loaded
2021-08-16T00:40:45.033Z,1629074445.033 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2021-08-16T00:40:45.035Z,1629074445.035 [IBIT](DEBUG): Construct Initiated Built In Test.
2021-08-16T00:40:45.050Z,1629074445.050 [IBIT] Loaded
2021-08-16T00:40:45.050Z,1629074445.050 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2021-08-16T00:40:45.056Z,1629074445.056 [CBIT](DEBUG): Construct Continuous Built In Test.
2021-08-16T00:40:45.164Z,1629074445.164 [CBIT] Loaded
2021-08-16T00:40:45.164Z,1629074445.164 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2021-08-16T00:40:45.165Z,1629074445.165 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2021-08-16T00:40:45.165Z,1629074445.165 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2021-08-16T00:40:45.264Z,1629074445.264 [StratificationFrontDetector](IMPORTANT): thresholdVTHI set to: 0.399988 degC
2021-08-16T00:40:45.265Z,1629074445.265 [StratificationFrontDetector](INFO): (re)initializing
2021-08-16T00:40:45.265Z,1629074445.265 [StratificationFrontDetector] Loaded
2021-08-16T00:40:45.265Z,1629074445.265 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2021-08-16T00:40:45.266Z,1629074445.266 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2021-08-16T00:40:45.266Z,1629074445.266 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2021-08-16T00:40:45.406Z,1629074445.406 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2021-08-16T00:40:45.407Z,1629074445.407 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2021-08-16T00:40:45.481Z,1629074445.481 [VerticalControl](DEBUG): Construct VerticalControl.
2021-08-16T00:40:45.536Z,1629074445.536 [VerticalControl] Loaded
2021-08-16T00:40:45.536Z,1629074445.536 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2021-08-16T00:40:45.539Z,1629074445.539 [HorizontalControl](DEBUG): Construct HorizontalControl.
2021-08-16T00:40:45.578Z,1629074445.578 [HorizontalControl] Loaded
2021-08-16T00:40:45.578Z,1629074445.578 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2021-08-16T00:40:45.581Z,1629074445.581 [SpeedControl](DEBUG): Construct SpeedControl.
2021-08-16T00:40:45.583Z,1629074445.583 [SpeedControl] Loaded
2021-08-16T00:40:45.583Z,1629074445.583 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2021-08-16T00:40:45.586Z,1629074445.586 [LoopControl](DEBUG): Construct LoopControl.
2021-08-16T00:40:45.587Z,1629074445.587 [LoopControl] Loaded
2021-08-16T00:40:45.587Z,1629074445.587 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2021-08-16T00:40:45.587Z,1629074445.587 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2021-08-16T00:40:45.588Z,1629074445.588 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2021-08-16T00:40:45.632Z,1629074445.632 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2021-08-16T00:40:45.639Z,1629074445.639 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2021-08-16T00:40:45.642Z,1629074445.642 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2021-08-16T00:40:45.653Z,1629074445.653 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2021-08-16T00:40:45.654Z,1629074445.654 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B324E0
2021-08-16T00:40:45.655Z,1629074445.655 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 938
2021-08-16T00:40:45.660Z,1629074445.660 [Supervisor](INFO): Main Thread ID is 829
2021-08-16T00:40:45.660Z,1629074445.660 [Supervisor](DEBUG): Running supervisor.
2021-08-16T00:40:45.661Z,1629074445.661 [CommandLine ThreadHandler](INFO): Handler Thread ID is 939
2021-08-16T00:40:45.663Z,1629074445.663 [controlThread ThreadHandler](INFO): Handler Thread ID is 940
2021-08-16T00:40:45.663Z,1629074445.663 [controlThread](DEBUG): Initializing ControlThread
2021-08-16T00:40:45.670Z,1629074445.670 [NavChart](DEBUG): Initialize NavChart Navigation.
2021-08-16T00:40:45.671Z,1629074445.671 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2021-08-16T00:40:45.671Z,1629074445.671 [WorkSite](DEBUG): Initializing WorkSite component.
2021-08-16T00:40:45.673Z,1629074445.673 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2021-08-16T00:40:45.673Z,1629074445.673 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2021-08-16T00:40:45.673Z,1629074445.673 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2021-08-16T00:40:45.674Z,1629074445.674 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2021-08-16T00:40:45.674Z,1629074445.674 [VerticalHomogeneityIndexCalculator](DEBUG): (re)initializing
2021-08-16T00:40:45.675Z,1629074445.675 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2021-08-16T00:40:45.676Z,1629074445.676 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2021-08-16T00:40:45.676Z,1629074445.676 [SBIT](INFO): Initialize SBIT Component.
2021-08-16T00:40:45.677Z,1629074445.677 [SBIT](IMPORTANT): git: 2021-08-12
2021-08-16T00:40:45.677Z,1629074445.677 [SBIT](INFO): git hash: 4ac1c7994e02762939ba6e7c4596a90b7f61f056
2021-08-16T00:40:45.677Z,1629074445.677 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2021-08-16T00:40:45.679Z,1629074445.679 [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:40:45.680Z,1629074445.680 [SBIT](INFO): Beginning SBIT in 36.000000 seconds.
2021-08-16T00:40:45.680Z,1629074445.680 [IBIT](INFO): Initialize IBIT Component.
2021-08-16T00:40:45.681Z,1629074445.681 [CBIT](DEBUG): Initialize CBIT Component.
2021-08-16T00:40:45.682Z,1629074445.682 [logger ThreadHandler](INFO): Handler Thread ID is 941
2021-08-16T00:40:45.695Z,1629074445.695 [CBIT](DEBUG): Initialized mux pins.
2021-08-16T00:40:45.695Z,1629074445.695 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2021-08-16T00:40:45.695Z,1629074445.695 [CBIT](DEBUG): Initializing the watchdog timer.
2021-08-16T00:40:45.700Z,1629074445.700 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 942
2021-08-16T00:40:45.708Z,1629074445.708 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 943
2021-08-16T00:40:45.709Z,1629074445.709 [DataOverHttps](DEBUG): dashIP=128.128.181.155 starts with a digit so assuming it is a numeric IP
2021-08-16T00:40:45.716Z,1629074445.716 [Onboard ThreadHandler](INFO): Handler Thread ID is 944
2021-08-16T00:40:45.720Z,1629074445.720 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2021-08-16T00:40:45.725Z,1629074445.725 [CBIT](FAULT): Found backtrace file:
1629074075.507249 [DataOverHttps]: SIGSEGV: address not mapped to object
1629074075.507249 [DataOverHttps]: Backtrace:
./bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x1a11d0]


2021-08-16T00:40:45.742Z,1629074445.742 [CBIT](FAULT): Renaming backtrace file to Data/backtrace13
2021-08-16T00:40:45.742Z,1629074445.742 [CBIT](DEBUG): Initializing heartbeat.
2021-08-16T00:40:45.752Z,1629074445.752 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 945
2021-08-16T00:40:45.772Z,1629074445.772 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 946
2021-08-16T00:40:45.772Z,1629074445.772 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2021-08-16T00:40:45.777Z,1629074445.777 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 948
2021-08-16T00:40:45.778Z,1629074445.778 [WetLabsSeaOWL_UV_A](INFO): Powering down
2021-08-16T00:40:45.788Z,1629074445.788 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 949
2021-08-16T00:40:45.797Z,1629074445.797 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2021-08-16T00:40:45.797Z,1629074445.797 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2021-08-16T00:40:45.797Z,1629074445.797 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2021-08-16T00:40:45.798Z,1629074445.798 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2021-08-16T00:40:45.798Z,1629074445.798 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2021-08-16T00:40:45.798Z,1629074445.798 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2021-08-16T00:40:45.798Z,1629074445.798 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2021-08-16T00:40:45.798Z,1629074445.798 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2021-08-16T00:40:45.798Z,1629074445.798 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2021-08-16T00:40:45.799Z,1629074445.799 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2021-08-16T00:40:45.799Z,1629074445.799 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2021-08-16T00:40:45.799Z,1629074445.799 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2021-08-16T00:40:45.799Z,1629074445.799 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2021-08-16T00:40:45.799Z,1629074445.799 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2021-08-16T00:40:45.800Z,1629074445.800 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2021-08-16T00:40:45.800Z,1629074445.800 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2021-08-16T00:40:45.811Z,1629074445.811 [CBIT](DEBUG): Deactivating GF circuits.
2021-08-16T00:40:45.811Z,1629074445.811 [CBIT](DEBUG): Deactivating emergency mode.
2021-08-16T00:40:45.847Z,1629074445.847 [CBIT](DEBUG): Backplane powered.
2021-08-16T00:40:45.848Z,1629074445.848 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2021-08-16T00:40:45.850Z,1629074445.850 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2021-08-16T00:40:45.851Z,1629074445.851 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2021-08-16T00:40:45.851Z,1629074445.851 [LoopControl](DEBUG): Initialize LoopControlComponent.
2021-08-16T00:40:45.852Z,1629074445.852 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2021-08-16T00:40:45.879Z,1629074445.879 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2021-08-16T00:40:45.921Z,1629074445.921 [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:40:45.922Z,1629074445.922 [MissionManager](INFO): Loading Mission: Missions/underIce/DefaultWithUndock.xml
2021-08-16T00:40:46.079Z,1629074446.079 [MissionManager](INFO): DefineArg DefaultWithUndock.ElapsedSinceDefaultStarted = 0.000000 min
2021-08-16T00:40:46.108Z,1629074446.108 [MissionManager](INFO): DefineArg DefaultWithUndock.DetachTimeout = 30.000000 min
2021-08-16T00:40:46.112Z,1629074446.112 [MissionManager](INFO): DefineArg DefaultWithUndock.TransponderCode = 2.000000 count
2021-08-16T00:40:46.126Z,1629074446.126 [MissionManager](INFO): DefineArg DefaultWithUndock.TrackingUpdatePeriod = 2.500000 s
2021-08-16T00:40:46.130Z,1629074446.130 [MissionManager](INFO): DefineArg DefaultWithUndock.NumberOfPings = 1.000000 count
2021-08-16T00:40:46.155Z,1629074446.155 [Radio_Surface](INFO): Powering up
2021-08-16T00:40:46.158Z,1629074446.158 [MissionManager](INFO): DefineArg DefaultWithUndock.DetachModeDDM = 2.000000 count
2021-08-16T00:40:46.172Z,1629074446.172 [DefaultWithUndock:A.Wait](DEBUG): Construct Wait.
2021-08-16T00:40:46.286Z,1629074446.286 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Construct.
2021-08-16T00:40:46.287Z,1629074446.287 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values.
2021-08-16T00:40:46.347Z,1629074446.347 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): Construct GoToSurface.
2021-08-16T00:40:46.395Z,1629074446.395 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2021-08-16T00:40:46.397Z,1629074446.397 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Construct Wait.
2021-08-16T00:40:46.424Z,1629074446.424 [DefaultWithUndock:E.Execute](DEBUG): Construct Execute.
2021-08-16T00:40:46.446Z,1629074446.446 [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:40:46.452Z,1629074446.452 [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:40:46.459Z,1629074446.459 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2021-08-16T00:40:46.632Z,1629074446.632 [DDM](INFO): Powering up
2021-08-16T00:40:46.632Z,1629074446.632 [DDM](DEBUG): Initializing DDM.
2021-08-16T00:40:46.656Z,1629074446.656 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar
2021-08-16T00:40:46.657Z,1629074446.657 [DUSBL_Hydroid](INFO): Powering up
2021-08-16T00:40:46.657Z,1629074446.657 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2021-08-16T00:40:46.677Z,1629074446.677 [Power24vConverter](INFO): Powering up.
2021-08-16T00:40:46.696Z,1629074446.696 [DepthRateCalculator](ERROR): Depth measurement is not active
2021-08-16T00:40:46.729Z,1629074446.729 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2021-08-16T00:40:46.736Z,1629074446.736 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2021-08-16T00:40:46.737Z,1629074446.737 [ElevatorServo](DEBUG): Initializing EZServoServo.
2021-08-16T00:40:46.744Z,1629074446.744 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2021-08-16T00:40:46.745Z,1629074446.745 [MassServo](DEBUG): Initializing EZServoServo.
2021-08-16T00:40:46.751Z,1629074446.751 [MassServo](DEBUG): Initializing MassServo.
2021-08-16T00:40:46.752Z,1629074446.752 [RudderServo](DEBUG): Initializing EZServoServo.
2021-08-16T00:40:46.760Z,1629074446.760 [RudderServo](DEBUG): Initializing RudderServo.
2021-08-16T00:40:46.761Z,1629074446.761 [ThrusterServo](DEBUG): Initializing EZServoServo.
2021-08-16T00:40:46.767Z,1629074446.767 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2021-08-16T00:40:46.883Z,1629074446.883 [Micromodem](INFO): Powering up
2021-08-16T00:40:46.884Z,1629074446.884 [Micromodem](DEBUG): Initializing Micromodem.
2021-08-16T00:40:47.591Z,1629074447.591 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2021-08-16T00:40:47.591Z,1629074447.591 [RudderServo](FAULT): Rudder failed to initialize
2021-08-16T00:40:47.592Z,1629074447.592 [RudderServo] Communications Fault, FailCount= 1
2021-08-16T00:40:47.592Z,1629074447.592 [RudderServo](ERROR): Communications Fault
2021-08-16T00:40:47.692Z,1629074447.692 [CBIT](ERROR): Communications Fault in component: RudderServo
2021-08-16T00:40:47.872Z,1629074447.872 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2021-08-16T00:40:47.872Z,1629074447.872 [RudderServo](INFO): Powering down
2021-08-16T00:40:48.520Z,1629074448.520 [RudderServo](DEBUG): Initializing EZServoServo.
2021-08-16T00:40:48.640Z,1629074448.640 [RudderServo](DEBUG): Initializing RudderServo.
2021-08-16T00:40:48.644Z,1629074448.644 [CBIT](INFO): Clearing failed state for component RudderServo
2021-08-16T00:40:48.645Z,1629074448.645 [RudderServo] No Fault, FailCount= 1
2021-08-16T00:40:51.786Z,1629074451.786 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33

2021-08-16T00:40:59.018Z,1629074459.018 [Micromodem](INFO): Nmea in: $CATMG,2021-08-16T00:40:57.750489Z,RTC,RTC*5F

2021-08-16T00:40:59.018Z,1629074459.018 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2021-08-16T00:40:57.750489Z,RTC,RTC*5F

2021-08-16T00:41:02.245Z,1629074462.245 [DDM](INFO): Dynamic Docking Module:
2021-08-16T00:41:03.089Z,1629074463.089 [Micromodem](ERROR): Nmea resend: $CCCFG,ALL,0*33

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

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

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

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

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

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

2021-08-16T00:41:04.673Z,1629074464.673 [DUSBL_Hydroid](INFO): DUSBL Version:O
2021-08-16T00:41:04.689Z,1629074464.689 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,0*2D

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

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

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

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

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

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

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

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

2021-08-16T00:41:06.290Z,1629074466.290 [Micromodem](INFO): Nmea out: $CCCLK,2021,08,16,00,41,07*48

2021-08-16T00:41:06.694Z,1629074466.694 [Micromodem](INFO): Nmea in: $CACLK,2021,8,16,0,41,7*7A

2021-08-16T00:41:06.695Z,1629074466.695 [Micromodem](INFO): Nmea in: $CATMS,0,2021-08-16T00:41:08Z*75

2021-08-16T00:41:06.697Z,1629074466.697 [Micromodem](INFO): Nmea in: $CATMG,2021-08-16T00:41:08.026699Z,USER_CMD,RTC*10

2021-08-16T00:41:13.562Z,1629074473.562 [NAL9602](INFO): Powering up NAL9602
2021-08-16T00:41:18.814Z,1629074478.814 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC, Data Header,2*00

2021-08-16T00:41:18.819Z,1629074478.819 [Micromodem](INFO): Nmea in: $CACST,6,1,20210816004118.543709,06,169,22,0091,0150,156,01,01,00,01,5,-01,-01,2,3,2,0,150,-30.4,9.42,-100,-6.42,-01,-0.94,60,14500,4000*4E

2021-08-16T00:41:22.080Z,1629074482.080 [SBIT](IMPORTANT): Beginning Startup BIT
2021-08-16T00:41:22.090Z,1629074482.090 [CBIT](IMPORTANT): Beginning ground fault scan
2021-08-16T00:41:24.470Z,1629074484.470 [NAL9602](INFO): NAL9602 initialized
2021-08-16T00:41:33.049Z,1629074493.049 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.005724
CHAN A1 (24V): -0.023823
CHAN A2 (12V): -0.005641
CHAN A3 (5V): -0.001733
CHAN B0 (3.3V): 0.000438
CHAN B1 (3.15aV): 0.000236
CHAN B2 (3.15bV): 0.000283
CHAN B3 (GND): 0.002128
OPEN: 0.006516
Full Scale Calc: 4.765 mA, -1.589 mA
2021-08-16T00:41:33.762Z,1629074493.762 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC, Data Header,2*00

2021-08-16T00:41:33.767Z,1629074493.767 [Micromodem](INFO): Nmea in: $CACST,6,1,20210816004132.545311,06,183,22,0113,0150,141,01,01,00,01,5,-01,-01,2,3,4,0,150,4.4,-5.74,-100,8.74,-01,-1.18,56,14500,4000*5A

2021-08-16T00:41:41.859Z,1629074501.859 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=24201, MT Status=1, MTMSN=839
2021-08-16T00:41:41.859Z,1629074501.859 [NAL9602](INFO): Data available in MT queue
2021-08-16T00:41:42.392Z,1629074502.392 [NAL9602](INFO): Received command:configSet lineCapture.rolloutTimeout 10 min persist
2021-08-16T00:41:42.818Z,1629074502.818 [CommandLine](IMPORTANT): got command configSet LineCapture.rolloutTimeout 10.000000 minute persist
2021-08-16T00:41:42.819Z,1629074502.819 [CommandLine](FAULT): Not allowing to overwrite existing Data/persisted.cfg after unclean shutdown.
2021-08-16T00:41:49.948Z,1629074509.948 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,004148.00,A,4133.37807,N,07043.01985,W,0.641,0.00,160821,,,A*71
2021-08-16T00:41:49.951Z,1629074509.951 [NAL9602](INFO): GPS fix at 20210816T004148: (41.556301, -70.716998)
2021-08-16T00:42:02.065Z,1629074522.065 [Micromodem](INFO): Nmea in: $CAMSG,Error accessing coproc,4*51

2021-08-16T00:42:02.070Z,1629074522.070 [Micromodem](INFO): Nmea in: $CACST,6,1,20210816004202.547157,06,887,23,0093,0150,208,02,02,01,02,-1,-01,-01,4,3,0,0,-999,-99.9,-9.99,-999,-9.99,-01,0.00,-999,14500,4000*54

2021-08-16T00:42:16.244Z,1629074536.244 [SBIT](IMPORTANT): SBIT PASSED
2021-08-16T00:42:16.244Z,1629074536.244 [SBIT](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2021-08-16T00:42:16.653Z,1629074536.653 [WorkSite](INFO): Already have valid position. Ignoring workSite position from Data/workSite.cfg
2021-08-16T00:42:16.658Z,1629074536.658 [MissionManager](IMPORTANT): Started mission Startup
2021-08-16T00:42:16.658Z,1629074536.658 [Startup] Running Loop=1
2021-08-16T00:42:16.658Z,1629074536.658 [Startup](DEBUG): Aggregate::initialize Startup
2021-08-16T00:42:16.659Z,1629074536.659 [Startup:A.GoToSurface] Running Loop=1
2021-08-16T00:42:16.659Z,1629074536.659 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-08-16T00:42:16.659Z,1629074536.659 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-08-16T00:42:16.660Z,1629074536.660 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-08-16T00:42:16.660Z,1629074536.660 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-08-16T00:42:16.661Z,1629074536.661 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-08-16T00:42:16.661Z,1629074536.661 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-08-16T00:42:16.663Z,1629074536.663 [Startup:StartupSatComms] Running Loop=1
2021-08-16T00:42:16.663Z,1629074536.663 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2021-08-16T00:42:16.663Z,1629074536.663 [Startup:StartupSatComms:A] Running Loop=1
2021-08-16T00:42:17.068Z,1629074537.068 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2021-08-16T00:42:18.650Z,1629074538.650 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,004216.00,A,4133.37825,N,07043.02413,W,0.544,0.00,160821,,,A*7E
2021-08-16T00:42:18.653Z,1629074538.653 [NAL9602](INFO): GPS fix at 20210816T004216: (41.556304, -70.717069)
2021-08-16T00:42:18.663Z,1629074538.663 [Startup:StartupSatComms:A] Stopped
2021-08-16T00:42:18.663Z,1629074538.663 [Startup:StartupSatComms:B] Running Loop=1
2021-08-16T00:42:19.093Z,1629074539.093 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-08-16T00:42:42.004Z,1629074562.004 [NAL9602](INFO): SBD MO Status=1, MOMSN=24202, MT Status=0, MTMSN=0
2021-08-16T00:42:42.064Z,1629074562.064 [NAL9602](INFO): Sent 184 bytes from file Logs/20210816T002900/Courier0007.lzma
2021-08-16T00:42:42.064Z,1629074562.064 [NAL9602](INFO): Packets left to send: 1
2021-08-16T00:42:51.488Z,1629074571.488 [NAL9602](INFO): SBD MO Status=1, MOMSN=24203, MT Status=0, MTMSN=0
2021-08-16T00:42:51.536Z,1629074571.536 [NAL9602](INFO): Sent 79 bytes from file Logs/20210816T002900/Courier0007.lzma
2021-08-16T00:42:51.536Z,1629074571.536 [NAL9602](INFO): Packets left to send: 0
2021-08-16T00:43:01.825Z,1629074581.825 [NAL9602](INFO): SBD MO Status=1, MOMSN=24204, MT Status=0, MTMSN=0
2021-08-16T00:43:01.884Z,1629074581.884 [NAL9602](INFO): Sent 18 bytes from file Logs/20210816T002900/Courier0010.lzma
2021-08-16T00:43:01.884Z,1629074581.884 [NAL9602](INFO): Packets left to send: 0
2021-08-16T00:43:05.353Z,1629074585.353 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2021-08-16T00:43:05.761Z,1629074585.761 [Micromodem](INFO): Nmea in: $CACST,6,1,20210816004304.526309,06,460,20,0116,0150,208,02,02,01,02,-1,-01,-01,1,3,6,0,150,7.9,-0.06,-100,3.06,-01,0.63,65,14500,4000*5A

2021-08-16T00:43:10.999Z,1629074590.999 [NAL9602](INFO): SBD MO Status=1, MOMSN=24205, MT Status=0, MTMSN=0
2021-08-16T00:43:11.056Z,1629074591.056 [NAL9602](INFO): Sent 184 bytes from file Logs/20210816T004033/Courier0000.lzma
2021-08-16T00:43:11.056Z,1629074591.056 [NAL9602](INFO): Packets left to send: 1
2021-08-16T00:43:14.082Z,1629074594.082 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2021-08-16T00:43:14.405Z,1629074594.405 [Micromodem](INFO): Nmea in: $CACST,6,1,20210816004314.542554,06,234,23,0091,0150,216,02,02,00,02,-1,-01,-01,1,3,5,0,150,7.2,-0.05,-100,3.05,-01,-1.05,65,14500,4000*77

2021-08-16T00:43:18.842Z,1629074598.842 [Startup:StartupSatComms:B](INFO): Timed out from 2021-08-16T00:42:18.7Z
2021-08-16T00:43:18.842Z,1629074598.842 [Startup:StartupSatComms:B] Stopped
2021-08-16T00:43:18.842Z,1629074598.842 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2021-08-16T00:43:18.842Z,1629074598.842 [Startup:StartupSatComms] Stopped
2021-08-16T00:43:18.843Z,1629074598.843 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2021-08-16T00:43:18.844Z,1629074598.844 [Startup](INFO): Completed Startup
2021-08-16T00:43:18.844Z,1629074598.844 [MissionManager](INFO): Startup is completed.
2021-08-16T00:43:18.844Z,1629074598.844 [MissionManager](INFO): Uninitializing Mission Startup
2021-08-16T00:43:18.844Z,1629074598.844 [Startup] Stopped
2021-08-16T00:43:18.844Z,1629074598.844 [Startup](DEBUG): Aggregate::uninitialize Startup
2021-08-16T00:43:18.844Z,1629074598.844 [Startup:A.GoToSurface] Stopped
2021-08-16T00:43:18.845Z,1629074598.845 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-08-16T00:43:19.256Z,1629074599.256 [MissionManager](IMPORTANT): Started mission DefaultWithUndock
2021-08-16T00:43:19.256Z,1629074599.256 [DefaultWithUndock] Running Loop=1
2021-08-16T00:43:19.256Z,1629074599.256 [DefaultWithUndock](DEBUG): Aggregate::initialize DefaultWithUndock
2021-08-16T00:43:19.256Z,1629074599.256 [DefaultWithUndock:A.Wait] Running Loop=1
2021-08-16T00:43:19.256Z,1629074599.256 [DefaultWithUndock:A.Wait](DEBUG): Initialize Wait Component.
2021-08-16T00:43:21.651Z,1629074601.651 [NAL9602](INFO): SBD MO Status=1, MOMSN=24206, MT Status=0, MTMSN=0
2021-08-16T00:43:21.704Z,1629074601.704 [NAL9602](INFO): Sent 74 bytes from file Logs/20210816T004033/Courier0000.lzma
2021-08-16T00:43:21.704Z,1629074601.704 [NAL9602](INFO): Packets left to send: 0
2021-08-16T00:43:49.538Z,1629074629.538 [DefaultWithUndock:A.Wait](INFO): Done Waiting.
2021-08-16T00:43:49.538Z,1629074629.538 [DefaultWithUndock:A.Wait] Stopped
2021-08-16T00:43:49.538Z,1629074629.538 [DefaultWithUndock:A.Wait](DEBUG): Uninitialize Wait Component.
2021-08-16T00:43:49.538Z,1629074629.538 [DefaultWithUndock:LeaveDock] Running Loop=1
2021-08-16T00:43:49.538Z,1629074629.538 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::initialize DefaultWithUndock:LeaveDock
2021-08-16T00:43:49.538Z,1629074629.538 [DefaultWithUndock:LeaveDock:A.] Running Loop=1
2021-08-16T00:43:49.538Z,1629074629.538 [DefaultWithUndock:LeaveDock:A.](INFO): Initializing TrackAcousticContact.
2021-08-16T00:43:49.539Z,1629074629.539 [DefaultWithUndock:LeaveDock:B.Undock] Running Loop=1
2021-08-16T00:43:49.539Z,1629074629.539 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initialize.
2021-08-16T00:43:49.539Z,1629074629.539 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values.
2021-08-16T00:43:49.952Z,1629074629.952 [DefaultWithUndock:LeaveDock:A.] Running Loop=1
2021-08-16T00:43:50.327Z,1629074630.327 [PowerOnly](INFO): Powering up loadControl
2021-08-16T00:43:52.414Z,1629074632.414 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2021-08-16T00:43:52.794Z,1629074632.794 [NAL9602](INFO): Not Powering down - fast GPS
2021-08-16T00:43:53.233Z,1629074633.233 [Micromodem](INFO): Nmea out: $CCPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*76

2021-08-16T00:43:53.394Z,1629074633.394 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detaching from dock.
2021-08-16T00:43:53.588Z,1629074633.588 [Micromodem](INFO): Nmea in: $SNPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6B

2021-08-16T00:43:53.624Z,1629074633.624 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detected possible detachment. Starting timer.
2021-08-16T00:43:54.404Z,1629074634.404 [Micromodem](INFO): Nmea in: $SNTTA,,,,,004354.74*5B

2021-08-16T00:43:54.973Z,1629074634.973 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2021-08-16T00:43:58.045Z,1629074638.045 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2021-08-16T00:43:58.846Z,1629074638.846 [Micromodem](INFO): Nmea out: $CCPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*76

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

2021-08-16T00:44:00.066Z,1629074640.066 [Micromodem](INFO): Nmea in: $SNTTA,,,,,004400.35*58

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

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

2021-08-16T00:44:05.722Z,1629074645.722 [Micromodem](INFO): Nmea in: $SNTTA,,,,,004406.00*58

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

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

2021-08-16T00:44:10.586Z,1629074650.586 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004659
2021-08-16T00:44:11.382Z,1629074651.382 [Micromodem](INFO): Nmea in: $SNTTA,,,,,004411.66*5E

2021-08-16T00:44:13.824Z,1629074653.824 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detached at range: 899.76 m. Transitioning DDM to standby.
2021-08-16T00:44:15.013Z,1629074655.013 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2021-08-16T00:44:15.814Z,1629074655.814 [Micromodem](INFO): Nmea out: $CCPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*76

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

2021-08-16T00:44:16.306Z,1629074656.306 [DefaultWithUndock:LeaveDock:B.Undock](INFO): DDM at standby.
2021-08-16T00:44:16.629Z,1629074656.629 [DefaultWithUndock:LeaveDock:B.Undock](IMPORTANT): Undocking sequence complete.
2021-08-16T00:44:16.630Z,1629074656.630 [DefaultWithUndock:LeaveDock:B.Undock] Stopped
2021-08-16T00:44:16.630Z,1629074656.630 [DefaultWithUndock:LeaveDock](INFO): Completed DefaultWithUndock:LeaveDock
2021-08-16T00:44:16.630Z,1629074656.630 [DefaultWithUndock:LeaveDock] Stopped
2021-08-16T00:44:16.630Z,1629074656.630 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::uninitialize DefaultWithUndock:LeaveDock
2021-08-16T00:44:16.630Z,1629074656.630 [DefaultWithUndock:LeaveDock:A.] Stopped
2021-08-16T00:44:16.630Z,1629074656.630 [DefaultWithUndock:SurfaceDefault] Running Loop=1
2021-08-16T00:44:16.631Z,1629074656.631 [DefaultWithUndock:SurfaceDefault](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault
2021-08-16T00:44:16.631Z,1629074656.631 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen] Running Loop=1
2021-08-16T00:44:16.631Z,1629074656.631 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:HoldLatchOpen
2021-08-16T00:44:16.631Z,1629074656.631 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:A] Running Loop=1
2021-08-16T00:44:16.631Z,1629074656.631 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:B] Running Loop=1
2021-08-16T00:44:16.631Z,1629074656.631 [DefaultWithUndock:SurfaceDefault:B.GoToSurface] Running Loop=1
2021-08-16T00:44:16.631Z,1629074656.631 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-08-16T00:44:16.632Z,1629074656.632 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-08-16T00:44:16.632Z,1629074656.632 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-08-16T00:44:16.632Z,1629074656.632 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-08-16T00:44:16.633Z,1629074656.633 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-08-16T00:44:16.633Z,1629074656.633 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-08-16T00:44:17.004Z,1629074657.004 [Micromodem](INFO): Nmea in: $SNTTA,,,,,004417.32*59

2021-08-16T00:44:17.044Z,1629074657.044 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=1
2021-08-16T00:44:17.045Z,1629074657.045 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2021-08-16T00:44:17.045Z,1629074657.045 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2021-08-16T00:44:17.045Z,1629074657.045 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen] Stopped
2021-08-16T00:44:17.045Z,1629074657.045 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:HoldLatchOpen
2021-08-16T00:44:17.045Z,1629074657.045 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:A] Stopped
2021-08-16T00:44:17.045Z,1629074657.045 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:B] Stopped
2021-08-16T00:44:17.477Z,1629074657.477 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2021-08-16T00:44:19.014Z,1629074659.014 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,004418.00,A,4133.38472,N,07043.04126,W,0.564,278.91,160821,,,A*75
2021-08-16T00:44:19.017Z,1629074659.017 [NAL9602](INFO): GPS fix at 20210816T004418: (41.556412, -70.717354)
2021-08-16T00:44:19.029Z,1629074659.029 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2021-08-16T00:44:19.029Z,1629074659.029 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2021-08-16T00:44:19.517Z,1629074659.517 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-08-16T00:44:22.631Z,1629074662.631 [DataOverHttps](INFO): Sending 52 bytes from file Logs/20210816T004033/Courier0004.lzma
2021-08-16T00:44:23.634Z,1629074663.634 [DataOverHttps](INFO): Moved sent file to Logs/20210816T004033/Courier0004.lzma.bak
2021-08-16T00:44:23.635Z,1629074663.635 [DataOverHttps](INFO): SBD MOMSN=445429
2021-08-16T00:44:32.671Z,1629074672.671 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210816T004033/Courier0007.lzma
2021-08-16T00:44:33.673Z,1629074673.673 [DataOverHttps](INFO): Moved sent file to Logs/20210816T004033/Courier0007.lzma.bak
2021-08-16T00:44:33.673Z,1629074673.673 [DataOverHttps](INFO): SBD MOMSN=445431
2021-08-16T00:44:42.715Z,1629074682.715 [DataOverHttps](INFO): Sending 1078 bytes from file Logs/20210816T002900/Express0008.lzma
2021-08-16T00:44:43.713Z,1629074683.713 [DataOverHttps](INFO): Moved sent file to Logs/20210816T002900/Express0008.lzma.bak
2021-08-16T00:44:43.713Z,1629074683.713 [DataOverHttps](INFO): SBD MOMSN=445434
2021-08-16T00:44:52.757Z,1629074692.757 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20210816T002900/Express0011.lzma
2021-08-16T00:44:53.567Z,1629074693.567 [NAL9602](INFO): SBD MO Status=0, MOMSN=24207, MT Status=0, MTMSN=0
2021-08-16T00:44:53.567Z,1629074693.567 [NAL9602](INFO): No messages in MT queue
2021-08-16T00:44:53.757Z,1629074693.757 [DataOverHttps](INFO): Moved sent file to Logs/20210816T002900/Express0011.lzma.bak
2021-08-16T00:44:53.757Z,1629074693.757 [DataOverHttps](INFO): SBD MOMSN=445470
2021-08-16T00:45:02.806Z,1629074702.806 [DataOverHttps](INFO): Sending 1079 bytes from file Logs/20210816T004033/Express0001.lzma
2021-08-16T00:45:03.805Z,1629074703.805 [DataOverHttps](INFO): Moved sent file to Logs/20210816T004033/Express0001.lzma.bak
2021-08-16T00:45:03.805Z,1629074703.805 [DataOverHttps](INFO): SBD MOMSN=445472
2021-08-16T00:45:12.843Z,1629074712.843 [DataOverHttps](INFO): Sending 104 bytes from file Logs/20210816T004033/Express0005.lzma
2021-08-16T00:45:13.845Z,1629074713.845 [DataOverHttps](INFO): Moved sent file to Logs/20210816T004033/Express0005.lzma.bak
2021-08-16T00:45:13.845Z,1629074713.845 [DataOverHttps](INFO): SBD MOMSN=445491
2021-08-16T00:45:21.838Z,1629074721.838 [PowerOnly](INFO): Powering down loadControl
2021-08-16T00:45:22.246Z,1629074722.246 [PowerOnly](FAULT): loadControl LCB fault:  Software Overcurrent.
2021-08-16T00:45:22.246Z,1629074722.246 [PowerOnly] Hardware Fault, FailCount= 1
2021-08-16T00:45:22.246Z,1629074722.246 [PowerOnly](ERROR): Hardware Fault
2021-08-16T00:45:22.266Z,1629074722.266 [CBIT](ERROR): Hardware Fault in component: PowerOnly
2021-08-16T00:45:22.645Z,1629074722.645 [PowerOnly](INFO): Powering down loadControl
2021-08-16T00:45:22.883Z,1629074722.883 [DataOverHttps](INFO): Sending 260 bytes from file Logs/20210816T004033/Express0008.lzma
2021-08-16T00:45:23.512Z,1629074723.512 [CBIT](INFO): Clearing failed state for component PowerOnly
2021-08-16T00:45:23.512Z,1629074723.512 [PowerOnly] No Fault, FailCount= 1
2021-08-16T00:45:23.885Z,1629074723.885 [DataOverHttps](INFO): Moved sent file to Logs/20210816T004033/Express0008.lzma.bak
2021-08-16T00:45:23.885Z,1629074723.885 [DataOverHttps](INFO): SBD MOMSN=445495
2021-08-16T00:45:24.292Z,1629074724.292 [NAL9602](INFO): Not Powering down - fast GPS
2021-08-16T00:45:25.074Z,1629074725.074 [PowerOnly](INFO): Powering down loadControl
2021-08-16T00:45:25.555Z,1629074725.555 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2021-08-16T00:45:25.555Z,1629074725.555 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2021-08-16T00:45:25.555Z,1629074725.555 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-08-16T00:46:05.053Z,1629074765.053 [DataOverHttps](IMPORTANT): SBD MTMSN=20210816T004604
2021-08-16T00:46:09.072Z,1629074769.072 [DataOverHttps](INFO): Received command:restart sys
2021-08-16T00:46:09.095Z,1629074769.095 [CommandLine](IMPORTANT): got command restart system
2021-08-16T00:46:11.156Z,1629074771.156 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2021-08-16T00:46:11.158Z,1629074771.158 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2021-08-16T00:46:11.159Z,1629074771.159 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-08-16T00:46:11.223Z,1629074771.223 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2021-08-16T00:46:11.224Z,1629074771.224 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-08-16T00:46:11.224Z,1629074771.224 [CommandLine](INFO): Join timeout helper Thread ID is 986
2021-08-16T00:46:11.239Z,1629074771.239 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2021-08-16T00:46:11.239Z,1629074771.239 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-08-16T00:46:11.240Z,1629074771.240 [NavChartDb](INFO): Join timeout helper Thread ID is 987
2021-08-16T00:46:11.259Z,1629074771.259 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2021-08-16T00:46:11.260Z,1629074771.260 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-08-16T00:46:11.271Z,1629074771.271 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2021-08-16T00:46:11.271Z,1629074771.271 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2021-08-16T00:46:11.272Z,1629074771.272 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 988
2021-08-16T00:46:11.467Z,1629074771.467 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitiali