2022-01-31T18:26:06.102Z,1643653566.102 [Supervisor](DEBUG): Initializing supervisor.
2022-01-31T18:26:06.107Z,1643653566.107 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2022-01-31T18:26:06.107Z,1643653566.107 [SyncHandler](INFO): Protected caller Thread ID is 6128
2022-01-31T18:26:06.107Z,1643653566.107 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2022-01-31T18:26:06.109Z,1643653566.109 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2022-01-31T18:26:06.109Z,1643653566.109 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 6129
2022-01-31T18:26:06.113Z,1643653566.113 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2022-01-31T18:26:06.131Z,1643653566.131 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2022-01-31T18:26:06.132Z,1643653566.132 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2022-01-31T18:26:06.133Z,1643653566.133 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 6130
2022-01-31T18:26:06.137Z,1643653566.137 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2022-01-31T18:26:06.138Z,1643653566.138 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2022-01-31T18:26:06.138Z,1643653566.138 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 6131
2022-01-31T18:26:06.140Z,1643653566.140 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2022-01-31T18:26:06.141Z,1643653566.141 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2022-01-31T18:26:06.141Z,1643653566.141 [logger ThreadHandler](INFO): Protected caller Thread ID is 6132
2022-01-31T18:26:06.145Z,1643653566.145 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2022-01-31T18:26:06.145Z,1643653566.145 [Supervisor](INFO): Looking for Config files in directory: Config/
2022-01-31T18:26:06.147Z,1643653566.147 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2022-01-31T18:26:06.632Z,1643653566.632 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2022-01-31T18:26:06.633Z,1643653566.633 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2022-01-31T18:26:06.713Z,1643653566.713 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2022-01-31T18:26:07.036Z,1643653567.036 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2022-01-31T18:26:07.037Z,1643653567.037 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2022-01-31T18:26:07.145Z,1643653567.145 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2022-01-31T18:26:07.146Z,1643653567.146 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2022-01-31T18:26:07.350Z,1643653567.350 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2022-01-31T18:26:07.350Z,1643653567.350 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2022-01-31T18:26:07.858Z,1643653567.858 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2022-01-31T18:26:07.859Z,1643653567.859 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2022-01-31T18:26:08.124Z,1643653568.124 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2022-01-31T18:26:08.125Z,1643653568.125 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2022-01-31T18:26:08.273Z,1643653568.273 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2022-01-31T18:26:08.274Z,1643653568.274 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2022-01-31T18:26:08.465Z,1643653568.465 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2022-01-31T18:26:08.465Z,1643653568.465 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2022-01-31T18:26:08.564Z,1643653568.564 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2022-01-31T18:26:08.565Z,1643653568.565 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2022-01-31T18:26:08.784Z,1643653568.784 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2022-01-31T18:26:08.785Z,1643653568.785 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2022-01-31T18:26:09.168Z,1643653569.168 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2022-01-31T18:26:09.169Z,1643653569.169 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2022-01-31T18:26:09.251Z,1643653569.251 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2022-01-31T18:26:09.378Z,1643653569.378 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2022-01-31T18:26:09.379Z,1643653569.379 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2022-01-31T18:26:10.067Z,1643653570.067 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2022-01-31T18:26:10.068Z,1643653570.068 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2022-01-31T18:26:10.566Z,1643653570.566 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2022-01-31T18:26:10.568Z,1643653570.568 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-polaris/
2022-01-31T18:26:10.569Z,1643653570.569 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/vehicle.cfg
2022-01-31T18:26:11.790Z,1643653571.790 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Control.cfg
2022-01-31T18:26:12.464Z,1643653572.464 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Estimation.cfg
2022-01-31T18:26:12.563Z,1643653572.563 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/BIT.cfg
2022-01-31T18:26:12.664Z,1643653572.664 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Battery.cfg
2022-01-31T18:26:12.923Z,1643653572.923 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2022-01-31T18:26:12.923Z,1643653572.923 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Simulator.cfg
2022-01-31T18:26:13.010Z,1643653573.010 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Navigation.cfg
2022-01-31T18:26:13.113Z,1643653573.113 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Derivation.cfg
2022-01-31T18:26:13.238Z,1643653573.238 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/logger.cfg
2022-01-31T18:26:13.351Z,1643653573.351 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/secure.cfg
2022-01-31T18:26:13.437Z,1643653573.437 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Dock.cfg
2022-01-31T18:26:13.525Z,1643653573.525 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Servo.cfg
2022-01-31T18:26:13.637Z,1643653573.637 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/workSite.cfg
2022-01-31T18:26:13.737Z,1643653573.737 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Sensor.cfg
2022-01-31T18:26:13.943Z,1643653573.943 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Science.cfg
2022-01-31T18:26:14.105Z,1643653574.105 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2022-01-31T18:26:14.125Z,1643653574.125 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2022-01-31T18:26:14.545Z,1643653574.545 [AHRS_M2] Loaded
2022-01-31T18:26:14.545Z,1643653574.545 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2022-01-31T18:26:14.579Z,1643653574.579 [BackseatComponent] Loaded
2022-01-31T18:26:14.579Z,1643653574.579 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2022-01-31T18:26:14.581Z,1643653574.581 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 407DF4E0
2022-01-31T18:26:14.581Z,1643653574.581 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 6226
2022-01-31T18:26:14.583Z,1643653574.583 [LcmUniversalReporter] Loaded
2022-01-31T18:26:14.584Z,1643653574.584 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2022-01-31T18:26:15.330Z,1643653575.330 [BPC1] Loaded
2022-01-31T18:26:15.330Z,1643653575.330 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2022-01-31T18:26:15.402Z,1643653575.402 [DataOverHttps] Loaded
2022-01-31T18:26:15.403Z,1643653575.403 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2022-01-31T18:26:15.404Z,1643653575.404 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4080F4E0
2022-01-31T18:26:15.404Z,1643653575.404 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 6227
2022-01-31T18:26:15.423Z,1643653575.423 [Depth_Keller] Loaded
2022-01-31T18:26:15.423Z,1643653575.423 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2022-01-31T18:26:15.427Z,1643653575.427 [DropWeight] Loaded
2022-01-31T18:26:15.428Z,1643653575.428 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2022-01-31T18:26:15.485Z,1643653575.485 [NAL9602] Loaded
2022-01-31T18:26:15.485Z,1643653575.485 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2022-01-31T18:26:15.513Z,1643653575.513 [Onboard] Loaded
2022-01-31T18:26:15.513Z,1643653575.513 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2022-01-31T18:26:15.514Z,1643653575.514 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4083F4E0
2022-01-31T18:26:15.515Z,1643653575.515 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 6228
2022-01-31T18:26:15.521Z,1643653575.521 [PowerOnly](INFO): Adding load control power supply at /dev/loadC1
2022-01-31T18:26:15.531Z,1643653575.531 [PowerOnly] Loaded
2022-01-31T18:26:15.531Z,1643653575.531 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2022-01-31T18:26:15.542Z,1643653575.542 [Power24vConverter] Loaded
2022-01-31T18:26:15.542Z,1643653575.542 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2022-01-31T18:26:15.555Z,1643653575.555 [Radio_Surface] Loaded
2022-01-31T18:26:15.555Z,1643653575.555 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2022-01-31T18:26:15.556Z,1643653575.556 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4086F4E0
2022-01-31T18:26:15.557Z,1643653575.557 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 6229
2022-01-31T18:26:15.558Z,1643653575.558 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2022-01-31T18:26:15.558Z,1643653575.558 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2022-01-31T18:26:15.632Z,1643653575.632 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2022-01-31T18:26:15.633Z,1643653575.633 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2022-01-31T18:26:15.988Z,1643653575.988 [DeadReckonUsingMultipleVelocitySources] Loaded
2022-01-31T18:26:15.988Z,1643653575.988 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2022-01-31T18:26:16.025Z,1643653576.025 [LBLNavigation] Loaded
2022-01-31T18:26:16.025Z,1643653576.025 [ComponentRegistry](DEBUG): SyncComponent "LBLNavigation" handled in the control thread.
2022-01-31T18:26:16.065Z,1643653576.065 [NavChart] Loaded
2022-01-31T18:26:16.065Z,1643653576.065 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2022-01-31T18:26:16.070Z,1643653576.070 [UniversalFixResidualReporter] Loaded
2022-01-31T18:26:16.071Z,1643653576.071 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2022-01-31T18:26:16.081Z,1643653576.081 [WorkSite] Loaded
2022-01-31T18:26:16.081Z,1643653576.081 [ComponentRegistry](DEBUG): SyncComponent "WorkSite" handled in the control thread.
2022-01-31T18:26:16.082Z,1643653576.082 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2022-01-31T18:26:16.082Z,1643653576.082 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2022-01-31T18:26:16.343Z,1643653576.343 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2022-01-31T18:26:16.345Z,1643653576.345 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2022-01-31T18:26:16.469Z,1643653576.469 [BuoyancyServo] Loaded
2022-01-31T18:26:16.469Z,1643653576.469 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2022-01-31T18:26:16.490Z,1643653576.490 [ElevatorServo] Loaded
2022-01-31T18:26:16.490Z,1643653576.490 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2022-01-31T18:26:16.510Z,1643653576.510 [MassServo] Loaded
2022-01-31T18:26:16.511Z,1643653576.511 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2022-01-31T18:26:16.530Z,1643653576.530 [RudderServo] Loaded
2022-01-31T18:26:16.530Z,1643653576.530 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2022-01-31T18:26:16.546Z,1643653576.546 [ThrusterHE] Loaded
2022-01-31T18:26:16.547Z,1643653576.547 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2022-01-31T18:26:16.547Z,1643653576.547 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2022-01-31T18:26:16.547Z,1643653576.547 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2022-01-31T18:26:16.659Z,1643653576.659 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2022-01-31T18:26:16.659Z,1643653576.659 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2022-01-31T18:26:16.978Z,1643653576.978 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2022-01-31T18:26:16.979Z,1643653576.979 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2022-01-31T18:26:17.021Z,1643653577.021 [DepthRateCalculator] Loaded
2022-01-31T18:26:17.021Z,1643653577.021 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2022-01-31T18:26:17.026Z,1643653577.026 [PitchRateCalculator] Loaded
2022-01-31T18:26:17.026Z,1643653577.026 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2022-01-31T18:26:17.036Z,1643653577.036 [SpeedCalculator] Loaded
2022-01-31T18:26:17.036Z,1643653577.036 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2022-01-31T18:26:17.049Z,1643653577.049 [TempGradientCalculator] Loaded
2022-01-31T18:26:17.050Z,1643653577.050 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2022-01-31T18:26:17.065Z,1643653577.065 [VerticalHomogeneityIndexCalculator] Loaded
2022-01-31T18:26:17.065Z,1643653577.065 [ComponentRegistry](DEBUG): SyncComponent "VerticalHomogeneityIndexCalculator" handled in the control thread.
2022-01-31T18:26:17.070Z,1643653577.070 [YawRateCalculator] Loaded
2022-01-31T18:26:17.070Z,1643653577.070 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2022-01-31T18:26:17.091Z,1643653577.091 [ElevatorOffsetCalculator] Loaded
2022-01-31T18:26:17.091Z,1643653577.091 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2022-01-31T18:26:17.092Z,1643653577.092 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2022-01-31T18:26:17.092Z,1643653577.092 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2022-01-31T18:26:17.238Z,1643653577.238 [SBIT](DEBUG): Construct Startup Built In Test.
2022-01-31T18:26:17.250Z,1643653577.250 [SBIT] Loaded
2022-01-31T18:26:17.250Z,1643653577.250 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2022-01-31T18:26:17.253Z,1643653577.253 [IBIT](DEBUG): Construct Initiated Built In Test.
2022-01-31T18:26:17.266Z,1643653577.266 [IBIT] Loaded
2022-01-31T18:26:17.266Z,1643653577.266 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2022-01-31T18:26:17.272Z,1643653577.272 [CBIT](DEBUG): Construct Continuous Built In Test.
2022-01-31T18:26:17.374Z,1643653577.374 [CBIT] Loaded
2022-01-31T18:26:17.374Z,1643653577.374 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2022-01-31T18:26:17.374Z,1643653577.374 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2022-01-31T18:26:17.375Z,1643653577.375 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2022-01-31T18:26:17.432Z,1643653577.432 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2022-01-31T18:26:17.433Z,1643653577.433 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2022-01-31T18:26:17.537Z,1643653577.537 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2022-01-31T18:26:17.538Z,1643653577.538 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2022-01-31T18:26:17.590Z,1643653577.590 [VerticalControl](DEBUG): Construct VerticalControl.
2022-01-31T18:26:17.640Z,1643653577.640 [VerticalControl] Loaded
2022-01-31T18:26:17.640Z,1643653577.640 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2022-01-31T18:26:17.643Z,1643653577.643 [HorizontalControl](DEBUG): Construct HorizontalControl.
2022-01-31T18:26:17.679Z,1643653577.679 [HorizontalControl] Loaded
2022-01-31T18:26:17.679Z,1643653577.679 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2022-01-31T18:26:17.682Z,1643653577.682 [SpeedControl](DEBUG): Construct SpeedControl.
2022-01-31T18:26:17.683Z,1643653577.683 [SpeedControl] Loaded
2022-01-31T18:26:17.684Z,1643653577.684 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2022-01-31T18:26:17.686Z,1643653577.686 [LoopControl](DEBUG): Construct LoopControl.
2022-01-31T18:26:17.687Z,1643653577.687 [LoopControl] Loaded
2022-01-31T18:26:17.687Z,1643653577.687 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2022-01-31T18:26:17.687Z,1643653577.687 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2022-01-31T18:26:17.688Z,1643653577.688 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2022-01-31T18:26:17.715Z,1643653577.715 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2022-01-31T18:26:17.721Z,1643653577.721 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2022-01-31T18:26:17.723Z,1643653577.723 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2022-01-31T18:26:17.734Z,1643653577.734 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2022-01-31T18:26:17.735Z,1643653577.735 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B2D4E0
2022-01-31T18:26:17.735Z,1643653577.735 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 6230
2022-01-31T18:26:17.740Z,1643653577.740 [Supervisor](INFO): Main Thread ID is 829
2022-01-31T18:26:17.740Z,1643653577.740 [Supervisor](DEBUG): Running supervisor.
2022-01-31T18:26:17.740Z,1643653577.740 [CommandExec ThreadHandler](INFO): Handler Thread ID is 6231
2022-01-31T18:26:17.741Z,1643653577.741 [CommandExec](INFO): Initializing the command executive.
2022-01-31T18:26:17.742Z,1643653577.742 [CommandLine ThreadHandler](INFO): Handler Thread ID is 6232
2022-01-31T18:26:17.744Z,1643653577.744 [controlThread ThreadHandler](INFO): Handler Thread ID is 6233
2022-01-31T18:26:17.745Z,1643653577.745 [controlThread](DEBUG): Initializing ControlThread
2022-01-31T18:26:17.750Z,1643653577.750 [NavChart](DEBUG): Initialize NavChart Navigation.
2022-01-31T18:26:17.751Z,1643653577.751 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2022-01-31T18:26:17.751Z,1643653577.751 [WorkSite](DEBUG): Initializing WorkSite component.
2022-01-31T18:26:17.753Z,1643653577.753 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2022-01-31T18:26:17.753Z,1643653577.753 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2022-01-31T18:26:17.753Z,1643653577.753 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2022-01-31T18:26:17.753Z,1643653577.753 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2022-01-31T18:26:17.754Z,1643653577.754 [VerticalHomogeneityIndexCalculator](DEBUG): (re)initializing
2022-01-31T18:26:17.755Z,1643653577.755 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2022-01-31T18:26:17.755Z,1643653577.755 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2022-01-31T18:26:17.756Z,1643653577.756 [SBIT](INFO): Initialize SBIT Component.
2022-01-31T18:26:17.756Z,1643653577.756 [SBIT](IMPORTANT): git: 2022-01-19
2022-01-31T18:26:17.756Z,1643653577.756 [SBIT](INFO): git hash: 3c152841e44dce493716324b2ee7dcf988968060
2022-01-31T18:26:17.757Z,1643653577.757 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2022-01-31T18:26:17.758Z,1643653577.758 [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-01-31T18:26:17.759Z,1643653577.759 [SBIT](INFO): Beginning SBIT in 44.000000 seconds.
2022-01-31T18:26:17.759Z,1643653577.759 [IBIT](INFO): Initialize IBIT Component.
2022-01-31T18:26:17.760Z,1643653577.760 [CBIT](DEBUG): Initialize CBIT Component.
2022-01-31T18:26:17.761Z,1643653577.761 [logger ThreadHandler](INFO): Handler Thread ID is 6234
2022-01-31T18:26:17.772Z,1643653577.772 [CBIT](DEBUG): Initialized mux pins.
2022-01-31T18:26:17.772Z,1643653577.772 [CBIT](DEBUG): Initializing the watchdog timer.
2022-01-31T18:26:17.780Z,1643653577.780 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 6235
2022-01-31T18:26:17.793Z,1643653577.793 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 6236
2022-01-31T18:26:17.794Z,1643653577.794 [DataOverHttps](DEBUG): dashIP=128.128.181.226 starts with a digit so assuming it is a numeric IP
2022-01-31T18:26:17.796Z,1643653577.796 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2022-01-31T18:26:17.796Z,1643653577.796 [CBIT](DEBUG): Initializing heartbeat.
2022-01-31T18:26:17.804Z,1643653577.804 [Onboard ThreadHandler](INFO): Handler Thread ID is 6237
2022-01-31T18:26:17.828Z,1643653577.828 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 6238
2022-01-31T18:26:17.845Z,1643653577.845 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 6239
2022-01-31T18:26:17.850Z,1643653577.850 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2022-01-31T18:26:17.850Z,1643653577.850 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2022-01-31T18:26:17.850Z,1643653577.850 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2022-01-31T18:26:17.850Z,1643653577.850 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2022-01-31T18:26:17.851Z,1643653577.851 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2022-01-31T18:26:17.851Z,1643653577.851 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2022-01-31T18:26:17.851Z,1643653577.851 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2022-01-31T18:26:17.851Z,1643653577.851 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2022-01-31T18:26:17.851Z,1643653577.851 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2022-01-31T18:26:17.851Z,1643653577.851 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2022-01-31T18:26:17.852Z,1643653577.852 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2022-01-31T18:26:17.852Z,1643653577.852 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2022-01-31T18:26:17.852Z,1643653577.852 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2022-01-31T18:26:17.852Z,1643653577.852 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2022-01-31T18:26:17.852Z,1643653577.852 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2022-01-31T18:26:17.853Z,1643653577.853 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2022-01-31T18:26:17.868Z,1643653577.868 [CBIT](DEBUG): Deactivating GF circuits.
2022-01-31T18:26:17.868Z,1643653577.868 [CBIT](DEBUG): Deactivating emergency mode.
2022-01-31T18:26:17.904Z,1643653577.904 [CBIT](DEBUG): Backplane powered.
2022-01-31T18:26:17.904Z,1643653577.904 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2022-01-31T18:26:17.906Z,1643653577.906 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2022-01-31T18:26:17.907Z,1643653577.907 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2022-01-31T18:26:17.908Z,1643653577.908 [LoopControl](DEBUG): Initialize LoopControlComponent.
2022-01-31T18:26:17.909Z,1643653577.909 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2022-01-31T18:26:17.927Z,1643653577.927 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2022-01-31T18:26:17.938Z,1643653577.938 [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-01-31T18:26:17.939Z,1643653577.939 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2022-01-31T18:26:18.024Z,1643653578.024 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2022-01-31T18:26:18.026Z,1643653578.026 [Default:A.Wait](DEBUG): Construct Wait.
2022-01-31T18:26:18.028Z,1643653578.028 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2022-01-31T18:26:18.060Z,1643653578.060 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2022-01-31T18:26:18.062Z,1643653578.062 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2022-01-31T18:26:18.084Z,1643653578.084 [Default:E.Execute](DEBUG): Construct Execute.
2022-01-31T18:26:18.112Z,1643653578.112 [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-01-31T18:26:18.117Z,1643653578.117 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,PowerOnly,Power24vConverter,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,WorkSite,LBLNavigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2022-01-31T18:26:18.132Z,1643653578.132 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2022-01-31T18:26:18.232Z,1643653578.232 [Radio_Surface](INFO): Powering up
2022-01-31T18:26:18.295Z,1643653578.295 [Power24vConverter](INFO): Powering up.
2022-01-31T18:26:18.340Z,1643653578.340 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2022-01-31T18:26:18.348Z,1643653578.348 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2022-01-31T18:26:18.349Z,1643653578.349 [ElevatorServo](DEBUG): Initializing EZServoServo.
2022-01-31T18:26:18.356Z,1643653578.356 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2022-01-31T18:26:18.357Z,1643653578.357 [MassServo](DEBUG): Initializing EZServoServo.
2022-01-31T18:26:18.364Z,1643653578.365 [MassServo](DEBUG): Initializing MassServo.
2022-01-31T18:26:18.365Z,1643653578.365 [RudderServo](DEBUG): Initializing EZServoServo.
2022-01-31T18:26:18.372Z,1643653578.372 [RudderServo](DEBUG): Initializing RudderServo.
2022-01-31T18:26:18.373Z,1643653578.373 [ThrusterHE](DEBUG): Initializing EZServoServo.
2022-01-31T18:26:18.380Z,1643653578.380 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2022-01-31T18:26:19.256Z,1643653579.256 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2022-01-31T18:26:19.256Z,1643653579.256 [RudderServo](FAULT): Rudder failed to initialize
2022-01-31T18:26:19.256Z,1643653579.256 [RudderServo] Communications Fault, FailCount= 1
2022-01-31T18:26:19.256Z,1643653579.256 [RudderServo](ERROR): Communications Fault
2022-01-31T18:26:19.260Z,1643653579.260 [CBIT](ERROR): Communications Fault in component: RudderServo
2022-01-31T18:26:19.473Z,1643653579.473 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-01-31T18:26:19.473Z,1643653579.473 [RudderServo](INFO): Powering down
2022-01-31T18:26:20.155Z,1643653580.155 [RudderServo](DEBUG): Initializing EZServoServo.
2022-01-31T18:26:20.277Z,1643653580.277 [RudderServo](DEBUG): Initializing RudderServo.
2022-01-31T18:26:20.281Z,1643653580.281 [CBIT](INFO): Clearing failed state for component RudderServo
2022-01-31T18:26:20.281Z,1643653580.281 [RudderServo] No Fault, FailCount= 1
2022-01-31T18:26:45.597Z,1643653605.597 [NAL9602](INFO): Powering up NAL9602
2022-01-31T18:26:56.514Z,1643653616.514 [NAL9602](INFO): NAL9602 initialized
2022-01-31T18:27:02.179Z,1643653622.179 [SBIT](IMPORTANT): Beginning Startup BIT
2022-01-31T18:27:02.199Z,1643653622.199 [CBIT](IMPORTANT): Beginning ground fault scan
2022-01-31T18:27:13.212Z,1643653633.212 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.057736
CHAN A1 (24V): 0.110278
CHAN A2 (12V): 0.036449
CHAN A3 (5V): 0.009293
CHAN B0 (3.3V): 0.005198
CHAN B1 (3.15aV): 0.004875
CHAN B2 (3.15bV): 0.005221
CHAN B3 (GND): -0.011624
OPEN: 0.006577
Full Scale: +/- 1 mA
2022-01-31T18:27:13.475Z,1643653633.475 [NAL9602](INFO): SBD MO Status=0, MOMSN=35461, MT Status=0, MTMSN=0
2022-01-31T18:27:13.475Z,1643653633.475 [NAL9602](INFO): No messages in MT queue
2022-01-31T18:27:29.236Z,1643653649.236 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182730.00,A,4128.93391,N,07053.08877,W,1.186,0.00,310122,,,A*71
2022-01-31T18:27:29.239Z,1643653649.239 [NAL9602](INFO): GPS fix at 20220131T182730: (41.482232, -70.884813)
2022-01-31T18:27:29.249Z,1643653649.249 [LBLNavigation](INFO): Reset ping filters
2022-01-31T18:27:29.249Z,1643653649.249 [LBLNavigation](INFO): Reset fix filter
2022-01-31T18:27:56.323Z,1643653676.323 [SBIT](IMPORTANT): SBIT PASSED
2022-01-31T18:27:56.324Z,1643653676.324 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2022-01-31T18:27:56.325Z,1643653676.325 [SBIT](IMPORTANT): BuoyancyServo.fastPumpCoefficient=2 none;

2022-01-31T18:27:56.325Z,1643653676.325 [SBIT](IMPORTANT): BuoyancyServo.velocity=800 none;

2022-01-31T18:27:56.325Z,1643653676.325 [SBIT](IMPORTANT): CBIT.gfScanTimeout=2 hour;

2022-01-31T18:27:56.325Z,1643653676.325 [SBIT](IMPORTANT): CTD_Seabird.loadAtStartup=0 bool;

2022-01-31T18:27:56.325Z,1643653676.325 [SBIT](IMPORTANT): DataOverHttps.loadAtStartup=1 bool;

2022-01-31T18:27:56.325Z,1643653676.325 [SBIT](IMPORTANT): Express linearApproximation CTD_Seabird.bin_median_sea_water_salinity 0.050000 practical_salinity_unit;

2022-01-31T18:27:56.325Z,1643653676.325 [SBIT](IMPORTANT): Express linearApproximation CTD_Seabird.bin_median_sea_water_temperature 0.500000 celsius;

2022-01-31T18:27:56.325Z,1643653676.325 [SBIT](IMPORTANT): Express none WetLabsSeaOWL_UV_A.Output700;

2022-01-31T18:27:56.326Z,1643653676.326 [SBIT](IMPORTANT): Express none WetLabsSeaOWL_UV_A.OutputFDOM;

2022-01-31T18:27:56.326Z,1643653676.326 [SBIT](IMPORTANT): Express none WetLabsSeaOWL_UV_A.concentration_of_colored_dissolved_organic_matter_in_sea_water;

2022-01-31T18:27:56.326Z,1643653676.326 [SBIT](IMPORTANT): Express none WetLabsSeaOWL_UV_A.mass_concentration_of_chlorophyll_in_sea_water;

2022-01-31T18:27:56.326Z,1643653676.326 [SBIT](IMPORTANT): Express none WetLabsSeaOWL_UV_A.mass_concentration_of_petroleum_hydrocarbons_in_sea_water;

2022-01-31T18:27:56.326Z,1643653676.326 [SBIT](IMPORTANT): Express none concentration_of_colored_dissolved_organic_matter_in_sea_water;

2022-01-31T18:27:56.326Z,1643653676.326 [SBIT](IMPORTANT): Express none mass_concentration_of_chlorophyll_in_sea_water;

2022-01-31T18:27:56.326Z,1643653676.326 [SBIT](IMPORTANT): Express linearApproximation platform_average_current 0.500000 ampere;

2022-01-31T18:27:56.326Z,1643653676.326 [SBIT](IMPORTANT): Micromodem.loadAtStartup=0 bool;

2022-01-31T18:27:56.326Z,1643653676.326 [SBIT](IMPORTANT): NAL9602.fastGPSFix=1 bool;

2022-01-31T18:27:56.327Z,1643653676.327 [SBIT](IMPORTANT): PAR_Licor.loadAtStartup=0 bool;

2022-01-31T18:27:56.327Z,1643653676.327 [SBIT](IMPORTANT): RDI_Pathfinder.loadAtStartup=0 bool;

2022-01-31T18:27:56.327Z,1643653676.327 [SBIT](IMPORTANT): RDI_PathfinderUp.loadAtStartup=0 bool;

2022-01-31T18:27:56.327Z,1643653676.327 [SBIT](IMPORTANT): Radio_Surface.loadAtStartup=1 bool;

2022-01-31T18:27:56.327Z,1643653676.327 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=154 cubic_centimeter;

2022-01-31T18:27:56.327Z,1643653676.327 [SBIT](IMPORTANT): VerticalControl.massDefault=6 millimeter;

2022-01-31T18:27:56.327Z,1643653676.327 [SBIT](IMPORTANT): WetLabsSeaOWL_UV_A.loadAtStartup=0 bool;

2022-01-31T18:27:56.718Z,1643653676.718 [WorkSite](INFO): Already have valid position. Ignoring workSite position from Data/workSite.cfg
2022-01-31T18:27:56.723Z,1643653676.723 [MissionManager](IMPORTANT): Started mission Startup
2022-01-31T18:27:56.723Z,1643653676.723 [Startup] Running Loop=1
2022-01-31T18:27:56.723Z,1643653676.723 [Startup](DEBUG): Aggregate::initialize Startup
2022-01-31T18:27:56.723Z,1643653676.723 [Startup:A.GoToSurface] Running Loop=1
2022-01-31T18:27:56.723Z,1643653676.723 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-01-31T18:27:56.732Z,1643653676.732 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-01-31T18:27:56.732Z,1643653676.732 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-01-31T18:27:56.733Z,1643653676.733 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-01-31T18:27:56.733Z,1643653676.733 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-01-31T18:27:56.733Z,1643653676.733 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-01-31T18:27:56.735Z,1643653676.735 [Startup:StartupSatComms] Running Loop=1
2022-01-31T18:27:56.735Z,1643653676.735 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2022-01-31T18:27:56.735Z,1643653676.735 [Startup:StartupSatComms:A] Running Loop=1
2022-01-31T18:27:57.129Z,1643653677.129 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2022-01-31T18:27:58.729Z,1643653678.729 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182759.00,A,4128.93394,N,07053.09598,W,0.855,292.21,310122,,,A*7A
2022-01-31T18:27:58.731Z,1643653678.731 [NAL9602](INFO): GPS fix at 20220131T182759: (41.482232, -70.884933)
2022-01-31T18:27:58.742Z,1643653678.742 [Startup:StartupSatComms:A] Stopped
2022-01-31T18:27:58.742Z,1643653678.742 [Startup:StartupSatComms:B] Running Loop=1
2022-01-31T18:27:59.162Z,1643653679.162 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-01-31T18:28:16.994Z,1643653696.994 [NAL9602](INFO): SBD MO Status=1, MOMSN=35462, MT Status=0, MTMSN=0
2022-01-31T18:28:17.044Z,1643653697.044 [NAL9602](INFO): Sent 51 bytes from file Logs/20220131T175324/Courier0025.lzma
2022-01-31T18:28:17.044Z,1643653697.044 [NAL9602](INFO): Packets left to send: 0
2022-01-31T18:28:27.536Z,1643653707.536 [NAL9602](INFO): SBD MO Status=1, MOMSN=35463, MT Status=0, MTMSN=0
2022-01-31T18:28:27.601Z,1643653707.601 [NAL9602](INFO): Sent 51 bytes from file Logs/20220131T175324/Courier0028.lzma
2022-01-31T18:28:27.601Z,1643653707.601 [NAL9602](INFO): Packets left to send: 0
2022-01-31T18:28:36.871Z,1643653716.871 [NAL9602](INFO): SBD MO Status=1, MOMSN=35464, MT Status=0, MTMSN=0
2022-01-31T18:28:36.916Z,1643653716.916 [NAL9602](INFO): Sent 184 bytes from file Logs/20220131T182606/Courier0000.lzma
2022-01-31T18:28:36.916Z,1643653716.916 [NAL9602](INFO): Packets left to send: 1
2022-01-31T18:28:45.005Z,1643653725.005 [NAL9602](INFO): SBD MO Status=1, MOMSN=35465, MT Status=0, MTMSN=0
2022-01-31T18:28:45.060Z,1643653725.060 [NAL9602](INFO): Sent 70 bytes from file Logs/20220131T182606/Courier0000.lzma
2022-01-31T18:28:45.060Z,1643653725.060 [NAL9602](INFO): Packets left to send: 0
2022-01-31T18:28:54.106Z,1643653734.106 [NAL9602](INFO): SBD MO Status=1, MOMSN=35466, MT Status=0, MTMSN=0
2022-01-31T18:28:54.156Z,1643653734.156 [NAL9602](INFO): Sent 184 bytes from file Logs/20220131T175324/Express0020.lzma
2022-01-31T18:28:54.156Z,1643653734.156 [NAL9602](INFO): Packets left to send: 2
2022-01-31T18:28:59.096Z,1643653739.096 [Startup:StartupSatComms:B](INFO): Timed out from 2022-01-31T18:27:58.7Z
2022-01-31T18:28:59.096Z,1643653739.096 [Startup:StartupSatComms:B] Stopped
2022-01-31T18:28:59.096Z,1643653739.096 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2022-01-31T18:28:59.096Z,1643653739.096 [Startup:StartupSatComms] Stopped
2022-01-31T18:28:59.096Z,1643653739.096 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2022-01-31T18:28:59.097Z,1643653739.097 [Startup](INFO): Completed Startup
2022-01-31T18:28:59.097Z,1643653739.097 [MissionManager](INFO): Startup is completed.
2022-01-31T18:28:59.097Z,1643653739.097 [MissionManager](INFO): Uninitializing Mission Startup
2022-01-31T18:28:59.098Z,1643653739.098 [Startup] Stopped
2022-01-31T18:28:59.098Z,1643653739.098 [Startup](DEBUG): Aggregate::uninitialize Startup
2022-01-31T18:28:59.098Z,1643653739.098 [Startup:A.GoToSurface] Stopped
2022-01-31T18:28:59.098Z,1643653739.098 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-01-31T18:28:59.488Z,1643653739.488 [MissionManager](IMPORTANT): Started mission Default
2022-01-31T18:28:59.488Z,1643653739.488 [Default] Running Loop=1
2022-01-31T18:28:59.488Z,1643653739.488 [Default](DEBUG): Aggregate::initialize Default
2022-01-31T18:28:59.488Z,1643653739.488 [Default:B.GoToSurface] Running Loop=1
2022-01-31T18:28:59.488Z,1643653739.488 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-01-31T18:28:59.489Z,1643653739.489 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-01-31T18:28:59.489Z,1643653739.489 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-01-31T18:28:59.489Z,1643653739.489 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-01-31T18:28:59.490Z,1643653739.490 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-01-31T18:28:59.490Z,1643653739.490 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-01-31T18:28:59.490Z,1643653739.490 [Default:A.Wait] Running Loop=1
2022-01-31T18:28:59.490Z,1643653739.490 [Default:A.Wait](DEBUG): Initialize Wait Component.
2022-01-31T18:29:03.133Z,1643653743.133 [NAL9602](INFO): SBD MO Status=1, MOMSN=35467, MT Status=0, MTMSN=0
2022-01-31T18:29:03.180Z,1643653743.180 [NAL9602](INFO): Sent 184 bytes from file Logs/20220131T175324/Express0020.lzma
2022-01-31T18:29:03.180Z,1643653743.180 [NAL9602](INFO): Packets left to send: 1
2022-01-31T18:29:12.822Z,1643653752.822 [Default:A.Wait](INFO): Done Waiting.
2022-01-31T18:29:12.823Z,1643653752.823 [Default:A.Wait] Stopped
2022-01-31T18:29:12.823Z,1643653752.823 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2022-01-31T18:29:13.230Z,1643653753.230 [Default:CheckIn] Running Loop=1
2022-01-31T18:29:13.230Z,1643653753.230 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-01-31T18:29:13.230Z,1643653753.230 [Default:CheckIn:Read_GPS] Running Loop=1
2022-01-31T18:29:13.644Z,1643653753.644 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2022-01-31T18:29:15.253Z,1643653755.253 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182916.00,A,4128.93267,N,07053.11437,W,0.641,264.21,310122,,,A*7D
2022-01-31T18:29:15.255Z,1643653755.255 [NAL9602](INFO): GPS fix at 20220131T182916: (41.482211, -70.885239)
2022-01-31T18:29:15.265Z,1643653755.265 [Default:CheckIn:Read_GPS] Stopped
2022-01-31T18:29:15.265Z,1643653755.265 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-01-31T18:29:15.738Z,1643653755.738 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-01-31T18:29:35.565Z,1643653775.565 [NAL9602](INFO): SBD MO Status=1, MOMSN=35468, MT Status=0, MTMSN=0
2022-01-31T18:29:35.616Z,1643653775.616 [NAL9602](INFO): Sent 72 bytes from file Logs/20220131T182606/Courier0004.lzma
2022-01-31T18:29:35.616Z,1643653775.616 [NAL9602](INFO): Packets left to send: 0
2022-01-31T18:29:43.403Z,1643653783.403 [NAL9602](INFO): SBD MO Status=1, MOMSN=35469, MT Status=0, MTMSN=0
2022-01-31T18:29:43.453Z,1643653783.453 [NAL9602](INFO): Sent 41 bytes from file Logs/20220131T175324/Express0020.lzma
2022-01-31T18:29:43.453Z,1643653783.453 [NAL9602](INFO): Packets left to send: 0
2022-01-31T18:29:52.879Z,1643653792.879 [NAL9602](INFO): SBD MO Status=1, MOMSN=35470, MT Status=0, MTMSN=0
2022-01-31T18:29:52.940Z,1643653792.940 [NAL9602](INFO): Sent 39 bytes from file Logs/20220131T175324/Express0023.lzma
2022-01-31T18:29:52.940Z,1643653792.940 [NAL9602](INFO): Packets left to send: 0
2022-01-31T18:30:02.309Z,1643653802.309 [NAL9602](INFO): SBD MO Status=1, MOMSN=35471, MT Status=0, MTMSN=0
2022-01-31T18:30:02.362Z,1643653802.362 [NAL9602](INFO): Sent 98 bytes from file Logs/20220131T175324/Express0026.lzma
2022-01-31T18:30:02.362Z,1643653802.362 [NAL9602](INFO): Packets left to send: 0
2022-01-31T18:30:27.850Z,1643653827.850 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004593
2022-01-31T18:30:28.722Z,1643653828.722 [NAL9602](INFO): SBD MO Status=2, MOMSN=35472, MT Status=2, MTMSN=0
2022-01-31T18:30:28.723Z,1643653828.723 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-01-31T18:30:31.863Z,1643653831.863 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20220131T175324/Express0029.lzma
2022-01-31T18:30:33.870Z,1643653833.870 [DataOverHttps](INFO): Moved sent file to Logs/20220131T175324/Express0029.lzma.bak
2022-01-31T18:30:33.870Z,1643653833.870 [DataOverHttps](INFO): SBD MOMSN=1375636
2022-01-31T18:30:47.930Z,1643653847.930 [DataOverHttps](INFO): Sending 1150 bytes from file Logs/20220131T182606/Express0001.lzma
2022-01-31T18:30:53.950Z,1643653853.950 [DataOverHttps](INFO): Moved sent file to Logs/20220131T182606/Express0001.lzma.bak
2022-01-31T18:30:53.950Z,1643653853.950 [DataOverHttps](INFO): SBD MOMSN=1375638
2022-01-31T18:30:59.429Z,1643653859.429 [NAL9602](INFO): Not Powering down - fast GPS
2022-01-31T18:31:15.036Z,1643653875.036 [DataOverHttps](INFO): Sending 225 bytes from file Logs/20220131T182606/Express0005.lzma
2022-01-31T18:31:17.042Z,1643653877.042 [DataOverHttps](INFO): Moved sent file to Logs/20220131T182606/Express0005.lzma.bak
2022-01-31T18:31:17.042Z,1643653877.042 [DataOverHttps](INFO): SBD MOMSN=1375674
2022-01-31T18:31:19.237Z,1643653879.237 [Default:CheckIn:Read_Iridium] Stopped
2022-01-31T18:31:19.237Z,1643653879.237 [Default:CheckIn:C.Wait] Running Loop=1
2022-01-31T18:31:19.237Z,1643653879.237 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-01-31T18:33:43.460Z,1643654023.460 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2022-01-31T18:33:43.463Z,1643654023.463 [BPC1](INFO): Received data from all battery sticks.
2022-01-31T18:36:19.021Z,1643654179.021 [Power24vConverter](INFO): Powering down.
2022-01-31T18:36:19.847Z,1643654179.847 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-01-31T18:36:19.847Z,1643654179.847 [Default:CheckIn:C.Wait] Stopped
2022-01-31T18:36:19.847Z,1643654179.847 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-01-31T18:36:19.847Z,1643654179.847 [Default:CheckIn:D] Running Loop=1
2022-01-31T18:36:20.240Z,1643654180.240 [Default:CheckIn:D] Stopped
2022-01-31T18:36:20.240Z,1643654180.240 [Default:CheckIn:E] Running Loop=1
2022-01-31T18:36:20.652Z,1643654180.652 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 7.345860 min 
2022-01-31T18:36:20.652Z,1643654180.652 [Default:CheckIn:E] Stopped
2022-01-31T18:36:20.652Z,1643654180.652 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-01-31T18:36:20.653Z,1643654180.653 [Default:CheckIn] Stopped
2022-01-31T18:36:20.653Z,1643654180.653 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-01-31T18:36:20.653Z,1643654180.653 [Default:CheckIn](INFO): Running loop #2
2022-01-31T18:36:20.653Z,1643654180.653 [Default:CheckIn] Running Loop=2
2022-01-31T18:36:20.653Z,1643654180.653 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-01-31T18:36:20.653Z,1643654180.653 [Default:CheckIn:Read_GPS] Running Loop=1
2022-01-31T18:36:22.665Z,1643654182.665 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183623.00,A,4128.92427,N,07053.20592,W,0.583,268.92,310122,,,A*73
2022-01-31T18:36:22.667Z,1643654182.667 [NAL9602](INFO): GPS fix at 20220131T183623: (41.482071, -70.886765)
2022-01-31T18:36:22.702Z,1643654182.702 [Default:CheckIn:Read_GPS] Stopped
2022-01-31T18:36:22.702Z,1643654182.702 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-01-31T18:36:32.452Z,1643654192.452 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20220131T182606/Courier0007.lzma
2022-01-31T18:36:33.453Z,1643654193.453 [DataOverHttps](INFO): Moved sent file to Logs/20220131T182606/Courier0007.lzma.bak
2022-01-31T18:36:33.454Z,1643654193.454 [DataOverHttps](INFO): SBD MOMSN=1375720
2022-01-31T18:36:36.999Z,1643654196.999 [NAL9602](INFO): SBD MO Status=1, MOMSN=35472, MT Status=0, MTMSN=0
2022-01-31T18:36:36.999Z,1643654196.999 [NAL9602](INFO): No messages in MT queue
2022-01-31T18:36:49.539Z,1643654209.539 [DataOverHttps](INFO): Sending 159 bytes from file Logs/20220131T182606/Express0008.lzma
2022-01-31T18:36:50.542Z,1643654210.542 [DataOverHttps](INFO): Moved sent file to Logs/20220131T182606/Express0008.lzma.bak
2022-01-31T18:36:50.542Z,1643654210.542 [DataOverHttps](INFO): SBD MOMSN=1375723
2022-01-31T18:36:51.961Z,1643654211.961 [Default:CheckIn:Read_Iridium] Stopped
2022-01-31T18:36:51.961Z,1643654211.961 [Default:CheckIn:C.Wait] Running Loop=1
2022-01-31T18:36:51.961Z,1643654211.961 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-01-31T18:37:07.701Z,1643654227.701 [NAL9602](INFO): Not Powering down - fast GPS
2022-01-31T18:37:53.909Z,1643654273.909 [CommandExec](IMPORTANT): got command gfscan
2022-01-31T18:37:54.181Z,1643654274.181 [CBIT](IMPORTANT): Beginning ground fault scan
2022-01-31T18:37:57.066Z,1643654277.066 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2022-01-31T18:38:05.088Z,1643654285.088 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.049135
CHAN A1 (24V) N/A reporting off
CHAN A2 (12V): 0.027184
CHAN A3 (5V): 0.005694
CHAN B0 (3.3V): 0.004583
CHAN B1 (3.15aV): 0.003386
CHAN B2 (3.15bV): 0.003760
CHAN B3 (GND): -0.010480
OPEN: 0.005323
Full Scale: +/- 1 mA
2022-01-31T18:39:29.709Z,1643654369.709 [CommandExec](IMPORTANT): got command gfscan
2022-01-31T18:39:29.977Z,1643654369.977 [CBIT](IMPORTANT): Beginning ground fault scan
2022-01-31T18:39:32.762Z,1643654372.762 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2022-01-31T18:39:40.846Z,1643654380.846 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.312683
CHAN A1 (24V) N/A reporting off
CHAN A2 (12V): 0.027216
CHAN A3 (5V): 0.005070
CHAN B0 (3.3V): 0.003531
CHAN B1 (3.15aV): 0.003474
CHAN B2 (3.15bV): 0.002599
CHAN B3 (GND): -0.009696
OPEN: 0.005630
Full Scale: +/- 1 mA
2022-01-31T18:40:25.485Z,1643654425.485 [CommandExec](IMPORTANT): got command gfscan
2022-01-31T18:40:25.677Z,1643654425.677 [CBIT](IMPORTANT): Beginning ground fault scan
2022-01-31T18:40:28.591Z,1643654428.591 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2022-01-31T18:40:36.631Z,1643654436.631 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.575988
CHAN A1 (24V) N/A reporting off
CHAN A2 (12V): 0.043928
CHAN A3 (5V): 0.004153
CHAN B0 (3.3V): 0.003462
CHAN B1 (3.15aV): 0.002865
CHAN B2 (3.15bV): 0.002446
CHAN B3 (GND): -0.009228
OPEN: 0.005577
Full Scale: +/- 1 mA
2022-01-31T18:41:27.076Z,1643654487.076 [AHRS_M2](FAULT): Failed to acquire valid data within timeout.
2022-01-31T18:41:27.076Z,1643654487.076 [AHRS_M2] Data Fault, FailCount= 1
2022-01-31T18:41:27.076Z,1643654487.076 [AHRS_M2](ERROR): Data Fault
2022-01-31T18:41:27.103Z,1643654487.103 [CBIT](ERROR): Data Fault in component: AHRS_M2
2022-01-31T18:41:27.460Z,1643654487.460 [AHRS_M2](INFO): Powering down
2022-01-31T18:41:28.318Z,1643654488.318 [CBIT](INFO): Clearing failed state for component AHRS_M2
2022-01-31T18:41:28.318Z,1643654488.318 [AHRS_M2] No Fault, FailCount= 1
2022-01-31T18:41:28.672Z,1643654488.672 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2022-01-31T18:41:30.373Z,1643654490.373 [CommandExec](IMPORTANT): got command gfscan
2022-01-31T18:41:30.716Z,1643654490.716 [CBIT](IMPORTANT): Beginning ground fault scan
2022-01-31T18:41:33.576Z,1643654493.576 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2022-01-31T18:41:41.665Z,1643654501.665 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.723129
CHAN A1 (24V) N/A reporting off
CHAN A2 (12V): 0.106184
CHAN A3 (5V): 0.003252
CHAN B0 (3.3V): 0.003054
CHAN B1 (3.15aV): 0.002067
CHAN B2 (3.15bV): 0.002418
CHAN B3 (GND): -0.009121
OPEN: 0.005744
Full Scale: +/- 1 mA
2022-01-31T18:41:52.532Z,1643654512.532 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-01-31T18:41:52.532Z,1643654512.532 [Default:CheckIn:C.Wait] Stopped
2022-01-31T18:41:52.532Z,1643654512.532 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-01-31T18:41:52.532Z,1643654512.532 [Default:CheckIn:D] Running Loop=1
2022-01-31T18:41:52.961Z,1643654512.961 [Default:CheckIn:D] Stopped
2022-01-31T18:41:52.961Z,1643654512.961 [Default:CheckIn:E] Running Loop=1
2022-01-31T18:41:53.363Z,1643654513.363 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.891211 min 
2022-01-31T18:41:53.363Z,1643654513.363 [Default:CheckIn:E] Stopped
2022-01-31T18:41:53.363Z,1643654513.363 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-01-31T18:41:53.363Z,1643654513.363 [Default:CheckIn] Stopped
2022-01-31T18:41:53.363Z,1643654513.363 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-01-31T18:41:53.363Z,1643654513.363 [Default:CheckIn](INFO): Running loop #3
2022-01-31T18:41:53.363Z,1643654513.363 [Default:CheckIn] Running Loop=3
2022-01-31T18:41:53.368Z,1643654513.368 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-01-31T18:41:53.368Z,1643654513.368 [Default:CheckIn:Read_GPS] Running Loop=1
2022-01-31T18:41:55.351Z,1643654515.351 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184157.00,A,4128.91983,N,07053.27074,W,0.486,258.91,310122,,,A*7E
2022-01-31T18:41:55.353Z,1643654515.353 [NAL9602](INFO): GPS fix at 20220131T184157: (41.481997, -70.887846)
2022-01-31T18:41:55.417Z,1643654515.417 [Default:CheckIn:Read_GPS] Stopped
2022-01-31T18:41:55.417Z,1643654515.417 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-01-31T18:42:00.867Z,1643654520.867 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20220131T182606/Courier0010.lzma
2022-01-31T18:42:02.874Z,1643654522.874 [DataOverHttps](INFO): Moved sent file to Logs/20220131T182606/Courier0010.lzma.bak
2022-01-31T18:42:02.874Z,1643654522.874 [DataOverHttps](INFO): SBD MOMSN=1375753
2022-01-31T18:42:07.963Z,1643654527.963 [NAL9602](INFO): SBD MO Status=1, MOMSN=35473, MT Status=0, MTMSN=0
2022-01-31T18:42:07.963Z,1643654527.963 [NAL9602](INFO): No messages in MT queue
2022-01-31T18:42:20.948Z,1643654540.948 [DataOverHttps](INFO): Sending 562 bytes from file Logs/20220131T182606/Express0011.lzma
2022-01-31T18:42:25.966Z,1643654545.966 [DataOverHttps](INFO): Moved sent file to Logs/20220131T182606/Express0011.lzma.bak
2022-01-31T18:42:25.966Z,1643654545.966 [DataOverHttps](INFO): SBD MOMSN=1375756
2022-01-31T18:42:28.172Z,1643654548.172 [Default:CheckIn:Read_Iridium] Stopped
2022-01-31T18:42:28.172Z,1643654548.172 [Default:CheckIn:C.Wait] Running Loop=1
2022-01-31T18:42:28.172Z,1643654548.172 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-01-31T18:42:38.665Z,1643654558.665 [NAL9602](INFO): Not Powering down - fast GPS
2022-01-31T18:43:25.206Z,1643654605.206 [DataOverHttps](IMPORTANT): SBD MTMSN=20220131T184327
2022-01-31T18:43:31.232Z,1643654611.232 [DataOverHttps](INFO): Received command: configSet PAR_Licor.loadAtStartup 1 bool persist;configSet RDI_Pathfinder.loadAtStartup 1 bool persist;configSet WetLabsSeaOWL_UV_A.loadAtStartup 1 bool persist;configSet CTD_Seabird.loadAtStartup 1 bool persist
2022-01-31T18:43:32.184Z,1643654612.184 [CommandExec](IMPORTANT): got command configSet PAR_Licor.loadAtStartup 1.000000 bool persist
2022-01-31T18:43:32.185Z,1643654612.185 [CommandExec](IMPORTANT): configSet PAR_Licor.loadAtStartup requires a restart to take effect.
2022-01-31T18:43:32.187Z,1643654612.187 [CommandExec](IMPORTANT): got command configSet RDI_Pathfinder.loadAtStartup 1.000000 bool persist
2022-01-31T18:43:32.200Z,1643654612.200 [CommandExec](IMPORTANT): configSet RDI_Pathfinder.loadAtStartup requires a restart to take effect.
2022-01-31T18:43:32.202Z,1643654612.202 [CommandExec](IMPORTANT): got command configSet WetLabsSeaOWL_UV_A.loadAtStartup 1.000000 bool persist
2022-01-31T18:43:32.203Z,1643654612.203 [CommandExec](IMPORTANT): configSet WetLabsSeaOWL_UV_A.loadAtStartup requires a restart to take effect.
2022-01-31T18:43:32.250Z,1643654612.250 [CommandExec](IMPORTANT): got command configSet CTD_Seabird.loadAtStartup 1.000000 bool persist
2022-01-31T18:43:32.250Z,1643654612.250 [CommandExec](IMPORTANT): configSet CTD_Seabird.loadAtStartup requires a restart to take effect.
2022-01-31T18:45:57.881Z,1643654757.881 [DataOverHttps](IMPORTANT): SBD MTMSN=20220131T184600
2022-01-31T18:46:03.907Z,1643654763.907 [DataOverHttps](INFO): Received command: configSet Depth_Keller.loadAtStartup 0 bool persist;restart app
2022-01-31T18:46:04.269Z,1643654764.269 [CommandExec](IMPORTANT): got command configSet Depth_Keller.loadAtStartup 0.000000 bool persist
2022-01-31T18:46:04.270Z,1643654764.270 [CommandExec](IMPORTANT): configSet Depth_Keller.loadAtStartup requires a restart to take effect.
2022-01-31T18:46:04.272Z,1643654764.272 [CommandExec](IMPORTANT): got command restart application
2022-01-31T18:46:05.276Z,1643654765.276 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2022-01-31T18:46:05.276Z,1643654765.276 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2022-01-31T18:46:05.276Z,1643654765.276 [CommandExec](INFO): Uninitializing the command executive.
2022-01-31T18:46:05.276Z,1643654765.276 [CommandExec](INFO): Uninitializing the command scheduler.
2022-01-31T18:46:05.277Z,1643654765.277 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-01-31T18:46:05.468Z,1643654765.468 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2022-01-31T18:46:05.468Z,1643654765.468 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2022-01-31T18:46:05.468Z,1643654765.468 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-01-31T18:46:05.469Z,1643654765.469 [NavChartDb](INFO): Join timeout helper Thread ID is 6290
2022-01-31T18:46:05.748Z,1643654765.748 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2022-01-31T18:46:05.748Z,1643654765.748 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-01-31T18:46:05.771Z,1643654765.771 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2022-01-31T18:46:05.771Z,1643654765.771 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-01-31T18:46:05.771Z,1643654765.771 [Radio_Surface](INFO): Join timeout helper Thread ID is 6291
2022-01-31T18:46:06.156Z,1643654766.156 [Radio_Surface](INFO): Powering down
2022-01-31T18:46:06.157Z,1643654766.157 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2022-01-31T18:46:06.157Z,1643654766.157 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-01-31T18:46:06.160Z,1643654766.160 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2022-01-31T18:46:06.160Z,1643654766.160 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-01-31T18:46:06.160Z,1643654766.160 [Onboard](INFO): Join timeout helper Thread ID is 6292
2022-01-31T18:46:06.916Z,1643654766.916 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2022-01-31T18:46:08.880Z,1643654768.880 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2022-01-31T18:46:08.880Z,1643654768.880 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-01-31T18:46:08.888Z,1643654768.888 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2022-01-31T18:46:08.888Z,1643654768.888 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-01-31T18:46:08.888Z,1643654768.888 [DataOverHttps](INFO): Join timeout helper Thread ID is 6293
2022-01-31T18:46:08.932Z,1643654768.932 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2022-01-31T18:46:08.932Z,1643654768.932 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-01-31T18:46:08.950Z,1643654768.950 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2022-01-31T18:46:08.951Z,1643654768.951 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-01-31T18:46:08.951Z,1643654768.951 [BackseatComponent](INFO): Join timeout helper Thread ID is 6294
2022-01-31T18:46:09.012Z,1643654769.012 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2022-01-31T18:46:09.013Z,1643654769.013 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-01-31T18:46:09.021Z,1643654769.021 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2022-01-31T18:46:09.021Z,1643654769.021 [logger ThreadHandler](INFO): Thread cancelled.
2022-01-31T18:46:09.021Z,1643654769.021 [logger](INFO): Join timeout helper Thread ID is 6295
2022-01-31T18:46:09.052Z,1643654769.052 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2022-01-31T18:46:09.052Z,1643654769.052 [logger ThreadHandler](INFO): Thread cancelled.
2022-01-31T18:46:09.060Z,1643654769.060 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2022-01-31T18:46:09.061Z,1643654769.061 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-01-31T18:46:09.061Z,1643654769.061 [CommandLine](INFO): Join timeout helper Thread ID is 6296
2022-01-31T18:46:09.144Z,1643654769.144 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2022-01-31T18:46:09.144Z,1643654769.144 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-01-31T18:46:09.149Z,1643654769.149 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2022-01-31T18:46:09.149Z,1643654769.149 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-01-31T18:46:09.149Z,1643654769.149 [CommandExec](INFO): Join timeout helper Thread ID is 6297
2022-01-31T18:46:09.153Z,1643654769.153 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2022-01-31T18:46:09.153Z,1643654769.153 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-01-31T18:46:09.153Z,1643654769.153 [controlThread](INFO): Join timeout helper Thread ID is 6298
2022-01-31T18:46:09.172Z,1643654769.172 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2022-01-31T18:46:09.172Z,1643654769.172 [controlThread](DEBUG): Uninitializing ControlThread
2022-01-31T18:46:09.172Z,1643654769.172 [AHRS_M2](INFO): Powering down
2022-01-31T18:46:09.245Z,1643654769.245 [NAL9602](INFO): Powering down
2022-01-31T18:46:09.246Z,1643654769.246 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2022-01-31T18:46:09.247Z,1643654769.247 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2022-01-31T18:46:09.248Z,1643654769.248 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2022-01-31T18:46:09.249Z,1643654769.249 [MissionManager](INFO): Uninitializing Mission Default
2022-01-31T18:46:09.249Z,1643654769.249 [Default] Stopped
2022-01-31T18:46:09.249Z,1643654769.249 [Default](DEBUG): Aggregate::uninitialize Default
2022-01-31T18:46:09.249Z,1643654769.249 [Default:B.GoToSurface] Stopped
2022-01-31T18:46:09.249Z,1643654769.249 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-01-31T18:46:09.249Z,1643654769.249 [Default:CheckIn] Stopped
2022-01-31T18:46:09.249Z,1643654769.249 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-01-31T18:46:09.249Z,1643654769.249 [Default:CheckIn:C.Wait] Stopped
2022-01-31T18:46:09.249Z,1643654769.249 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-01-31T18:46:09.252Z,1643654769.252 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2022-01-31T18:46:09.252Z,1643654769.252 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2022-01-31T18:46:09.253Z,1643654769.253 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2022-01-31T18:46:09.253Z,1643654769.253 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2022-01-31T18:46:09.253Z,1643654769.253 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2022-01-31T18:46:09.253Z,1643654769.253 [BuoyancyServo](INFO): Powering down
2022-01-31T18:46:09.268Z,1643654769.268 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2022-01-31T18:46:09.268Z,1643654769.268 [ElevatorServo](INFO): Powering down
2022-01-31T18:46:09.269Z,1643654769.269 [MassServo](DEBUG): Uninitialize Mass Servo.
2022-01-31T18:46:09.269Z,1643654769.269 [MassServo](INFO): Powering down
2022-01-31T18:46:09.270Z,1643654769.270 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-01-31T18:46:09.270Z,1643654769.270 [RudderServo](INFO): Powering down
2022-01-31T18:46:09.270Z,1643654769.270 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2022-01-31T18:46:09.271Z,1643654769.271 [ThrusterHE](INFO): Powering down
2022-01-31T18:46:09.271Z,1643654769.271 [SBIT](DEBUG): Uninitialize SBIT Component.
2022-01-31T18:46:09.272Z,1643654769.272 [IBIT](DEBUG): Uninitialize IBIT Component.
2022-01-31T18:46:09.272Z,1643654769.272 [CBIT](DEBUG): Uninitialize CBIT Component.
2022-01-31T18:46:09.272Z,1643654769.272 [CBIT](DEBUG): Powering off loads.
2022-01-31T18:46:09.284Z,1643654769.284 [CBIT](DEBUG): Disabling WDT.
2022-01-31T18:46:09.296Z,1643654769.296 [CBIT](DEBUG): Opening all GF detection circuits.
2022-01-31T18:46:09.296Z,1643654769.296 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-01-31T18:46:09.313Z,1643654769.313 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-01-31T18:46:09.317Z,1643654769.317 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-01-31T18:46:09.323Z,1643654769.323 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-01-31T18:46:09.366Z,1643654769.366 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-01-31T18:46:09.468Z,1643654769.468 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-01-31T18:46:09.541Z,1643654769.541 [logger ThreadHandler](INFO): Thread cancelled.