2022-09-05T11:31:13.990Z,1662377473.990 [Supervisor](DEBUG): Initializing supervisor.
2022-09-05T11:31:13.994Z,1662377473.994 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2022-09-05T11:31:13.994Z,1662377473.994 [SyncHandler](INFO): Protected caller Thread ID is 5508
2022-09-05T11:31:13.995Z,1662377473.995 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2022-09-05T11:31:13.996Z,1662377473.996 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2022-09-05T11:31:13.996Z,1662377473.996 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 5509
2022-09-05T11:31:14.000Z,1662377474.000 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2022-09-05T11:31:14.017Z,1662377474.017 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2022-09-05T11:31:14.018Z,1662377474.018 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2022-09-05T11:31:14.018Z,1662377474.018 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 5510
2022-09-05T11:31:14.022Z,1662377474.022 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2022-09-05T11:31:14.023Z,1662377474.023 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2022-09-05T11:31:14.024Z,1662377474.024 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 5511
2022-09-05T11:31:14.026Z,1662377474.026 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2022-09-05T11:31:14.027Z,1662377474.027 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2022-09-05T11:31:14.027Z,1662377474.027 [logger ThreadHandler](INFO): Protected caller Thread ID is 5512
2022-09-05T11:31:14.031Z,1662377474.031 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2022-09-05T11:31:14.031Z,1662377474.031 [Supervisor](INFO): Looking for Config files in directory: Config/
2022-09-05T11:31:14.035Z,1662377474.035 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2022-09-05T11:31:14.500Z,1662377474.500 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2022-09-05T11:31:14.501Z,1662377474.501 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2022-09-05T11:31:14.583Z,1662377474.583 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2022-09-05T11:31:14.907Z,1662377474.907 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2022-09-05T11:31:14.909Z,1662377474.909 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2022-09-05T11:31:15.017Z,1662377475.017 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2022-09-05T11:31:15.018Z,1662377475.018 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2022-09-05T11:31:15.210Z,1662377475.210 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2022-09-05T11:31:15.211Z,1662377475.211 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2022-09-05T11:31:15.678Z,1662377475.678 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2022-09-05T11:31:15.679Z,1662377475.679 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2022-09-05T11:31:15.944Z,1662377475.944 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2022-09-05T11:31:15.946Z,1662377475.946 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2022-09-05T11:31:16.158Z,1662377476.158 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2022-09-05T11:31:16.160Z,1662377476.160 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2022-09-05T11:31:16.348Z,1662377476.348 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2022-09-05T11:31:16.349Z,1662377476.349 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2022-09-05T11:31:16.448Z,1662377476.448 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2022-09-05T11:31:16.448Z,1662377476.448 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2022-09-05T11:31:16.669Z,1662377476.669 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2022-09-05T11:31:16.671Z,1662377476.671 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2022-09-05T11:31:17.045Z,1662377477.045 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2022-09-05T11:31:17.046Z,1662377477.046 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2022-09-05T11:31:17.131Z,1662377477.131 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2022-09-05T11:31:17.270Z,1662377477.270 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2022-09-05T11:31:17.270Z,1662377477.270 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2022-09-05T11:31:17.961Z,1662377477.961 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2022-09-05T11:31:17.961Z,1662377477.961 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2022-09-05T11:31:18.362Z,1662377478.362 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2022-09-05T11:31:18.365Z,1662377478.365 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-polaris/
2022-09-05T11:31:18.637Z,1662377478.637 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/vehicle.cfg
2022-09-05T11:31:19.305Z,1662377479.305 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Control.cfg
2022-09-05T11:31:19.409Z,1662377479.409 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Estimation.cfg
2022-09-05T11:31:19.511Z,1662377479.511 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/BIT.cfg
2022-09-05T11:31:19.613Z,1662377479.613 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Battery.cfg
2022-09-05T11:31:19.876Z,1662377479.876 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2022-09-05T11:31:19.877Z,1662377479.877 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Simulator.cfg
2022-09-05T11:31:19.988Z,1662377479.988 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Navigation.cfg
2022-09-05T11:31:20.093Z,1662377480.093 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Derivation.cfg
2022-09-05T11:31:20.216Z,1662377480.216 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/logger.cfg
2022-09-05T11:31:20.329Z,1662377480.329 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/secure.cfg
2022-09-05T11:31:20.416Z,1662377480.416 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Dock.cfg
2022-09-05T11:31:20.504Z,1662377480.504 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Servo.cfg
2022-09-05T11:31:20.615Z,1662377480.615 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/workSite.cfg
2022-09-05T11:31:20.731Z,1662377480.731 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Sensor.cfg
2022-09-05T11:31:20.929Z,1662377480.929 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Science.cfg
2022-09-05T11:31:21.085Z,1662377481.085 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2022-09-05T11:31:21.102Z,1662377481.102 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2022-09-05T11:31:21.641Z,1662377481.641 [AHRS_M2] Loaded
2022-09-05T11:31:21.641Z,1662377481.641 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2022-09-05T11:31:22.408Z,1662377482.408 [BPC1] Loaded
2022-09-05T11:31:22.408Z,1662377482.408 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2022-09-05T11:31:22.490Z,1662377482.490 [DataOverHttps] Loaded
2022-09-05T11:31:22.490Z,1662377482.490 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2022-09-05T11:31:22.491Z,1662377482.491 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407E44E0
2022-09-05T11:31:22.492Z,1662377482.492 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 5606
2022-09-05T11:31:22.516Z,1662377482.516 [DDM] Loaded
2022-09-05T11:31:22.516Z,1662377482.516 [ComponentRegistry](DEBUG): SyncComponent "DDM" handled in the control thread.
2022-09-05T11:31:22.536Z,1662377482.536 [Depth_Keller] Loaded
2022-09-05T11:31:22.536Z,1662377482.536 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2022-09-05T11:31:22.540Z,1662377482.540 [DropWeight] Loaded
2022-09-05T11:31:22.541Z,1662377482.541 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2022-09-05T11:31:22.589Z,1662377482.589 [Micromodem] Loaded
2022-09-05T11:31:22.589Z,1662377482.589 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2022-09-05T11:31:22.649Z,1662377482.649 [NAL9602] Loaded
2022-09-05T11:31:22.649Z,1662377482.649 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2022-09-05T11:31:22.678Z,1662377482.678 [Onboard] Loaded
2022-09-05T11:31:22.678Z,1662377482.678 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2022-09-05T11:31:22.679Z,1662377482.679 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408144E0
2022-09-05T11:31:22.680Z,1662377482.680 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 5607
2022-09-05T11:31:22.686Z,1662377482.686 [PowerOnly](INFO): Adding load control power supply at /dev/loadC1
2022-09-05T11:31:22.696Z,1662377482.696 [PowerOnly] Loaded
2022-09-05T11:31:22.696Z,1662377482.696 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2022-09-05T11:31:22.708Z,1662377482.708 [Power24vConverter] Loaded
2022-09-05T11:31:22.709Z,1662377482.709 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2022-09-05T11:31:22.722Z,1662377482.722 [Radio_Surface] Loaded
2022-09-05T11:31:22.722Z,1662377482.722 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2022-09-05T11:31:22.723Z,1662377482.723 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408444E0
2022-09-05T11:31:22.724Z,1662377482.724 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 5608
2022-09-05T11:31:22.767Z,1662377482.767 [RDI_Pathfinder] Loaded
2022-09-05T11:31:22.768Z,1662377482.768 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2022-09-05T11:31:22.794Z,1662377482.794 [RDI_PathfinderUp] Loaded
2022-09-05T11:31:22.794Z,1662377482.794 [ComponentRegistry](DEBUG): SyncComponent "RDI_PathfinderUp" handled in the control thread.
2022-09-05T11:31:22.795Z,1662377482.795 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2022-09-05T11:31:22.796Z,1662377482.796 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2022-09-05T11:31:22.809Z,1662377482.809 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2022-09-05T11:31:22.809Z,1662377482.809 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2022-09-05T11:31:22.937Z,1662377482.937 [DeadReckonUsingMultipleVelocitySources] Loaded
2022-09-05T11:31:22.937Z,1662377482.937 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2022-09-05T11:31:22.961Z,1662377482.961 [LBLNavigation] Loaded
2022-09-05T11:31:22.961Z,1662377482.961 [ComponentRegistry](DEBUG): SyncComponent "LBLNavigation" handled in the control thread.
2022-09-05T11:31:22.974Z,1662377482.974 [NavChart] Loaded
2022-09-05T11:31:22.974Z,1662377482.974 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2022-09-05T11:31:22.979Z,1662377482.979 [UniversalFixResidualReporter] Loaded
2022-09-05T11:31:22.980Z,1662377482.980 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2022-09-05T11:31:22.990Z,1662377482.990 [WorkSite] Loaded
2022-09-05T11:31:22.990Z,1662377482.990 [ComponentRegistry](DEBUG): SyncComponent "WorkSite" handled in the control thread.
2022-09-05T11:31:22.990Z,1662377482.990 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2022-09-05T11:31:22.991Z,1662377482.991 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2022-09-05T11:31:23.103Z,1662377483.103 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2022-09-05T11:31:23.104Z,1662377483.104 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2022-09-05T11:31:23.246Z,1662377483.246 [BuoyancyServo] Loaded
2022-09-05T11:31:23.246Z,1662377483.246 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2022-09-05T11:31:23.268Z,1662377483.268 [ElevatorServo] Loaded
2022-09-05T11:31:23.268Z,1662377483.268 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2022-09-05T11:31:23.293Z,1662377483.293 [DockingServo] Loaded
2022-09-05T11:31:23.293Z,1662377483.293 [ComponentRegistry](DEBUG): SyncComponent "DockingServo" handled in the control thread.
2022-09-05T11:31:23.313Z,1662377483.313 [MassServo] Loaded
2022-09-05T11:31:23.314Z,1662377483.314 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2022-09-05T11:31:23.333Z,1662377483.333 [RudderServo] Loaded
2022-09-05T11:31:23.334Z,1662377483.334 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2022-09-05T11:31:23.349Z,1662377483.349 [ThrusterHE] Loaded
2022-09-05T11:31:23.350Z,1662377483.350 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2022-09-05T11:31:23.350Z,1662377483.350 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2022-09-05T11:31:23.350Z,1662377483.350 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2022-09-05T11:31:24.144Z,1662377484.144 [CTD_Seabird] Loaded
2022-09-05T11:31:24.144Z,1662377484.144 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2022-09-05T11:31:24.145Z,1662377484.145 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409824E0
2022-09-05T11:31:24.146Z,1662377484.146 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 5609
2022-09-05T11:31:24.177Z,1662377484.177 [WetLabsSeaOWL_UV_A] Loaded
2022-09-05T11:31:24.177Z,1662377484.177 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2022-09-05T11:31:24.178Z,1662377484.178 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 409B24E0
2022-09-05T11:31:24.179Z,1662377484.179 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 5610
2022-09-05T11:31:24.180Z,1662377484.180 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2022-09-05T11:31:24.180Z,1662377484.180 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2022-09-05T11:31:24.518Z,1662377484.518 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2022-09-05T11:31:24.518Z,1662377484.518 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2022-09-05T11:31:24.579Z,1662377484.579 [DepthRateCalculator] Loaded
2022-09-05T11:31:24.579Z,1662377484.579 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2022-09-05T11:31:24.584Z,1662377484.584 [PitchRateCalculator] Loaded
2022-09-05T11:31:24.585Z,1662377484.585 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2022-09-05T11:31:24.593Z,1662377484.593 [SpeedCalculator] Loaded
2022-09-05T11:31:24.594Z,1662377484.594 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2022-09-05T11:31:24.606Z,1662377484.606 [TempGradientCalculator] Loaded
2022-09-05T11:31:24.606Z,1662377484.606 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2022-09-05T11:31:24.621Z,1662377484.621 [VerticalHomogeneityIndexCalculator] Loaded
2022-09-05T11:31:24.621Z,1662377484.621 [ComponentRegistry](DEBUG): SyncComponent "VerticalHomogeneityIndexCalculator" handled in the control thread.
2022-09-05T11:31:24.626Z,1662377484.626 [YawRateCalculator] Loaded
2022-09-05T11:31:24.626Z,1662377484.626 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2022-09-05T11:31:24.648Z,1662377484.648 [ElevatorOffsetCalculator] Loaded
2022-09-05T11:31:24.648Z,1662377484.648 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2022-09-05T11:31:24.648Z,1662377484.648 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2022-09-05T11:31:24.649Z,1662377484.649 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2022-09-05T11:31:24.809Z,1662377484.809 [SBIT](DEBUG): Construct Startup Built In Test.
2022-09-05T11:31:24.821Z,1662377484.821 [SBIT] Loaded
2022-09-05T11:31:24.821Z,1662377484.821 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2022-09-05T11:31:24.824Z,1662377484.824 [IBIT](DEBUG): Construct Initiated Built In Test.
2022-09-05T11:31:24.836Z,1662377484.836 [IBIT] Loaded
2022-09-05T11:31:24.836Z,1662377484.836 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2022-09-05T11:31:24.842Z,1662377484.842 [CBIT](DEBUG): Construct Continuous Built In Test.
2022-09-05T11:31:24.945Z,1662377484.945 [CBIT] Loaded
2022-09-05T11:31:24.945Z,1662377484.945 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2022-09-05T11:31:24.945Z,1662377484.945 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2022-09-05T11:31:24.946Z,1662377484.946 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2022-09-05T11:31:25.020Z,1662377485.020 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2022-09-05T11:31:25.021Z,1662377485.021 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2022-09-05T11:31:25.196Z,1662377485.196 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2022-09-05T11:31:25.196Z,1662377485.196 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2022-09-05T11:31:25.257Z,1662377485.257 [VerticalControl](DEBUG): Construct VerticalControl.
2022-09-05T11:31:25.305Z,1662377485.305 [VerticalControl] Loaded
2022-09-05T11:31:25.306Z,1662377485.306 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2022-09-05T11:31:25.309Z,1662377485.309 [HorizontalControl](DEBUG): Construct HorizontalControl.
2022-09-05T11:31:25.346Z,1662377485.346 [HorizontalControl] Loaded
2022-09-05T11:31:25.346Z,1662377485.346 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2022-09-05T11:31:25.349Z,1662377485.349 [SpeedControl](DEBUG): Construct SpeedControl.
2022-09-05T11:31:25.350Z,1662377485.350 [SpeedControl] Loaded
2022-09-05T11:31:25.351Z,1662377485.351 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2022-09-05T11:31:25.353Z,1662377485.353 [LoopControl](DEBUG): Construct LoopControl.
2022-09-05T11:31:25.354Z,1662377485.354 [LoopControl] Loaded
2022-09-05T11:31:25.354Z,1662377485.354 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2022-09-05T11:31:25.355Z,1662377485.355 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2022-09-05T11:31:25.355Z,1662377485.355 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2022-09-05T11:31:25.393Z,1662377485.393 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2022-09-05T11:31:25.400Z,1662377485.400 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2022-09-05T11:31:25.403Z,1662377485.403 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2022-09-05T11:31:25.414Z,1662377485.414 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2022-09-05T11:31:25.415Z,1662377485.415 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B6E4E0
2022-09-05T11:31:25.415Z,1662377485.415 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 5611
2022-09-05T11:31:25.419Z,1662377485.419 [Supervisor](INFO): Main Thread ID is 3443
2022-09-05T11:31:25.420Z,1662377485.420 [Supervisor](DEBUG): Running supervisor.
2022-09-05T11:31:25.420Z,1662377485.420 [CommandExec ThreadHandler](INFO): Handler Thread ID is 5612
2022-09-05T11:31:25.421Z,1662377485.421 [CommandExec](INFO): Initializing the command executive.
2022-09-05T11:31:25.422Z,1662377485.422 [CommandLine ThreadHandler](INFO): Handler Thread ID is 5613
2022-09-05T11:31:25.424Z,1662377485.424 [controlThread ThreadHandler](INFO): Handler Thread ID is 5614
2022-09-05T11:31:25.425Z,1662377485.425 [controlThread](DEBUG): Initializing ControlThread
2022-09-05T11:31:25.430Z,1662377485.430 [NavChart](DEBUG): Initialize NavChart Navigation.
2022-09-05T11:31:25.431Z,1662377485.431 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2022-09-05T11:31:25.431Z,1662377485.431 [WorkSite](DEBUG): Initializing WorkSite component.
2022-09-05T11:31:25.433Z,1662377485.433 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2022-09-05T11:31:25.433Z,1662377485.433 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2022-09-05T11:31:25.433Z,1662377485.433 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2022-09-05T11:31:25.434Z,1662377485.434 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2022-09-05T11:31:25.434Z,1662377485.434 [VerticalHomogeneityIndexCalculator](DEBUG): (re)initializing
2022-09-05T11:31:25.435Z,1662377485.435 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2022-09-05T11:31:25.435Z,1662377485.435 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2022-09-05T11:31:25.436Z,1662377485.436 [SBIT](INFO): Initialize SBIT Component.
2022-09-05T11:31:25.436Z,1662377485.436 [SBIT](IMPORTANT): git: 2022-08-25
2022-09-05T11:31:25.437Z,1662377485.437 [SBIT](INFO): git hash: e1ddd60859d931066d70c4e9618f9367e52a6cfe
2022-09-05T11:31:25.437Z,1662377485.437 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2022-09-05T11:31:25.438Z,1662377485.438 [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
2022-09-05T11:31:25.439Z,1662377485.439 [SBIT](INFO): Beginning SBIT in 55.000000 seconds.
2022-09-05T11:31:25.440Z,1662377485.440 [IBIT](INFO): Initialize IBIT Component.
2022-09-05T11:31:25.441Z,1662377485.441 [CBIT](DEBUG): Initialize CBIT Component.
2022-09-05T11:31:25.442Z,1662377485.442 [logger ThreadHandler](INFO): Handler Thread ID is 5615
2022-09-05T11:31:25.455Z,1662377485.455 [CBIT](DEBUG): Initialized mux pins.
2022-09-05T11:31:25.455Z,1662377485.455 [CBIT](DEBUG): Initializing the watchdog timer.
2022-09-05T11:31:25.459Z,1662377485.459 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 5616
2022-09-05T11:31:25.460Z,1662377485.460 [DataOverHttps](DEBUG): dashIP=128.128.181.226 starts with a digit so assuming it is a numeric IP
2022-09-05T11:31:25.468Z,1662377485.468 [Onboard ThreadHandler](INFO): Handler Thread ID is 5617
2022-09-05T11:31:25.480Z,1662377485.480 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2022-09-05T11:31:25.480Z,1662377485.480 [CBIT](DEBUG): Initializing heartbeat.
2022-09-05T11:31:25.492Z,1662377485.492 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 5618
2022-09-05T11:31:25.502Z,1662377485.502 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 5619
2022-09-05T11:31:25.511Z,1662377485.511 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2022-09-05T11:31:25.513Z,1662377485.513 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 5621
2022-09-05T11:31:25.517Z,1662377485.517 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 5622
2022-09-05T11:31:25.524Z,1662377485.524 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2022-09-05T11:31:25.524Z,1662377485.524 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2022-09-05T11:31:25.524Z,1662377485.524 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2022-09-05T11:31:25.525Z,1662377485.525 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2022-09-05T11:31:25.525Z,1662377485.525 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2022-09-05T11:31:25.525Z,1662377485.525 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2022-09-05T11:31:25.525Z,1662377485.525 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2022-09-05T11:31:25.525Z,1662377485.525 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2022-09-05T11:31:25.551Z,1662377485.551 [CBIT](DEBUG): Deactivating GF circuits.
2022-09-05T11:31:25.551Z,1662377485.551 [CBIT](DEBUG): Deactivating emergency mode.
2022-09-05T11:31:25.587Z,1662377485.587 [CBIT](DEBUG): Backplane powered.
2022-09-05T11:31:25.587Z,1662377485.587 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2022-09-05T11:31:25.589Z,1662377485.589 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2022-09-05T11:31:25.590Z,1662377485.590 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2022-09-05T11:31:25.590Z,1662377485.590 [LoopControl](DEBUG): Initialize LoopControlComponent.
2022-09-05T11:31:25.591Z,1662377485.591 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2022-09-05T11:31:25.618Z,1662377485.618 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2022-09-05T11:31:25.634Z,1662377485.634 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

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

    <Aggregate Id="StartupSatComms">

        <Sequence/>

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

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

    </Aggregate>

</Mission>


2022-09-05T11:31:25.634Z,1662377485.634 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2022-09-05T11:31:25.725Z,1662377485.725 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2022-09-05T11:31:25.726Z,1662377485.726 [Default:A.Wait](DEBUG): Construct Wait.
2022-09-05T11:31:25.728Z,1662377485.728 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2022-09-05T11:31:25.787Z,1662377485.787 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2022-09-05T11:31:25.790Z,1662377485.790 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2022-09-05T11:31:25.812Z,1662377485.812 [Default:E.Execute](DEBUG): Construct Execute.
2022-09-05T11:31:25.831Z,1662377485.831 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

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

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

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

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

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

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

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

    </Aggregate>

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

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

</Mission>


2022-09-05T11:31:25.837Z,1662377485.837 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,DDM,Depth_Keller,DropWeight,Micromodem,NAL9602,PowerOnly,Power24vConverter,RDI_Pathfinder,RDI_PathfinderUp,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,WorkSite,LBLNavigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,DockingServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2022-09-05T11:31:25.859Z,1662377485.859 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2022-09-05T11:31:25.899Z,1662377485.899 [Radio_Surface](INFO): Powering up
2022-09-05T11:31:25.919Z,1662377485.919 [DDM](INFO): Powering up
2022-09-05T11:31:25.920Z,1662377485.920 [DDM](DEBUG): Initializing DDM.
2022-09-05T11:31:25.940Z,1662377485.940 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar
2022-09-05T11:31:25.942Z,1662377485.942 [Power24vConverter](INFO): Powering up.
2022-09-05T11:31:25.943Z,1662377485.943 [RDI_Pathfinder](IMPORTANT): Expecting PD13 message format
2022-09-05T11:31:25.967Z,1662377485.967 [DepthRateCalculator](ERROR): Depth measurement is not active
2022-09-05T11:31:25.993Z,1662377485.993 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2022-09-05T11:31:25.999Z,1662377485.999 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2022-09-05T11:31:26.000Z,1662377486.000 [ElevatorServo](DEBUG): Initializing EZServoServo.
2022-09-05T11:31:26.007Z,1662377486.007 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2022-09-05T11:31:26.008Z,1662377486.008 [DockingServo](DEBUG): Initializing DockingServo.
2022-09-05T11:31:26.009Z,1662377486.009 [MassServo](DEBUG): Initializing EZServoServo.
2022-09-05T11:31:26.015Z,1662377486.015 [MassServo](DEBUG): Initializing MassServo.
2022-09-05T11:31:26.016Z,1662377486.016 [RudderServo](DEBUG): Initializing EZServoServo.
2022-09-05T11:31:26.023Z,1662377486.023 [RudderServo](DEBUG): Initializing RudderServo.
2022-09-05T11:31:26.024Z,1662377486.024 [ThrusterHE](DEBUG): Initializing EZServoServo.
2022-09-05T11:31:26.032Z,1662377486.032 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2022-09-05T11:31:26.278Z,1662377486.278 [Micromodem](INFO): Powering up
2022-09-05T11:31:26.278Z,1662377486.278 [Micromodem](DEBUG): Initializing Micromodem.
2022-09-05T11:31:26.975Z,1662377486.975 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2022-09-05T11:31:26.975Z,1662377486.975 [RudderServo](FAULT): Rudder failed to initialize
2022-09-05T11:31:26.975Z,1662377486.975 [RudderServo] Communications Fault, FailCount= 1
2022-09-05T11:31:26.975Z,1662377486.975 [RudderServo](ERROR): Communications Fault
2022-09-05T11:31:26.980Z,1662377486.980 [CBIT](ERROR): Communications Fault in component: RudderServo
2022-09-05T11:31:27.194Z,1662377487.194 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-09-05T11:31:27.194Z,1662377487.194 [RudderServo](INFO): Powering down
2022-09-05T11:31:27.875Z,1662377487.875 [RudderServo](DEBUG): Initializing EZServoServo.
2022-09-05T11:31:27.996Z,1662377487.996 [RudderServo](DEBUG): Initializing RudderServo.
2022-09-05T11:31:27.000Z,1662377488.000 [CBIT](INFO): Clearing failed state for component RudderServo
2022-09-05T11:31:28.000Z,1662377488.000 [RudderServo] No Fault, FailCount= 1
2022-09-05T11:31:31.137Z,1662377491.137 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33

2022-09-05T11:31:32.548Z,1662377492.548 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2022-09-05T11:31:33.157Z,1662377493.157 [Micromodem](INFO): Nmea in: $CATMG,2022-09-05T11:31:32.646374Z,RTC,RTC*59

2022-09-05T11:31:33.158Z,1662377493.158 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2022-09-05T11:31:32.646374Z,RTC,RTC*59

2022-09-05T11:31:41.601Z,1662377501.601 [DDM](INFO): Latch/Whisker Boards:V1,H_RECOVERY_LATCH
!V2,H_RECOVERY_WHISKERS
2022-09-05T11:31:41.703Z,1662377501.703 [DDM](INFO): Dynamic Docking Module:C REMUS Capture Rev 1.1
2022-09-05T11:31:42.437Z,1662377502.437 [Micromodem](ERROR): Nmea resend: $CCCFG,ALL,0*33

2022-09-05T11:31:42.818Z,1662377502.818 [Micromodem](INFO): Nmea in: $CAERR,113143,NI  ,12,Unknown command*49

2022-09-05T11:31:42.818Z,1662377502.818 [Micromodem](ERROR): Got error from modem: $CAERR,113143,NI  ,12,Unknown command*49

2022-09-05T11:31:52.917Z,1662377512.917 [NAL9602](INFO): Powering up NAL9602
2022-09-05T11:31:53.725Z,1662377513.725 [Micromodem](ERROR): Nmea resend: $CCCFG,ALL,0*33

2022-09-05T11:31:54.168Z,1662377514.168 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31

2022-09-05T11:31:54.169Z,1662377514.169 [Micromodem](INFO): Nmea out: $CCCFG,POW,20*08

2022-09-05T11:31:54.533Z,1662377514.533 [Micromodem](INFO): Nmea in: $CACFG,POW,20*0A

2022-09-05T11:31:54.533Z,1662377514.533 [Micromodem](INFO): Nmea out: $CCCFG,SRC,0*30

2022-09-05T11:31:54.937Z,1662377514.937 [Micromodem](INFO): Nmea in: $CACFG,SRC,0*32

2022-09-05T11:31:54.937Z,1662377514.937 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64

2022-09-05T11:31:55.345Z,1662377515.345 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66

2022-09-05T11:31:55.346Z,1662377515.346 [Micromodem](INFO): Nmea out: $CCCFG,pwramp.txlevel,0*2F

2022-09-05T11:31:55.754Z,1662377515.754 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,0*2D

2022-09-05T11:31:55.754Z,1662377515.754 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E

2022-09-05T11:31:56.149Z,1662377516.149 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C

2022-09-05T11:31:56.149Z,1662377516.149 [Micromodem](INFO): Nmea out: $CCCFG,FC0,14500*47

2022-09-05T11:31:56.565Z,1662377516.565 [Micromodem](INFO): Nmea in: $CACFG,FC0,14500*45

2022-09-05T11:31:56.565Z,1662377516.565 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63

2022-09-05T11:31:56.957Z,1662377516.957 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61

2022-09-05T11:31:56.957Z,1662377516.957 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A

2022-09-05T11:31:57.373Z,1662377517.373 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38

2022-09-05T11:31:57.374Z,1662377517.374 [Micromodem](INFO): Nmea out: $CCCLK,2022,09,05,11,31,58*45

2022-09-05T11:31:57.765Z,1662377517.765 [Micromodem](INFO): Nmea in: $CACLK,2022,9,5,11,31,58*47

2022-09-05T11:31:57.767Z,1662377517.767 [Micromodem](INFO): Nmea in: $CATMS,0,2022-09-05T11:31:59Z*76

2022-09-05T11:31:57.768Z,1662377517.768 [Micromodem](INFO): Nmea in: $CATMG,2022-09-05T11:31:59.028514Z,USER_CMD,RTC*1B

2022-09-05T11:32:03.835Z,1662377523.835 [NAL9602](INFO): NAL9602 initialized
2022-09-05T11:32:18.375Z,1662377538.375 [NAL9602](INFO): SBD MO Status=0, MOMSN=46007, MT Status=0, MTMSN=0
2022-09-05T11:32:18.376Z,1662377538.376 [NAL9602](INFO): No messages in MT queue
2022-09-05T11:32:20.814Z,1662377540.814 [SBIT](IMPORTANT): Beginning Startup BIT
2022-09-05T11:32:20.826Z,1662377540.826 [CBIT](IMPORTANT): Beginning ground fault scan
2022-09-05T11:32:31.879Z,1662377551.879 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.121594
CHAN A1 (24V): 0.314013
CHAN A2 (12V): 0.043783
CHAN A3 (5V): 0.000245
CHAN B0 (3.3V): 0.001524
CHAN B1 (3.15aV): 0.001650
CHAN B2 (3.15bV): 0.001656
CHAN B3 (GND): 0.001074
OPEN: 0.006345
Full Scale: +/- 1 mA
2022-09-05T11:32:55.575Z,1662377575.575 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,113303.00,A,4014.02448,N,07040.37151,W,0.330,0.00,050922,,,A*7A
2022-09-05T11:32:55.578Z,1662377575.578 [NAL9602](INFO): GPS fix at 20220905T113303: (40.233741, -70.672859)
2022-09-05T11:32:55.600Z,1662377575.600 [LBLNavigation](INFO): Reset ping filters
2022-09-05T11:32:55.600Z,1662377575.600 [LBLNavigation](INFO): Reset fix filter
2022-09-05T11:33:14.983Z,1662377594.983 [SBIT](IMPORTANT): SBIT PASSED
2022-09-05T11:33:14.983Z,1662377594.983 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2022-09-05T11:33:14.984Z,1662377594.984 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count;

2022-09-05T11:33:14.984Z,1662377594.984 [SBIT](IMPORTANT): CBIT.abortDepth=250 meter;

2022-09-05T11:33:14.984Z,1662377594.984 [SBIT](IMPORTANT): CBIT.gfScanTimeout=2 hour;

2022-09-05T11:33:14.984Z,1662377594.984 [SBIT](IMPORTANT): CBIT.stopDepth=200 meter;

2022-09-05T11:33:14.985Z,1662377594.985 [SBIT](IMPORTANT): DDM.loadAtStartup=1 bool;

2022-09-05T11:33:14.985Z,1662377594.985 [SBIT](IMPORTANT): DockingServo.loadAtStartup=1 bool;

2022-09-05T11:33:14.985Z,1662377594.985 [SBIT](IMPORTANT): Express linearApproximation CTD_Seabird.bin_median_sea_water_salinity 0.050000 practical_salinity_unit;

2022-09-05T11:33:14.985Z,1662377594.985 [SBIT](IMPORTANT): Express linearApproximation CTD_Seabird.bin_median_sea_water_temperature 0.500000 celsius;

2022-09-05T11:33:14.985Z,1662377594.985 [SBIT](IMPORTANT): LineCapture.armSpeed=1.2 meter_per_second;

2022-09-05T11:33:14.985Z,1662377594.985 [SBIT](IMPORTANT): LineCapture.midcourseSpeed=1.2 meter_per_second;

2022-09-05T11:33:14.985Z,1662377594.985 [SBIT](IMPORTANT): LineCapture.rolloutTimeout=6 minute;

2022-09-05T11:33:14.985Z,1662377594.985 [SBIT](IMPORTANT): LineCapture.shortFinalRange=-1 meter;

2022-09-05T11:33:14.985Z,1662377594.985 [SBIT](IMPORTANT): LineCapture.terminalRange=300 meter;

2022-09-05T11:33:14.986Z,1662377594.986 [SBIT](IMPORTANT): LineCapture.verbose=1 bool;

2022-09-05T11:33:14.986Z,1662377594.986 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=152.268921 cubic_centimeter;

2022-09-05T11:33:14.986Z,1662377594.986 [SBIT](IMPORTANT): VerticalControl.massDefault=8.973020 millimeter;

2022-09-05T11:33:15.367Z,1662377595.367 [WorkSite](INFO): Already have valid position. Ignoring workSite position from Data/workSite.cfg
2022-09-05T11:33:15.374Z,1662377595.374 [MissionManager](IMPORTANT): Started mission Startup
2022-09-05T11:33:15.376Z,1662377595.376 [Startup] Running Loop=1
2022-09-05T11:33:15.376Z,1662377595.376 [Startup](DEBUG): Aggregate::initialize Startup
2022-09-05T11:33:15.377Z,1662377595.377 [Startup:A.GoToSurface] Running Loop=1
2022-09-05T11:33:15.377Z,1662377595.377 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-09-05T11:33:15.378Z,1662377595.378 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-09-05T11:33:15.379Z,1662377595.379 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-09-05T11:33:15.379Z,1662377595.379 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-09-05T11:33:15.380Z,1662377595.380 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-09-05T11:33:15.380Z,1662377595.380 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-09-05T11:33:15.381Z,1662377595.381 [Startup:StartupSatComms] Running Loop=1
2022-09-05T11:33:15.381Z,1662377595.381 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2022-09-05T11:33:15.382Z,1662377595.382 [Startup:StartupSatComms:A] Running Loop=1
2022-09-05T11:33:15.775Z,1662377595.775 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2022-09-05T11:33:17.359Z,1662377597.359 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,113325.00,A,4014.02693,N,07040.37087,W,0.136,25.45,050922,,,A*42
2022-09-05T11:33:17.361Z,1662377597.361 [NAL9602](INFO): GPS fix at 20220905T113325: (40.233782, -70.672848)
2022-09-05T11:33:17.392Z,1662377597.392 [Startup:StartupSatComms:A] Stopped
2022-09-05T11:33:17.392Z,1662377597.392 [Startup:StartupSatComms:B] Running Loop=1
2022-09-05T11:33:17.800Z,1662377597.800 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-09-05T11:33:31.555Z,1662377611.555 [NAL9602](INFO): SBD MO Status=1, MOMSN=46008, MT Status=0, MTMSN=0
2022-09-05T11:33:31.603Z,1662377611.603 [NAL9602](INFO): Sent 52 bytes from file Logs/20220904T034549/Courier0118.lzma
2022-09-05T11:33:31.603Z,1662377611.603 [NAL9602](INFO): Packets left to send: 0
2022-09-05T11:33:41.098Z,1662377621.098 [NAL9602](INFO): SBD MO Status=1, MOMSN=46009, MT Status=0, MTMSN=0
2022-09-05T11:33:41.159Z,1662377621.159 [NAL9602](INFO): Sent 184 bytes from file Logs/20220905T113113/Courier0000.lzma
2022-09-05T11:33:41.159Z,1662377621.159 [NAL9602](INFO): Packets left to send: 1
2022-09-05T11:33:50.830Z,1662377630.830 [NAL9602](INFO): SBD MO Status=1, MOMSN=46010, MT Status=0, MTMSN=0
2022-09-05T11:33:50.876Z,1662377630.876 [NAL9602](INFO): Sent 67 bytes from file Logs/20220905T113113/Courier0000.lzma
2022-09-05T11:33:50.876Z,1662377630.876 [NAL9602](INFO): Packets left to send: 0
2022-09-05T11:34:01.821Z,1662377641.821 [NAL9602](INFO): SBD MO Status=1, MOMSN=46011, MT Status=0, MTMSN=0
2022-09-05T11:34:01.871Z,1662377641.871 [NAL9602](INFO): Sent 184 bytes from file Logs/20220904T034549/Express0119.lzma
2022-09-05T11:34:01.871Z,1662377641.871 [NAL9602](INFO): Packets left to send: 3
2022-09-05T11:34:11.900Z,1662377651.900 [CommandExec](IMPORTANT): got command DDM arm
2022-09-05T11:34:11.900Z,1662377651.900 [CommandExec](IMPORTANT): Switching docking moudle to ARM.
2022-09-05T11:34:13.489Z,1662377653.489 [DockingServo](INFO): Changing to mode: 2
2022-09-05T11:34:17.514Z,1662377657.514 [Startup:StartupSatComms:B](INFO): Timed out from 2022-09-05T11:33:17.4Z
2022-09-05T11:34:17.514Z,1662377657.514 [Startup:StartupSatComms:B] Stopped
2022-09-05T11:34:17.514Z,1662377657.514 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2022-09-05T11:34:17.514Z,1662377657.514 [Startup:StartupSatComms] Stopped
2022-09-05T11:34:17.515Z,1662377657.515 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2022-09-05T11:34:17.516Z,1662377657.516 [Startup](INFO): Completed Startup
2022-09-05T11:34:17.516Z,1662377657.516 [MissionManager](INFO): Startup is completed.
2022-09-05T11:34:17.516Z,1662377657.516 [MissionManager](INFO): Uninitializing Mission Startup
2022-09-05T11:34:17.516Z,1662377657.516 [Startup] Stopped
2022-09-05T11:34:17.516Z,1662377657.516 [Startup](DEBUG): Aggregate::uninitialize Startup
2022-09-05T11:34:17.516Z,1662377657.516 [Startup:A.GoToSurface] Stopped
2022-09-05T11:34:17.516Z,1662377657.516 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-09-05T11:34:17.892Z,1662377657.892 [MissionManager](IMPORTANT): Started mission Default
2022-09-05T11:34:17.892Z,1662377657.892 [Default] Running Loop=1
2022-09-05T11:34:17.893Z,1662377657.893 [Default](DEBUG): Aggregate::initialize Default
2022-09-05T11:34:17.893Z,1662377657.893 [Default:B.GoToSurface] Running Loop=1
2022-09-05T11:34:17.893Z,1662377657.893 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-09-05T11:34:17.893Z,1662377657.893 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-09-05T11:34:17.893Z,1662377657.893 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-09-05T11:34:17.894Z,1662377657.894 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-09-05T11:34:17.894Z,1662377657.894 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-09-05T11:34:17.894Z,1662377657.894 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-09-05T11:34:17.894Z,1662377657.894 [Default:A.Wait] Running Loop=1
2022-09-05T11:34:17.895Z,1662377657.895 [Default:A.Wait](DEBUG): Initialize Wait Component.
2022-09-05T11:34:21.118Z,1662377661.118 [NAL9602](INFO): SBD MO Status=1, MOMSN=46012, MT Status=0, MTMSN=0
2022-09-05T11:34:21.176Z,1662377661.176 [NAL9602](INFO): Sent 184 bytes from file Logs/20220904T034549/Express0119.lzma
2022-09-05T11:34:21.176Z,1662377661.176 [NAL9602](INFO): Packets left to send: 2
2022-09-05T11:34:31.237Z,1662377671.237 [Default:A.Wait](INFO): Done Waiting.
2022-09-05T11:34:31.237Z,1662377671.237 [Default:A.Wait] Stopped
2022-09-05T11:34:31.237Z,1662377671.237 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2022-09-05T11:34:31.654Z,1662377671.654 [Default:CheckIn] Running Loop=1
2022-09-05T11:34:31.654Z,1662377671.654 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-05T11:34:31.655Z,1662377671.655 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-05T11:34:32.036Z,1662377672.036 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2022-09-05T11:34:33.568Z,1662377673.568 [CommandExec](IMPORTANT): got command DDM arm
2022-09-05T11:34:33.568Z,1662377673.568 [CommandExec](IMPORTANT): Switching docking moudle to ARM.
2022-09-05T11:34:33.661Z,1662377673.661 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,113442.00,A,4014.02381,N,07040.37604,W,0.175,25.45,050922,,,A*48
2022-09-05T11:34:33.667Z,1662377673.667 [NAL9602](INFO): GPS fix at 20220905T113442: (40.233730, -70.672934)
2022-09-05T11:34:33.701Z,1662377673.701 [Default:CheckIn:Read_GPS] Stopped
2022-09-05T11:34:33.701Z,1662377673.701 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-05T11:34:34.112Z,1662377674.112 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-09-05T11:35:02.686Z,1662377702.686 [NAL9602](INFO): SBD MO Status=2, MOMSN=46013, MT Status=2, MTMSN=0
2022-09-05T11:35:02.686Z,1662377702.686 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-09-05T11:35:21.301Z,1662377721.301 [NAL9602](INFO): SBD MO Status=1, MOMSN=46013, MT Status=0, MTMSN=0
2022-09-05T11:35:21.351Z,1662377721.351 [NAL9602](INFO): Sent 72 bytes from file Logs/20220905T113113/Courier0004.lzma
2022-09-05T11:35:21.352Z,1662377721.352 [NAL9602](INFO): Packets left to send: 0
2022-09-05T11:35:39.010Z,1662377739.010 [NAL9602](INFO): SBD MO Status=1, MOMSN=46014, MT Status=0, MTMSN=0
2022-09-05T11:35:39.059Z,1662377739.059 [NAL9602](INFO): Sent 184 bytes from file Logs/20220904T034549/Express0119.lzma
2022-09-05T11:35:39.059Z,1662377739.059 [NAL9602](INFO): Packets left to send: 1
2022-09-05T11:35:48.598Z,1662377748.598 [NAL9602](INFO): SBD MO Status=1, MOMSN=46015, MT Status=0, MTMSN=0
2022-09-05T11:35:48.647Z,1662377748.647 [NAL9602](INFO): Sent 73 bytes from file Logs/20220904T034549/Express0119.lzma
2022-09-05T11:35:48.647Z,1662377748.647 [NAL9602](INFO): Packets left to send: 0
2022-09-05T11:35:56.230Z,1662377756.230 [NAL9602](INFO): SBD MO Status=1, MOMSN=46016, MT Status=0, MTMSN=0
2022-09-05T11:35:56.282Z,1662377756.282 [NAL9602](INFO): Sent 184 bytes from file Logs/20220905T113113/Express0001.lzma
2022-09-05T11:35:56.282Z,1662377756.282 [NAL9602](INFO): Packets left to send: 5
2022-09-05T11:36:07.619Z,1662377767.619 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for altitude
2022-09-05T11:36:10.430Z,1662377770.430 [NAL9602](INFO): SBD MO Status=1, MOMSN=46017, MT Status=0, MTMSN=0
2022-09-05T11:36:10.491Z,1662377770.491 [NAL9602](INFO): Sent 184 bytes from file Logs/20220905T113113/Express0001.lzma
2022-09-05T11:36:10.492Z,1662377770.492 [NAL9602](INFO): Packets left to send: 4
2022-09-05T11:36:25.378Z,1662377785.378 [NAL9602](INFO): SBD MO Status=1, MOMSN=46018, MT Status=0, MTMSN=0
2022-09-05T11:36:25.431Z,1662377785.431 [NAL9602](INFO): Sent 184 bytes from file Logs/20220905T113113/Express0001.lzma
2022-09-05T11:36:25.432Z,1662377785.432 [NAL9602](INFO): Packets left to send: 3
2022-09-05T11:36:34.607Z,1662377794.607 [RDI_Pathfinder](ERROR): DVL uart error: serial timeout
2022-09-05T11:36:34.607Z,1662377794.607 [RDI_Pathfinder] Communications Fault, FailCount= 1
2022-09-05T11:36:34.607Z,1662377794.607 [RDI_Pathfinder](ERROR): Communications Fault
2022-09-05T11:36:34.654Z,1662377794.654 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2022-09-05T11:36:35.043Z,1662377795.043 [RDI_Pathfinder](INFO): Powering down
2022-09-05T11:36:35.375Z,1662377795.375 [NAL9602](INFO): SBD MO Status=1, MOMSN=46019, MT Status=0, MTMSN=0
2022-09-05T11:36:35.423Z,1662377795.423 [NAL9602](INFO): Sent 184 bytes from file Logs/20220905T113113/Express0001.lzma
2022-09-05T11:36:35.424Z,1662377795.424 [NAL9602](INFO): Packets left to send: 2
2022-09-05T11:36:40.495Z,1662377800.495 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2022-09-05T11:36:40.495Z,1662377800.495 [RDI_Pathfinder] No Fault, FailCount= 1
2022-09-05T11:36:40.554Z,1662377800.554 [RDI_Pathfinder](IMPORTANT): Expecting PD13 message format
2022-09-05T11:36:46.728Z,1662377806.728 [NAL9602](INFO): SBD MO Status=1, MOMSN=46020, MT Status=0, MTMSN=0
2022-09-05T11:36:46.775Z,1662377806.775 [NAL9602](INFO): Sent 184 bytes from file Logs/20220905T113113/Express0001.lzma
2022-09-05T11:36:46.775Z,1662377806.775 [NAL9602](INFO): Packets left to send: 1
2022-09-05T11:36:56.871Z,1662377816.871 [NAL9602](INFO): SBD MO Status=1, MOMSN=46021, MT Status=0, MTMSN=0
2022-09-05T11:36:56.919Z,1662377816.919 [NAL9602](INFO): Sent 147 bytes from file Logs/20220905T113113/Express0001.lzma
2022-09-05T11:36:56.919Z,1662377816.919 [NAL9602](INFO): Packets left to send: 0
2022-09-05T11:37:10.202Z,1662377830.202 [NAL9602](INFO): SBD MO Status=2, MOMSN=46022, MT Status=2, MTMSN=0
2022-09-05T11:37:10.202Z,1662377830.202 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-09-05T11:37:30.705Z,1662377850.705 [NAL9602](INFO): SBD MO Status=1, MOMSN=46022, MT Status=0, MTMSN=0
2022-09-05T11:37:30.767Z,1662377850.767 [NAL9602](INFO): Sent 183 bytes from file Logs/20220905T113113/Express0005.lzma
2022-09-05T11:37:30.767Z,1662377850.767 [NAL9602](INFO): Packets left to send: 0
2022-09-05T11:37:49.711Z,1662377869.711 [NAL9602](INFO): SBD MO Status=2, MOMSN=46023, MT Status=2, MTMSN=0
2022-09-05T11:37:49.711Z,1662377869.711 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-09-05T11:38:06.222Z,1662377886.222 [NAL9602](INFO): SBD MO Status=0, MOMSN=46023, MT Status=0, MTMSN=0
2022-09-05T11:38:06.311Z,1662377886.311 [Default:CheckIn:Read_Iridium] Stopped
2022-09-05T11:38:06.311Z,1662377886.311 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-05T11:38:06.312Z,1662377886.312 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-05T11:38:36.925Z,1662377916.925 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-05T11:38:47.806Z,1662377927.806 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2022-09-05T11:38:47.810Z,1662377927.810 [BPC1](INFO): Received data from all battery sticks.
2022-09-05T11:38:55.991Z,1662377935.991 [RDI_PathfinderUp](ERROR): DVL uart error: serial timeout
2022-09-05T11:38:55.991Z,1662377935.991 [RDI_PathfinderUp] Communications Fault, FailCount= 1
2022-09-05T11:38:55.991Z,1662377935.991 [RDI_PathfinderUp](ERROR): Communications Fault
2022-09-05T11:38:56.014Z,1662377936.014 [CBIT](ERROR): Communications Fault in component: RDI_PathfinderUp
2022-09-05T11:38:56.415Z,1662377936.415 [RDI_PathfinderUp](INFO): Powering down
2022-09-05T11:38:57.145Z,1662377937.145 [CBIT](INFO): Clearing failed state for component RDI_PathfinderUp
2022-09-05T11:38:57.145Z,1662377937.145 [RDI_PathfinderUp] No Fault, FailCount= 1
2022-09-05T11:43:06.841Z,1662378186.841 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-09-05T11:43:06.841Z,1662378186.841 [Default:CheckIn:C.Wait] Stopped
2022-09-05T11:43:06.841Z,1662378186.841 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-05T11:43:06.841Z,1662378186.841 [Default:CheckIn:D] Running Loop=1
2022-09-05T11:43:07.260Z,1662378187.260 [Default:CheckIn:D] Stopped
2022-09-05T11:43:07.260Z,1662378187.260 [Default:CheckIn:E] Running Loop=1
2022-09-05T11:43:07.628Z,1662378187.628 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 8.822786 min 
2022-09-05T11:43:07.628Z,1662378187.628 [Default:CheckIn:E] Stopped
2022-09-05T11:43:07.628Z,1662378187.628 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-09-05T11:43:07.628Z,1662378187.628 [Default:CheckIn] Stopped
2022-09-05T11:43:07.628Z,1662378187.628 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-05T11:43:07.628Z,1662378187.628 [Default:CheckIn](INFO): Running loop #2
2022-09-05T11:43:07.628Z,1662378187.628 [Default:CheckIn] Running Loop=2
2022-09-05T11:43:07.628Z,1662378187.628 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-05T11:43:07.629Z,1662378187.629 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-05T11:43:09.635Z,1662378189.635 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,114318.00,A,4014.05486,N,07040.37882,W,0.467,351.81,050922,,,A*7E
2022-09-05T11:43:09.656Z,1662378189.656 [NAL9602](INFO): GPS fix at 20220905T114318: (40.234248, -70.672980)
2022-09-05T11:43:09.701Z,1662378189.701 [Default:CheckIn:Read_GPS] Stopped
2022-09-05T11:43:09.701Z,1662378189.701 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-05T11:43:33.998Z,1662378213.998 [NAL9602](INFO): SBD MO Status=1, MOMSN=46024, MT Status=0, MTMSN=0
2022-09-05T11:43:34.048Z,1662378214.048 [NAL9602](INFO): Sent 184 bytes from file Logs/20220905T113113/Courier0007.lzma
2022-09-05T11:43:34.048Z,1662378214.048 [NAL9602](INFO): Packets left to send: 1
2022-09-05T11:43:49.699Z,1662378229.699 [NAL9602](INFO): SBD MO Status=2, MOMSN=46025, MT Status=2, MTMSN=0
2022-09-05T11:43:49.699Z,1662378229.699 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-09-05T11:44:07.882Z,1662378247.882 [NAL9602](INFO): SBD MO Status=1, MOMSN=46025, MT Status=0, MTMSN=0
2022-09-05T11:44:07.931Z,1662378247.931 [NAL9602](INFO): Sent 16 bytes from file Logs/20220905T113113/Courier0007.lzma
2022-09-05T11:44:07.931Z,1662378247.931 [NAL9602](INFO): Packets left to send: 0
2022-09-05T11:44:18.374Z,1662378258.374 [NAL9602](INFO): SBD MO Status=1, MOMSN=46026, MT Status=0, MTMSN=0
2022-09-05T11:44:18.423Z,1662378258.423 [NAL9602](INFO): Sent 184 bytes from file Logs/20220905T113113/Express0008.lzma
2022-09-05T11:44:18.423Z,1662378258.423 [NAL9602](INFO): Packets left to send: 0
2022-09-05T11:44:25.720Z,1662378265.720 [NAL9602](INFO): SBD MO Status=0, MOMSN=46027, MT Status=0, MTMSN=0
2022-09-05T11:44:25.809Z,1662378265.809 [Default:CheckIn:Read_Iridium] Stopped
2022-09-05T11:44:25.809Z,1662378265.809 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-05T11:44:25.809Z,1662378265.809 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-05T11:44:56.379Z,1662378296.379 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-05T11:49:26.269Z,1662378566.269 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-09-05T11:49:26.269Z,1662378566.269 [Default:CheckIn:C.Wait] Stopped
2022-09-05T11:49:26.269Z,1662378566.269 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-05T11:49:26.269Z,1662378566.269 [Default:CheckIn:D] Running Loop=1
2022-09-05T11:49:26.673Z,1662378566.673 [Default:CheckIn:D] Stopped
2022-09-05T11:49:26.673Z,1662378566.673 [Default:CheckIn:E] Running Loop=1
2022-09-05T11:49:27.096Z,1662378567.096 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 15.146335 min 
2022-09-05T11:49:27.097Z,1662378567.097 [Default:CheckIn:E] Stopped
2022-09-05T11:49:27.097Z,1662378567.097 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-09-05T11:49:27.097Z,1662378567.097 [Default:CheckIn] Stopped
2022-09-05T11:49:27.097Z,1662378567.097 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-05T11:49:27.097Z,1662378567.097 [Default:CheckIn](INFO): Running loop #3
2022-09-05T11:49:27.097Z,1662378567.097 [Default:CheckIn] Running Loop=3
2022-09-05T11:49:27.097Z,1662378567.097 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-05T11:49:27.097Z,1662378567.097 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-05T11:49:29.083Z,1662378569.083 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,114937.00,A,4014.21609,N,07041.34580,W,11.352,277.66,050922,,,A*4A
2022-09-05T11:49:29.085Z,1662378569.085 [NAL9602](INFO): GPS fix at 20220905T114937: (40.236935, -70.689097)
2022-09-05T11:49:29.131Z,1662378569.131 [Default:CheckIn:Read_GPS] Stopped
2022-09-05T11:49:29.131Z,1662378569.131 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-05T11:49:53.191Z,1662378593.191 [NAL9602](INFO): SBD MO Status=2, MOMSN=46028, MT Status=2, MTMSN=0
2022-09-05T11:49:53.191Z,1662378593.191 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-09-05T11:50:20.148Z,1662378620.148 [NAL9602](INFO): SBD MO Status=1, MOMSN=46028, MT Status=0, MTMSN=0
2022-09-05T11:50:20.200Z,1662378620.200 [NAL9602](INFO): Sent 73 bytes from file Logs/20220905T113113/Courier0010.lzma
2022-09-05T11:50:20.200Z,1662378620.200 [NAL9602](INFO): Packets left to send: 0
2022-09-05T11:50:27.906Z,1662378627.906 [NAL9602](INFO): SBD MO Status=1, MOMSN=46029, MT Status=0, MTMSN=0
2022-09-05T11:50:27.955Z,1662378627.955 [NAL9602](INFO): Sent 131 bytes from file Logs/20220905T113113/Express0011.lzma
2022-09-05T11:50:27.956Z,1662378627.956 [NAL9602](INFO): Packets left to send: 0
2022-09-05T11:50:44.566Z,1662378644.566 [NAL9602](INFO): SBD MO Status=2, MOMSN=46030, MT Status=2, MTMSN=0
2022-09-05T11:50:44.567Z,1662378644.567 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-09-05T11:50:58.388Z,1662378658.388 [CommandExec](IMPORTANT): got command quit
2022-09-05T11:50:59.391Z,1662378659.391 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2022-09-05T11:50:59.391Z,1662378659.391 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-05T11:50:59.392Z,1662378659.392 [CommandExec](INFO): Uninitializing the command executive.
2022-09-05T11:50:59.392Z,1662378659.392 [CommandExec](INFO): Uninitializing the command scheduler.
2022-09-05T11:50:59.392Z,1662378659.392 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-09-05T11:50:59.495Z,1662378659.495 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2022-09-05T11:50:59.495Z,1662378659.495 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2022-09-05T11:50:59.495Z,1662378659.495 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-09-05T11:50:59.496Z,1662378659.496 [NavChartDb](INFO): Join timeout helper Thread ID is 5657
2022-09-05T11:50:59.732Z,1662378659.732 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-05T11:50:59.732Z,1662378659.732 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-09-05T11:50:59.735Z,1662378659.735 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2022-09-05T11:50:59.735Z,1662378659.735 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2022-09-05T11:50:59.736Z,1662378659.736 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 5658
2022-09-05T11:50:59.751Z,1662378659.751 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-05T11:50:59.752Z,1662378659.752 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2022-09-05T11:50:59.755Z,1662378659.755 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2022-09-05T11:50:59.755Z,1662378659.755 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-09-05T11:50:59.756Z,1662378659.756 [CTD_Seabird](INFO): Join timeout helper Thread ID is 5659
2022-09-05T11:51:00.368Z,1662378660.368 [CTD_Seabird](INFO): Powering down
2022-09-05T11:51:00.379Z,1662378660.379 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-05T11:51:00.379Z,1662378660.379 [CTD_Seabird](INFO): Powering down
2022-09-05T11:51:00.391Z,1662378660.391 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-09-05T11:51:00.395Z,1662378660.395 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2022-09-05T11:51:00.395Z,1662378660.395 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-09-05T11:51:00.395Z,1662378660.395 [Radio_Surface](INFO): Join timeout helper Thread ID is 5660
2022-09-05T11:51:00.531Z,1662378660.531 [Radio_Surface](INFO): Powering down
2022-09-05T11:51:00.532Z,1662378660.532 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-05T11:51:00.532Z,1662378660.532 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-09-05T11:51:00.539Z,1662378660.539 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2022-09-05T11:51:00.539Z,1662378660.539 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-09-05T11:51:00.540Z,1662378660.540 [Onboard](INFO): Join timeout helper Thread ID is 5661
2022-09-05T11:51:01.487Z,1662378661.487 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-05T11:51:01.488Z,1662378661.488 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-09-05T11:51:01.508Z,1662378661.508 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2022-09-05T11:51:01.509Z,1662378661.509 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-09-05T11:51:01.509Z,1662378661.509 [DataOverHttps](INFO): Join timeout helper Thread ID is 5662
2022-09-05T11:51:02.095Z,1662378662.095 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=46030, MT Status=1, MTMSN=1741
2022-09-05T11:51:02.363Z,1662378662.363 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-05T11:51:02.364Z,1662378662.364 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-09-05T11:51:02.372Z,1662378662.372 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2022-09-05T11:51:02.372Z,1662378662.372 [logger ThreadHandler](INFO): Thread cancelled.
2022-09-05T11:51:02.372Z,1662378662.372 [logger](INFO): Join timeout helper Thread ID is 5663
2022-09-05T11:51:02.398Z,1662378662.398 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-05T11:51:02.398Z,1662378662.398 [logger ThreadHandler](INFO): Thread cancelled.
2022-09-05T11:51:02.416Z,1662378662.416 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2022-09-05T11:51:02.416Z,1662378662.416 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-09-05T11:51:02.416Z,1662378662.416 [CommandLine](INFO): Join timeout helper Thread ID is 5664
2022-09-05T11:51:02.459Z,1662378662.459 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-05T11:51:02.459Z,1662378662.459 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-09-05T11:51:02.463Z,1662378662.463 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2022-09-05T11:51:02.463Z,1662378662.463 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-09-05T11:51:02.464Z,1662378662.464 [CommandExec](INFO): Join timeout helper Thread ID is 5665
2022-09-05T11:51:02.465Z,1662378662.465 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2022-09-05T11:51:02.465Z,1662378662.465 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-09-05T11:51:02.466Z,1662378662.466 [controlThread](INFO): Join timeout helper Thread ID is 5666
2022-09-05T11:51:02.588Z,1662378662.588 [NAL9602](INFO): Received command: restart logs
2022-09-05T11:51:02.615Z,1662378662.615 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-05T11:51:02.615Z,1662378662.615 [controlThread](DEBUG): Uninitializing ControlThread
2022-09-05T11:51:02.616Z,1662378662.616 [AHRS_M2](INFO): Powering down
2022-09-05T11:51:02.690Z,1662378662.690 [DDM](INFO): Powering down
2022-09-05T11:51:02.764Z,1662378662.764 [Micromodem](INFO): Powering down
2022-09-05T11:51:02.859Z,1662378662.859 [NAL9602](INFO): Powering down
2022-09-05T11:51:02.931Z,1662378662.931 [RDI_Pathfinder](INFO): Powering down
2022-09-05T11:51:03.003Z,1662378663.003 [RDI_PathfinderUp](INFO): Powering down
2022-09-05T11:51:03.004Z,1662378663.004 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2022-09-05T11:51:03.005Z,1662378663.005 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2022-09-05T11:51:03.006Z,1662378663.006 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2022-09-05T11:51:03.007Z,1662378663.007 [MissionManager](INFO): Uninitializing Mission Default
2022-09-05T11:51:03.007Z,1662378663.007 [Default] Stopped
2022-09-05T11:51:03.007Z,1662378663.007 [Default](DEBUG): Aggregate::uninitialize Default
2022-09-05T11:51:03.007Z,1662378663.007 [Default:B.GoToSurface] Stopped
2022-09-05T11:51:03.007Z,1662378663.007 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-09-05T11:51:03.007Z,1662378663.007 [Default:CheckIn] Stopped
2022-09-05T11:51:03.007Z,1662378663.007 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-05T11:51:03.007Z,1662378663.007 [Default:CheckIn:Read_Iridium] Stopped
2022-09-05T11:51:03.010Z,1662378663.010 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2022-09-05T11:51:03.010Z,1662378663.010 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2022-09-05T11:51:03.011Z,1662378663.011 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2022-09-05T11:51:03.011Z,1662378663.011 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2022-09-05T11:51:03.011Z,1662378663.011 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2022-09-05T11:51:03.012Z,1662378663.012 [BuoyancyServo](INFO): Powering down
2022-09-05T11:51:03.023Z,1662378663.023 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2022-09-05T11:51:03.023Z,1662378663.023 [ElevatorServo](INFO): Powering down
2022-09-05T11:51:03.024Z,1662378663.024 [DockingServo](DEBUG): Uninitialize Docking Servo.
2022-09-05T11:51:03.024Z,1662378663.024 [MassServo](DEBUG): Uninitialize Mass Servo.
2022-09-05T11:51:03.025Z,1662378663.025 [MassServo](INFO): Powering down
2022-09-05T11:51:03.025Z,1662378663.025 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-09-05T11:51:03.025Z,1662378663.025 [RudderServo](INFO): Powering down
2022-09-05T11:51:03.026Z,1662378663.026 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2022-09-05T11:51:03.026Z,1662378663.026 [ThrusterHE](INFO): Powering down
2022-09-05T11:51:03.027Z,1662378663.027 [SBIT](DEBUG): Uninitialize SBIT Component.
2022-09-05T11:51:03.028Z,1662378663.028 [IBIT](DEBUG): Uninitialize IBIT Component.
2022-09-05T11:51:03.028Z,1662378663.028 [CBIT](DEBUG): Uninitialize CBIT Component.
2022-09-05T11:51:03.028Z,1662378663.028 [CBIT](DEBUG): Powering off loads.
2022-09-05T11:51:03.039Z,1662378663.039 [CBIT](DEBUG): Disabling WDT.
2022-09-05T11:51:03.051Z,1662378663.051 [CBIT](DEBUG): Opening all GF detection circuits.
2022-09-05T11:51:03.052Z,1662378663.052 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-09-05T11:51:03.067Z,1662378663.067 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-09-05T11:51:03.071Z,1662378663.071 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-09-05T11:51:03.080Z,1662378663.080 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-09-05T11:51:03.172Z,1662378663.172 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2022-09-05T11:51:03.174Z,1662378663.174 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-09-05T11:51:03.234Z,1662378663.234 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-09-05T11:51:03.299Z,1662378663.299 [logger ThreadHandler](INFO): Thread cancelled.