2020-12-10T21:15:18.717Z,1607634918.717 [Supervisor](DEBUG): Initializing supervisor.
2020-12-10T21:15:18.721Z,1607634918.721 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-12-10T21:15:18.722Z,1607634918.722 [SyncHandler](INFO): Protected caller Thread ID is 827
2020-12-10T21:15:18.722Z,1607634918.722 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-12-10T21:15:18.723Z,1607634918.723 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-12-10T21:15:18.723Z,1607634918.723 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 828
2020-12-10T21:15:18.727Z,1607634918.727 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-12-10T21:15:18.746Z,1607634918.746 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-12-10T21:15:18.747Z,1607634918.747 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-12-10T21:15:18.748Z,1607634918.748 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 829
2020-12-10T21:15:18.750Z,1607634918.750 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-12-10T21:15:18.751Z,1607634918.751 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-12-10T21:15:18.751Z,1607634918.751 [logger ThreadHandler](INFO): Protected caller Thread ID is 830
2020-12-10T21:15:18.755Z,1607634918.755 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-12-10T21:15:18.755Z,1607634918.755 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-12-10T21:15:18.759Z,1607634918.759 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-12-10T21:15:19.167Z,1607634919.167 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-12-10T21:15:19.169Z,1607634919.169 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-12-10T21:15:19.249Z,1607634919.249 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-12-10T21:15:19.587Z,1607634919.587 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-12-10T21:15:19.589Z,1607634919.589 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-12-10T21:15:19.690Z,1607634919.690 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-12-10T21:15:19.691Z,1607634919.691 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-12-10T21:15:19.888Z,1607634919.888 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-12-10T21:15:19.890Z,1607634919.890 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-12-10T21:15:20.414Z,1607634920.414 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-12-10T21:15:20.415Z,1607634920.415 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-12-10T21:15:20.656Z,1607634920.656 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-12-10T21:15:20.657Z,1607634920.657 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-12-10T21:15:20.807Z,1607634920.807 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-12-10T21:15:20.807Z,1607634920.807 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-12-10T21:15:21.006Z,1607634921.006 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-12-10T21:15:21.008Z,1607634921.008 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-12-10T21:15:21.106Z,1607634921.106 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-12-10T21:15:21.107Z,1607634921.107 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2020-12-10T21:15:21.330Z,1607634921.330 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2020-12-10T21:15:21.331Z,1607634921.331 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-12-10T21:15:21.655Z,1607634921.655 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-12-10T21:15:21.657Z,1607634921.657 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-12-10T21:15:21.739Z,1607634921.739 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-12-10T21:15:21.866Z,1607634921.866 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-12-10T21:15:21.868Z,1607634921.868 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-12-10T21:15:23.682Z,1607634923.682 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-12-10T21:15:23.684Z,1607634923.684 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-12-10T21:15:24.059Z,1607634924.059 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-12-10T21:15:24.061Z,1607634924.061 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2020-12-10T21:15:24.063Z,1607634924.063 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2020-12-10T21:15:24.268Z,1607634924.268 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2020-12-10T21:15:24.370Z,1607634924.370 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2020-12-10T21:15:24.471Z,1607634924.471 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2020-12-10T21:15:24.730Z,1607634924.730 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-12-10T21:15:24.731Z,1607634924.731 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2020-12-10T21:15:24.818Z,1607634924.818 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2020-12-10T21:15:24.916Z,1607634924.916 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2020-12-10T21:15:25.031Z,1607634925.031 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2020-12-10T21:15:25.117Z,1607634925.117 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Dock.cfg
2020-12-10T21:15:25.204Z,1607634925.204 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2020-12-10T21:15:25.315Z,1607634925.315 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/workSite.cfg
2020-12-10T21:15:25.415Z,1607634925.415 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2020-12-10T21:15:25.609Z,1607634925.609 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2020-12-10T21:15:25.751Z,1607634925.751 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2020-12-10T21:15:25.756Z,1607634925.756 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-12-10T21:15:26.480Z,1607634926.480 [AHRS_M2] Loaded
2020-12-10T21:15:26.480Z,1607634926.480 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2020-12-10T21:15:27.217Z,1607634927.217 [BPC1] Loaded
2020-12-10T21:15:27.218Z,1607634927.218 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-12-10T21:15:27.366Z,1607634927.366 [DataOverHttps] Loaded
2020-12-10T21:15:27.367Z,1607634927.367 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-12-10T21:15:27.368Z,1607634927.368 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407974E0
2020-12-10T21:15:27.368Z,1607634927.368 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 919
2020-12-10T21:15:27.389Z,1607634927.389 [DDM] Loaded
2020-12-10T21:15:27.389Z,1607634927.389 [ComponentRegistry](DEBUG): SyncComponent "DDM" handled in the control thread.
2020-12-10T21:15:27.408Z,1607634927.408 [Depth_Keller] Loaded
2020-12-10T21:15:27.408Z,1607634927.408 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-12-10T21:15:27.412Z,1607634927.412 [DropWeight] Loaded
2020-12-10T21:15:27.412Z,1607634927.412 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2020-12-10T21:15:27.455Z,1607634927.455 [DUSBL_Hydroid] Loaded
2020-12-10T21:15:27.455Z,1607634927.455 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2020-12-10T21:15:27.500Z,1607634927.500 [Micromodem] Loaded
2020-12-10T21:15:27.500Z,1607634927.500 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2020-12-10T21:15:27.557Z,1607634927.557 [NAL9602] Loaded
2020-12-10T21:15:27.557Z,1607634927.557 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-12-10T21:15:27.584Z,1607634927.584 [Onboard] Loaded
2020-12-10T21:15:27.585Z,1607634927.585 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2020-12-10T21:15:27.586Z,1607634927.586 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 407C74E0
2020-12-10T21:15:27.586Z,1607634927.586 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 920
2020-12-10T21:15:27.591Z,1607634927.591 [PowerOnly](INFO): Adding load control power supply at /dev/loadC1
2020-12-10T21:15:27.602Z,1607634927.602 [PowerOnly] Loaded
2020-12-10T21:15:27.602Z,1607634927.602 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2020-12-10T21:15:27.615Z,1607634927.615 [Radio_Surface] Loaded
2020-12-10T21:15:27.615Z,1607634927.615 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-12-10T21:15:27.616Z,1607634927.616 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407F74E0
2020-12-10T21:15:27.617Z,1607634927.617 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 921
2020-12-10T21:15:27.646Z,1607634927.646 [RDI_Pathfinder] Loaded
2020-12-10T21:15:27.646Z,1607634927.646 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2020-12-10T21:15:27.671Z,1607634927.671 [RDI_PathfinderUp] Loaded
2020-12-10T21:15:27.671Z,1607634927.671 [ComponentRegistry](DEBUG): SyncComponent "RDI_PathfinderUp" handled in the control thread.
2020-12-10T21:15:27.672Z,1607634927.672 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-12-10T21:15:27.672Z,1607634927.672 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-12-10T21:15:27.688Z,1607634927.688 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-12-10T21:15:27.690Z,1607634927.690 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-12-10T21:15:27.819Z,1607634927.819 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-12-10T21:15:27.819Z,1607634927.819 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-12-10T21:15:27.832Z,1607634927.832 [NavChart] Loaded
2020-12-10T21:15:27.832Z,1607634927.832 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-12-10T21:15:27.838Z,1607634927.838 [UniversalFixResidualReporter] Loaded
2020-12-10T21:15:27.838Z,1607634927.838 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-12-10T21:15:27.848Z,1607634927.848 [WorkSite] Loaded
2020-12-10T21:15:27.848Z,1607634927.848 [ComponentRegistry](DEBUG): SyncComponent "WorkSite" handled in the control thread.
2020-12-10T21:15:27.849Z,1607634927.849 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-12-10T21:15:27.849Z,1607634927.849 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2020-12-10T21:15:27.959Z,1607634927.959 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2020-12-10T21:15:27.959Z,1607634927.959 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-12-10T21:15:28.098Z,1607634928.098 [BuoyancyServo] Loaded
2020-12-10T21:15:28.098Z,1607634928.098 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-12-10T21:15:28.138Z,1607634928.138 [ElevatorServo] Loaded
2020-12-10T21:15:28.138Z,1607634928.138 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-12-10T21:15:28.198Z,1607634928.198 [MassServo] Loaded
2020-12-10T21:15:28.198Z,1607634928.198 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-12-10T21:15:28.327Z,1607634928.327 [RudderServo] Loaded
2020-12-10T21:15:28.327Z,1607634928.327 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-12-10T21:15:28.397Z,1607634928.397 [ThrusterServo] Loaded
2020-12-10T21:15:28.413Z,1607634928.413 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-12-10T21:15:28.413Z,1607634928.413 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-12-10T21:15:28.414Z,1607634928.414 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-12-10T21:15:29.563Z,1607634929.563 [CTD_Seabird] Loaded
2020-12-10T21:15:29.563Z,1607634929.563 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2020-12-10T21:15:29.564Z,1607634929.564 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409274E0
2020-12-10T21:15:29.565Z,1607634929.565 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 922
2020-12-10T21:15:29.584Z,1607634929.584 [PAR_Licor] Loaded
2020-12-10T21:15:29.584Z,1607634929.584 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2020-12-10T21:15:29.616Z,1607634929.616 [WetLabsSeaOWL_UV_A] Loaded
2020-12-10T21:15:29.617Z,1607634929.617 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2020-12-10T21:15:29.618Z,1607634929.618 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 409574E0
2020-12-10T21:15:29.618Z,1607634929.618 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 923
2020-12-10T21:15:29.619Z,1607634929.619 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-12-10T21:15:29.619Z,1607634929.619 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-12-10T21:15:29.973Z,1607634929.973 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-12-10T21:15:29.974Z,1607634929.974 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-12-10T21:15:30.030Z,1607634930.030 [DepthRateCalculator] Loaded
2020-12-10T21:15:30.031Z,1607634930.031 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-12-10T21:15:30.036Z,1607634930.036 [PitchRateCalculator] Loaded
2020-12-10T21:15:30.036Z,1607634930.036 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-12-10T21:15:30.045Z,1607634930.045 [SpeedCalculator] Loaded
2020-12-10T21:15:30.046Z,1607634930.046 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-12-10T21:15:30.059Z,1607634930.059 [TempGradientCalculator] Loaded
2020-12-10T21:15:30.059Z,1607634930.059 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-12-10T21:15:30.064Z,1607634930.064 [YawRateCalculator] Loaded
2020-12-10T21:15:30.065Z,1607634930.065 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-12-10T21:15:30.086Z,1607634930.086 [ElevatorOffsetCalculator] Loaded
2020-12-10T21:15:30.086Z,1607634930.086 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-12-10T21:15:30.086Z,1607634930.086 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-12-10T21:15:30.087Z,1607634930.087 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-12-10T21:15:30.249Z,1607634930.249 [SBIT](DEBUG): Construct Startup Built In Test.
2020-12-10T21:15:30.261Z,1607634930.261 [SBIT] Loaded
2020-12-10T21:15:30.262Z,1607634930.262 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-12-10T21:15:30.264Z,1607634930.264 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-12-10T21:15:30.278Z,1607634930.278 [IBIT] Loaded
2020-12-10T21:15:30.278Z,1607634930.278 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-12-10T21:15:30.284Z,1607634930.284 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-12-10T21:15:30.386Z,1607634930.386 [CBIT] Loaded
2020-12-10T21:15:30.386Z,1607634930.386 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-12-10T21:15:30.386Z,1607634930.386 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-12-10T21:15:30.387Z,1607634930.387 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-12-10T21:15:30.464Z,1607634930.464 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-12-10T21:15:30.464Z,1607634930.464 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-12-10T21:15:30.590Z,1607634930.590 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-12-10T21:15:30.590Z,1607634930.590 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-12-10T21:15:30.658Z,1607634930.658 [VerticalControl](DEBUG): Construct VerticalControl.
2020-12-10T21:15:30.711Z,1607634930.711 [VerticalControl] Loaded
2020-12-10T21:15:30.712Z,1607634930.712 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-12-10T21:15:30.715Z,1607634930.715 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-12-10T21:15:30.750Z,1607634930.750 [HorizontalControl] Loaded
2020-12-10T21:15:30.750Z,1607634930.750 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-12-10T21:15:30.752Z,1607634930.752 [SpeedControl](DEBUG): Construct SpeedControl.
2020-12-10T21:15:30.754Z,1607634930.754 [SpeedControl] Loaded
2020-12-10T21:15:30.754Z,1607634930.754 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-12-10T21:15:30.757Z,1607634930.757 [LoopControl](DEBUG): Construct LoopControl.
2020-12-10T21:15:30.758Z,1607634930.758 [LoopControl] Loaded
2020-12-10T21:15:30.758Z,1607634930.758 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-12-10T21:15:30.758Z,1607634930.758 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-12-10T21:15:30.759Z,1607634930.759 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-12-10T21:15:30.801Z,1607634930.801 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-12-10T21:15:30.807Z,1607634930.807 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-12-10T21:15:30.809Z,1607634930.809 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-12-10T21:15:30.820Z,1607634930.820 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-12-10T21:15:30.821Z,1607634930.821 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AFF4E0
2020-12-10T21:15:30.821Z,1607634930.821 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 924
2020-12-10T21:15:30.826Z,1607634930.826 [Supervisor](INFO): Main Thread ID is 822
2020-12-10T21:15:30.826Z,1607634930.826 [Supervisor](DEBUG): Running supervisor.
2020-12-10T21:15:30.826Z,1607634930.826 [CommandLine ThreadHandler](INFO): Handler Thread ID is 925
2020-12-10T21:15:30.829Z,1607634930.829 [controlThread ThreadHandler](INFO): Handler Thread ID is 926
2020-12-10T21:15:30.829Z,1607634930.829 [controlThread](DEBUG): Initializing ControlThread
2020-12-10T21:15:30.836Z,1607634930.836 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-12-10T21:15:30.836Z,1607634930.836 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-12-10T21:15:30.837Z,1607634930.837 [WorkSite](DEBUG): Initializing WorkSite component.
2020-12-10T21:15:30.841Z,1607634930.841 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-12-10T21:15:30.842Z,1607634930.842 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-12-10T21:15:30.842Z,1607634930.842 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-12-10T21:15:30.842Z,1607634930.842 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-12-10T21:15:30.843Z,1607634930.843 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-12-10T21:15:30.843Z,1607634930.843 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-12-10T21:15:30.844Z,1607634930.844 [SBIT](INFO): Initialize SBIT Component.
2020-12-10T21:15:30.845Z,1607634930.845 [SBIT](IMPORTANT): git: 2020-12-09_polaris
2020-12-10T21:15:30.845Z,1607634930.845 [SBIT](INFO): git hash: af9a0cd533cadbfdab8ca7c32aa0f39f5c9a4f8c
2020-12-10T21:15:30.845Z,1607634930.845 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-12-10T21:15:30.846Z,1607634930.846 [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
2020-12-10T21:15:30.847Z,1607634930.847 [SBIT](INFO): Beginning SBIT in 21.000000 seconds.
2020-12-10T21:15:30.848Z,1607634930.848 [IBIT](INFO): Initialize IBIT Component.
2020-12-10T21:15:30.849Z,1607634930.849 [CBIT](DEBUG): Initialize CBIT Component.
2020-12-10T21:15:30.850Z,1607634930.850 [logger ThreadHandler](INFO): Handler Thread ID is 927
2020-12-10T21:15:30.861Z,1607634930.861 [CBIT](DEBUG): Initialized mux pins.
2020-12-10T21:15:30.861Z,1607634930.861 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2020-12-10T21:15:30.861Z,1607634930.861 [CBIT](DEBUG): Initializing the watchdog timer.
2020-12-10T21:15:30.869Z,1607634930.869 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 928
2020-12-10T21:15:30.870Z,1607634930.870 [DataOverHttps](DEBUG): dashIP=128.128.181.155 starts with a digit so assuming it is a numeric IP
2020-12-10T21:15:30.881Z,1607634930.881 [Onboard ThreadHandler](INFO): Handler Thread ID is 929
2020-12-10T21:15:30.886Z,1607634930.886 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2020-12-10T21:15:30.886Z,1607634930.886 [CBIT](DEBUG): Initializing heartbeat.
2020-12-10T21:15:30.899Z,1607634930.899 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 930
2020-12-10T21:15:30.917Z,1607634930.917 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 931
2020-12-10T21:15:30.918Z,1607634930.918 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2020-12-10T21:15:30.923Z,1607634930.923 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 933
2020-12-10T21:15:30.923Z,1607634930.923 [WetLabsSeaOWL_UV_A](INFO): Powering down
2020-12-10T21:15:30.934Z,1607634930.934 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 934
2020-12-10T21:15:30.942Z,1607634930.942 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-12-10T21:15:30.942Z,1607634930.942 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-12-10T21:15:30.942Z,1607634930.942 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-12-10T21:15:30.943Z,1607634930.943 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-12-10T21:15:30.943Z,1607634930.943 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-12-10T21:15:30.943Z,1607634930.943 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-12-10T21:15:30.943Z,1607634930.943 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-12-10T21:15:30.943Z,1607634930.943 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-12-10T21:15:30.943Z,1607634930.943 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-12-10T21:15:30.944Z,1607634930.944 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-12-10T21:15:30.944Z,1607634930.944 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-12-10T21:15:30.944Z,1607634930.944 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-12-10T21:15:30.944Z,1607634930.944 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-12-10T21:15:30.944Z,1607634930.944 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-12-10T21:15:30.944Z,1607634930.944 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-12-10T21:15:30.945Z,1607634930.945 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-12-10T21:15:30.957Z,1607634930.957 [CBIT](DEBUG): Deactivating GF circuits.
2020-12-10T21:15:30.957Z,1607634930.957 [CBIT](DEBUG): Deactivating emergency mode.
2020-12-10T21:15:30.993Z,1607634930.993 [CBIT](DEBUG): Backplane powered.
2020-12-10T21:15:30.993Z,1607634930.993 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-12-10T21:15:30.995Z,1607634930.995 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-12-10T21:15:30.996Z,1607634930.996 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-12-10T21:15:30.996Z,1607634930.996 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-12-10T21:15:30.997Z,1607634930.997 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-12-10T21:15:31.036Z,1607634931.036 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-12-10T21:15:31.055Z,1607634931.055 [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>


2020-12-10T21:15:31.056Z,1607634931.056 [MissionManager](INFO): Loading Mission: Missions/underIce/DefaultWithUndock.xml
2020-12-10T21:15:31.202Z,1607634931.202 [MissionManager](INFO): DefineArg DefaultWithUndock.ElapsedSinceDefaultStarted = 0.000000 min
2020-12-10T21:15:31.206Z,1607634931.206 [MissionManager](INFO): DefineArg DefaultWithUndock.DetachTimeout = 30.000000 min
2020-12-10T21:15:31.234Z,1607634931.234 [MissionManager](INFO): DefineArg DefaultWithUndock.TransponderCode = 2 count
2020-12-10T21:15:31.237Z,1607634931.237 [MissionManager](INFO): DefineArg DefaultWithUndock.TrackingUpdatePeriod = 2.500000 s
2020-12-10T21:15:31.269Z,1607634931.269 [MissionManager](INFO): DefineArg DefaultWithUndock.NumberOfPings = 1.000000 count
2020-12-10T21:15:31.272Z,1607634931.272 [MissionManager](INFO): DefineArg DefaultWithUndock.DetachModeDDM = 2.000000 count
2020-12-10T21:15:31.274Z,1607634931.274 [DefaultWithUndock:A.Wait](DEBUG): Construct Wait.
2020-12-10T21:15:31.309Z,1607634931.309 [Radio_Surface](INFO): Powering up
2020-12-10T21:15:31.396Z,1607634931.396 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Construct.
2020-12-10T21:15:31.396Z,1607634931.396 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values.
2020-12-10T21:15:31.460Z,1607634931.460 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-12-10T21:15:31.487Z,1607634931.487 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-12-10T21:15:31.506Z,1607634931.506 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-12-10T21:15:31.512Z,1607634931.512 [DefaultWithUndock:E.Execute](DEBUG): Construct Execute.
2020-12-10T21:15:31.538Z,1607634931.538 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Dock="Tethys/Dock"
         xmlns:Estimation="Tethys/Estimation"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Sensor="Tethys/Sensor"
         xmlns:Units="Tethys/Units"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Dock http://okeanids.mbari.org/tethys/Xml/Dock.xsd
                             Tethys/Estimation http://okeanids.mbari.org/tethys/Xml/Estimation.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Sensor http://okeanids.mbari.org/tethys/Xml/Sensor.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="DefaultWithUndock">

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

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

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

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

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

    <DefineArg Name="DetachModeDDM"><Description>
        DDM DETACH mode enumeration (whiskers retracted, latch open).
    </Description><Units:count/><Value>2</Value></DefineArg>
        
    <Guidance:Wait>
        <Description>
            Wait a moment to see if the scheduler starts a new mission before
            starting to actually run Default.
        </Description>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Units:second/><Value>30</Value></Setting>
    </Guidance:Wait>

    <Aggregate Id="LeaveDock">
        <Sequence/>

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

        <!-- Acoustic tracking directives -->
        <Estimation:TrackAcousticContact>
            <Parallel/>
            <Setting><Estimation:TrackAcousticContact.contactLabelSetting/><Arg Name="TransponderCode"/></Setting>
            <Setting><Estimation:TrackAcousticContact.numberOfSamplesSetting/><Arg Name="NumberOfPings"/></Setting>
            <Setting><Estimation:TrackAcousticContact.updatePeriodSetting/><Arg Name="TrackingUpdatePeriod"/></Setting>
        </Estimation:TrackAcousticContact>

        <!-- Leave the dock -->
        <Dock:Undock>
            <Sequence/>
        </Dock:Undock>

    </Aggregate>


    <Aggregate Id="SurfaceDefault">

        <Sequence/>

        <Aggregate Id="HoldLatchOpen">

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

            <!-- Power the DDM -->
            <ReadData>
                <Sensor:DDM.DDMMode/>
            </ReadData>

            <!-- Hold the DDM in DETACH mode (whiskers retracted, latch open) -->
            <Assign><Parallel/><Sensor:DDM.DDMModeCmd/><Arg Name="DetachModeDDM"/></Assign>

        </Aggregate>

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

        <Aggregate Id="CheckIn">

            <Sequence Repeat="288"/>

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

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

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

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

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

        </Aggregate>

    </Aggregate>

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

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

</Mission>


2020-12-10T21:15:31.549Z,1607634931.549 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,DDM,Depth_Keller,DropWeight,DUSBL_Hydroid,Micromodem,NAL9602,PowerOnly,RDI_Pathfinder,RDI_PathfinderUp,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,WorkSite,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2020-12-10T21:15:31.561Z,1607634931.561 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-12-10T21:15:31.682Z,1607634931.682 [DDM](INFO): Powering up
2020-12-10T21:15:31.682Z,1607634931.682 [DDM](DEBUG): Initializing DDM.
2020-12-10T21:15:31.844Z,1607634931.844 [DUSBL_Hydroid](INFO): Powering up
2020-12-10T21:15:31.844Z,1607634931.844 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2020-12-10T21:15:32.047Z,1607634932.047 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-12-10T21:15:32.053Z,1607634932.053 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-12-10T21:15:32.054Z,1607634932.054 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-12-10T21:15:32.061Z,1607634932.061 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-12-10T21:15:32.062Z,1607634932.062 [MassServo](DEBUG): Initializing EZServoServo.
2020-12-10T21:15:32.069Z,1607634932.069 [MassServo](DEBUG): Initializing MassServo.
2020-12-10T21:15:32.070Z,1607634932.070 [RudderServo](DEBUG): Initializing EZServoServo.
2020-12-10T21:15:32.077Z,1607634932.077 [RudderServo](DEBUG): Initializing RudderServo.
2020-12-10T21:15:32.078Z,1607634932.078 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-12-10T21:15:32.085Z,1607634932.085 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-12-10T21:15:32.087Z,1607634932.087 [CommandLine](FAULT): Scheduling is paused
2020-12-10T21:15:32.088Z,1607634932.088 [CBIT](INFO): Critical error at 20201210T211530
2020-12-10T21:15:32.088Z,1607634932.088 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2020-12-10T21:15:32.159Z,1607634932.159 [Micromodem](INFO): Powering up
2020-12-10T21:15:32.159Z,1607634932.159 [Micromodem](DEBUG): Initializing Micromodem.
2020-12-10T21:15:39.012Z,1607634939.012 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2020-12-10T21:15:39.025591Z,RTC,RTC*55

2020-12-10T21:15:47.457Z,1607634947.457 [DDM](INFO): Dynamic Docking Module:
2020-12-10T21:15:48.295Z,1607634948.295 [Micromodem](ERROR): Nmea resend: $CCCFG,ALL,0*33

2020-12-10T21:15:48.676Z,1607634948.676 [Micromodem](ERROR): Got error from modem: $CAERR,211550,NI  ,12,Unknown command*4E

2020-12-10T21:15:49.883Z,1607634949.883 [DUSBL_Hydroid](INFO): DUSBL Version:O
2020-12-10T21:15:52.396Z,1607634952.396 [SBIT](IMPORTANT): Beginning Startup BIT
2020-12-10T21:15:52.404Z,1607634952.404 [CBIT](IMPORTANT): Beginning ground fault scan
2020-12-10T21:15:57.566Z,1607634957.566 [NAL9602](INFO): Powering up NAL9602
2020-12-10T21:15:59.579Z,1607634959.579 [Micromodem](ERROR): Nmea resend: $CCCFG,ALL,0*33

2020-12-10T21:16:03.378Z,1607634963.378 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.065929
CHAN A1 (24V): 0.087964
CHAN A2 (12V): 0.041612
CHAN A3 (5V): 0.008770
CHAN B0 (3.3V): 0.003650
CHAN B1 (3.15aV): 0.003138
CHAN B2 (3.15bV): 0.003045
CHAN B3 (GND): -0.011563
OPEN: 0.007895
Full Scale Calc: 4.765 mA, -1.589 mA
2020-12-10T21:16:08.467Z,1607634968.467 [NAL9602](INFO): NAL9602 initialized
2020-12-10T21:16:30.289Z,1607634990.289 [NAL9602](INFO): SBD MO Status=2, MOMSN=12243, MT Status=2, MTMSN=0
2020-12-10T21:16:30.289Z,1607634990.289 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-12-10T21:16:36.369Z,1607634996.369 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2020-12-10T21:16:39.182Z,1607634999.182 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2020-12-10T21:16:40.013Z,1607635000.013 [NAL9602](INFO): SBD MO Status=0, MOMSN=12243, MT Status=0, MTMSN=0
2020-12-10T21:16:40.013Z,1607635000.013 [NAL9602](INFO): No messages in MT queue
2020-12-10T21:16:46.493Z,1607635006.493 [SBIT](IMPORTANT): SBIT PASSED
2020-12-10T21:16:46.493Z,1607635006.493 [SBIT](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2020-12-10T21:16:46.890Z,1607635006.890 [WorkSite](IMPORTANT): Reading workSite position from Data/workSite.cfg
2020-12-10T21:16:46.894Z,1607635006.894 [WorkSite](IMPORTANT): WorkSite fix at 20201210T211238: (41.552435, -70.718560)
2020-12-10T21:16:46.895Z,1607635006.895 [MissionManager](IMPORTANT): Started mission Startup
2020-12-10T21:16:46.896Z,1607635006.896 [Startup] Running Loop=1
2020-12-10T21:16:46.896Z,1607635006.896 [Startup](DEBUG): Aggregate::initialize Startup
2020-12-10T21:16:46.896Z,1607635006.896 [Startup:A.GoToSurface] Running Loop=1
2020-12-10T21:16:46.896Z,1607635006.896 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-12-10T21:16:46.897Z,1607635006.897 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-12-10T21:16:46.897Z,1607635006.897 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-12-10T21:16:46.897Z,1607635006.897 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-12-10T21:16:46.898Z,1607635006.898 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-12-10T21:16:46.898Z,1607635006.898 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-12-10T21:16:46.900Z,1607635006.900 [Startup:StartupSatComms] Running Loop=1
2020-12-10T21:16:46.900Z,1607635006.900 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2020-12-10T21:16:46.900Z,1607635006.900 [Startup:StartupSatComms:A] Running Loop=1
2020-12-10T21:16:47.327Z,1607635007.327 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2020-12-10T21:17:26.093Z,1607635046.093 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2020-12-10T21:17:47.096Z,1607635067.096 [Startup:StartupSatComms:A](INFO): Timed out from 2020-12-10T21:16:46.9Z
2020-12-10T21:17:47.096Z,1607635067.096 [Startup:StartupSatComms:A] Stopped
2020-12-10T21:17:47.096Z,1607635067.096 [Startup:StartupSatComms:B] Running Loop=1
2020-12-10T21:17:47.505Z,1607635067.505 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-12-10T21:18:17.294Z,1607635097.294 [NAL9602](INFO): SBD MO Status=1, MOMSN=12244, MT Status=0, MTMSN=0
2020-12-10T21:18:17.341Z,1607635097.341 [NAL9602](INFO): Sent 184 bytes from file Logs/20201210T201528/Courier0028.lzma
2020-12-10T21:18:17.342Z,1607635097.342 [NAL9602](INFO): Packets left to send: 16
2020-12-10T21:18:32.320Z,1607635112.320 [NAL9602](INFO): SBD MO Status=1, MOMSN=12245, MT Status=0, MTMSN=0
2020-12-10T21:18:32.377Z,1607635112.377 [NAL9602](INFO): Sent 184 bytes from file Logs/20201210T201528/Courier0028.lzma
2020-12-10T21:18:32.377Z,1607635112.377 [NAL9602](INFO): Packets left to send: 15
2020-12-10T21:18:40.874Z,1607635120.874 [NAL9602](INFO): SBD MO Status=1, MOMSN=12246, MT Status=0, MTMSN=0
2020-12-10T21:18:40.921Z,1607635120.921 [NAL9602](INFO): Sent 184 bytes from file Logs/20201210T201528/Courier0028.lzma
2020-12-10T21:18:40.921Z,1607635120.921 [NAL9602](INFO): Packets left to send: 14
2020-12-10T21:18:47.452Z,1607635127.452 [Startup:StartupSatComms:B](INFO): Timed out from 2020-12-10T21:17:47.1Z
2020-12-10T21:18:47.452Z,1607635127.452 [Startup:StartupSatComms:B] Stopped
2020-12-10T21:18:47.452Z,1607635127.452 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2020-12-10T21:18:47.452Z,1607635127.452 [Startup:StartupSatComms] Stopped
2020-12-10T21:18:47.452Z,1607635127.452 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2020-12-10T21:18:47.453Z,1607635127.453 [Startup](INFO): Completed Startup
2020-12-10T21:18:47.453Z,1607635127.453 [MissionManager](INFO): Startup is completed.
2020-12-10T21:18:47.453Z,1607635127.453 [MissionManager](INFO): Uninitializing Mission Startup
2020-12-10T21:18:47.453Z,1607635127.453 [Startup] Stopped
2020-12-10T21:18:47.454Z,1607635127.454 [Startup](DEBUG): Aggregate::uninitialize Startup
2020-12-10T21:18:47.454Z,1607635127.454 [Startup:A.GoToSurface] Stopped
2020-12-10T21:18:47.454Z,1607635127.454 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-12-10T21:18:47.831Z,1607635127.831 [MissionManager](IMPORTANT): Started mission DefaultWithUndock
2020-12-10T21:18:47.831Z,1607635127.831 [DefaultWithUndock] Running Loop=1
2020-12-10T21:18:47.831Z,1607635127.831 [DefaultWithUndock](DEBUG): Aggregate::initialize DefaultWithUndock
2020-12-10T21:18:47.831Z,1607635127.831 [DefaultWithUndock:A.Wait] Running Loop=1
2020-12-10T21:18:47.831Z,1607635127.831 [DefaultWithUndock:A.Wait](DEBUG): Initialize Wait Component.
2020-12-10T21:18:50.695Z,1607635130.695 [DataOverHttps](IMPORTANT): SBD MTMSN=20201210T211850
2020-12-10T21:18:50.708Z,1607635130.708 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.012991
2020-12-10T21:18:51.097Z,1607635131.097 [NAL9602](INFO): SBD MO Status=1, MOMSN=12247, MT Status=0, MTMSN=0
2020-12-10T21:18:51.145Z,1607635131.145 [NAL9602](INFO): Sent 184 bytes from file Logs/20201210T201528/Courier0028.lzma
2020-12-10T21:18:51.145Z,1607635131.145 [NAL9602](INFO): Packets left to send: 13
2020-12-10T21:18:55.721Z,1607635135.721 [DataOverHttps](INFO): Received command:stop
2020-12-10T21:18:55.781Z,1607635135.781 [CommandLine](IMPORTANT): got command stop
2020-12-10T21:18:55.782Z,1607635135.782 [CommandLine](IMPORTANT): Scheduling is paused
2020-12-10T21:18:56.722Z,1607635136.722 [DataOverHttps](IMPORTANT): SBD MTMSN=20201210T211856
2020-12-10T21:19:00.745Z,1607635140.745 [DataOverHttps](INFO): Received command:stop
2020-12-10T21:19:00.837Z,1607635140.837 [CommandLine](IMPORTANT): got command stop
2020-12-10T21:19:18.146Z,1607635158.146 [DefaultWithUndock:A.Wait](INFO): Done Waiting.
2020-12-10T21:19:18.146Z,1607635158.146 [DefaultWithUndock:A.Wait] Stopped
2020-12-10T21:19:18.146Z,1607635158.146 [DefaultWithUndock:A.Wait](DEBUG): Uninitialize Wait Component.
2020-12-10T21:19:18.146Z,1607635158.146 [DefaultWithUndock:LeaveDock] Running Loop=1
2020-12-10T21:19:18.146Z,1607635158.146 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::initialize DefaultWithUndock:LeaveDock
2020-12-10T21:19:18.146Z,1607635158.146 [DefaultWithUndock:LeaveDock:A.] Running Loop=1
2020-12-10T21:19:18.146Z,1607635158.146 [DefaultWithUndock:LeaveDock:A.](INFO): Initializing TrackAcousticContact.
2020-12-10T21:19:18.147Z,1607635158.147 [DefaultWithUndock:LeaveDock:B.Undock] Running Loop=1
2020-12-10T21:19:18.147Z,1607635158.147 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initialize.
2020-12-10T21:19:18.147Z,1607635158.147 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values.
2020-12-10T21:19:18.573Z,1607635158.573 [DefaultWithUndock:LeaveDock:A.] Running Loop=1
2020-12-10T21:19:18.925Z,1607635158.925 [PowerOnly](INFO): Powering up loadControl
2020-12-10T21:19:20.987Z,1607635160.987 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-12-10T21:19:21.791Z,1607635161.791 [NAL9602](INFO): Not Powering down - fast GPS
2020-12-10T21:19:23.080Z,1607635163.080 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detaching from dock.
2020-12-10T21:19:23.429Z,1607635163.429 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detected possible detachment. Starting timer.
2020-12-10T21:19:23.831Z,1607635163.831 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-12-10T21:19:25.442Z,1607635165.442 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-12-10T21:19:26.650Z,1607635166.650 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-12-10T21:19:32.347Z,1607635172.347 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-12-10T21:19:35.194Z,1607635175.194 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-12-10T21:19:36.346Z,1607635176.346 [RDI_PathfinderUp](ERROR): only read 2 of 4 data items
2020-12-10T21:19:36.734Z,1607635176.734 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-12-10T21:19:36.887Z,1607635176.887 [DataOverHttps](IMPORTANT): SBD MTMSN=20201210T211936
2020-12-10T21:19:38.155Z,1607635178.155 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-12-10T21:19:40.786Z,1607635180.786 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-12-10T21:19:40.909Z,1607635180.909 [DataOverHttps](INFO): Received command:stop
2020-12-10T21:19:40.945Z,1607635180.945 [CommandLine](IMPORTANT): got command stop
2020-12-10T21:19:42.382Z,1607635182.382 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-12-10T21:19:43.640Z,1607635183.640 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detached at range: 842.82 m. Transitioning DDM to standby.
2020-12-10T21:19:43.640Z,1607635183.640 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-12-10T21:19:46.493Z,1607635186.493 [DefaultWithUndock:LeaveDock:B.Undock](INFO): DDM at standby.
2020-12-10T21:19:46.494Z,1607635186.494 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-12-10T21:19:46.850Z,1607635186.850 [DefaultWithUndock:LeaveDock:B.Undock](IMPORTANT): Undocking sequence complete.
2020-12-10T21:19:46.850Z,1607635186.850 [DefaultWithUndock:LeaveDock:B.Undock] Stopped
2020-12-10T21:19:46.851Z,1607635186.851 [DefaultWithUndock:LeaveDock](INFO): Completed DefaultWithUndock:LeaveDock
2020-12-10T21:19:46.851Z,1607635186.851 [DefaultWithUndock:LeaveDock] Stopped
2020-12-10T21:19:46.851Z,1607635186.851 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::uninitialize DefaultWithUndock:LeaveDock
2020-12-10T21:19:46.851Z,1607635186.851 [DefaultWithUndock:LeaveDock:A.] Stopped
2020-12-10T21:19:46.851Z,1607635186.851 [DefaultWithUndock:SurfaceDefault] Running Loop=1
2020-12-10T21:19:46.851Z,1607635186.851 [DefaultWithUndock:SurfaceDefault](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault
2020-12-10T21:19:46.851Z,1607635186.851 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen] Running Loop=1
2020-12-10T21:19:46.851Z,1607635186.851 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:HoldLatchOpen
2020-12-10T21:19:46.851Z,1607635186.851 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:A] Running Loop=1
2020-12-10T21:19:46.851Z,1607635186.851 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:B] Running Loop=1
2020-12-10T21:19:46.851Z,1607635186.851 [DefaultWithUndock:SurfaceDefault:B.GoToSurface] Running Loop=1
2020-12-10T21:19:46.851Z,1607635186.851 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-12-10T21:19:46.852Z,1607635186.852 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-12-10T21:19:46.852Z,1607635186.852 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-12-10T21:19:46.852Z,1607635186.852 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-12-10T21:19:46.853Z,1607635186.853 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-12-10T21:19:46.853Z,1607635186.853 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-12-10T21:19:47.292Z,1607635187.292 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=1
2020-12-10T21:19:47.292Z,1607635187.292 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-12-10T21:19:47.292Z,1607635187.292 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2020-12-10T21:19:47.293Z,1607635187.293 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen] Stopped
2020-12-10T21:19:47.293Z,1607635187.293 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:HoldLatchOpen
2020-12-10T21:19:47.297Z,1607635187.297 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:A] Stopped
2020-12-10T21:19:47.297Z,1607635187.297 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:B] Stopped
2020-12-10T21:19:47.646Z,1607635187.646 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-12-10T21:19:49.259Z,1607635189.259 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211948.00,A,4133.12886,N,07043.10329,W,1.225,35.47,101220,,,A*43
2020-12-10T21:19:49.262Z,1607635189.262 [NAL9602](INFO): GPS fix at 20201210T211948: (41.552148, -70.718388)
2020-12-10T21:19:49.296Z,1607635189.296 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2020-12-10T21:19:49.296Z,1607635189.296 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2020-12-10T21:19:49.674Z,1607635189.674 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-12-10T21:19:52.972Z,1607635192.972 [DataOverHttps](INFO): Sending 2992 bytes from file Logs/20201210T201528/Courier0028.lzma
2020-12-10T21:19:54.967Z,1607635194.967 [DataOverHttps](INFO): Moved sent file to Logs/20201210T201528/Courier0028.lzma.bak
2020-12-10T21:19:54.967Z,1607635194.967 [DataOverHttps](INFO): SBD MOMSN=60217
2020-12-10T21:19:56.561Z,1607635196.561 [RDI_PathfinderUp](ERROR): DVL uart error: serial timeout
2020-12-10T21:19:56.561Z,1607635196.561 [RDI_PathfinderUp] Communications Fault, FailCount= 1
2020-12-10T21:19:56.561Z,1607635196.561 [RDI_PathfinderUp](ERROR): Communications Fault
2020-12-10T21:19:56.614Z,1607635196.614 [CBIT](ERROR): Communications Fault in component: RDI_PathfinderUp
2020-12-10T21:19:56.913Z,1607635196.913 [RDI_PathfinderUp](INFO): Powering down
2020-12-10T21:19:57.702Z,1607635197.702 [CBIT](INFO): Clearing failed state for component RDI_PathfinderUp
2020-12-10T21:19:57.702Z,1607635197.702 [RDI_PathfinderUp] No Fault, FailCount= 1
2020-12-10T21:20:04.005Z,1607635204.005 [DataOverHttps](INFO): Sending 324 bytes from file Logs/20201210T211518/Courier0000.lzma
2020-12-10T21:20:05.007Z,1607635205.007 [DataOverHttps](INFO): Moved sent file to Logs/20201210T211518/Courier0000.lzma.bak
2020-12-10T21:20:05.007Z,1607635205.007 [DataOverHttps](INFO): SBD MOMSN=61047
2020-12-10T21:20:14.250Z,1607635214.250 [NAL9602](INFO): SBD MO Status=0, MOMSN=12248, MT Status=0, MTMSN=0
2020-12-10T21:20:14.250Z,1607635214.250 [NAL9602](INFO): No messages in MT queue
2020-12-10T21:20:15.049Z,1607635215.049 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20201210T211518/Courier0004.lzma
2020-12-10T21:20:16.051Z,1607635216.051 [DataOverHttps](INFO): Moved sent file to Logs/20201210T211518/Courier0004.lzma.bak
2020-12-10T21:20:16.051Z,1607635216.051 [DataOverHttps](INFO): SBD MOMSN=61052
2020-12-10T21:20:25.098Z,1607635225.098 [DataOverHttps](INFO): Sending 448 bytes from file Logs/20201210T201528/Express0026.lzma
2020-12-10T21:20:26.099Z,1607635226.099 [DataOverHttps](INFO): Moved sent file to Logs/20201210T201528/Express0026.lzma.bak
2020-12-10T21:20:26.099Z,1607635226.099 [DataOverHttps](INFO): SBD MOMSN=61055
2020-12-10T21:20:35.138Z,1607635235.138 [DataOverHttps](INFO): Sending 776 bytes from file Logs/20201210T211518/Express0001.lzma
2020-12-10T21:20:36.139Z,1607635236.139 [DataOverHttps](INFO): Moved sent file to Logs/20201210T211518/Express0001.lzma.bak
2020-12-10T21:20:36.139Z,1607635236.139 [DataOverHttps](INFO): SBD MOMSN=61059
2020-12-10T21:20:45.063Z,1607635245.063 [NAL9602](INFO): Not Powering down - fast GPS
2020-12-10T21:20:45.179Z,1607635245.179 [DataOverHttps](INFO): Sending 390 bytes from file Logs/20201210T211518/Express0005.lzma
2020-12-10T21:20:46.181Z,1607635246.181 [DataOverHttps](INFO): Moved sent file to Logs/20201210T211518/Express0005.lzma.bak
2020-12-10T21:20:46.181Z,1607635246.181 [DataOverHttps](INFO): SBD MOMSN=61074
2020-12-10T21:20:47.379Z,1607635247.379 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2020-12-10T21:20:47.379Z,1607635247.379 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2020-12-10T21:20:47.379Z,1607635247.379 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-12-10T21:20:50.171Z,1607635250.171 [PowerOnly](INFO): Powering down loadControl
2020-12-10T21:21:46.328Z,1607635306.328 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-12-10T21:23:58.458Z,1607635438.458 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2020-12-10T21:23:58.461Z,1607635438.461 [BPC1](INFO): Received data from all battery sticks.
2020-12-10T21:25:35.407Z,1607635535.407 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-12-10T21:25:48.009Z,1607635548.009 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](INFO): Done Waiting.
2020-12-10T21:25:48.017Z,1607635548.017 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Stopped
2020-12-10T21:25:48.017Z,1607635548.017 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-12-10T21:25:48.017Z,1607635548.017 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Running Loop=1
2020-12-10T21:25:48.426Z,1607635548.426 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Stopped
2020-12-10T21:25:48.426Z,1607635548.426 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Running Loop=1
2020-12-10T21:25:48.787Z,1607635548.787 [DefaultWithUndock:SurfaceDefault:CheckIn:E](IMPORTANT): Default mission has been running for 7.009924 min 
2020-12-10T21:25:48.787Z,1607635548.787 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Stopped
2020-12-10T21:25:48.787Z,1607635548.787 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Completed DefaultWithUndock:SurfaceDefault:CheckIn
2020-12-10T21:25:48.787Z,1607635548.787 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped
2020-12-10T21:25:48.787Z,1607635548.787 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-12-10T21:25:48.787Z,1607635548.787 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Running loop #2
2020-12-10T21:25:48.787Z,1607635548.787 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=2
2020-12-10T21:25:48.787Z,1607635548.787 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-12-10T21:25:48.787Z,1607635548.787 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2020-12-10T21:25:50.758Z,1607635550.758 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212550.00,A,4133.10999,N,07043.09846,W,0.972,208.39,101220,,,A*7F
2020-12-10T21:25:50.760Z,1607635550.760 [NAL9602](INFO): GPS fix at 20201210T212550: (41.551833, -70.718308)
2020-12-10T21:25:50.771Z,1607635550.771 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2020-12-10T21:25:50.771Z,1607635550.771 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2020-12-10T21:25:54.461Z,1607635554.461 [DataOverHttps](INFO): Sending 200 bytes from file Logs/20201210T211518/Courier0009.lzma
2020-12-10T21:25:55.463Z,1607635555.463 [DataOverHttps](INFO): Moved sent file to Logs/20201210T211518/Courier0009.lzma.bak
2020-12-10T21:25:55.463Z,1607635555.463 [DataOverHttps](INFO): SBD MOMSN=61086
2020-12-10T21:26:02.879Z,1607635562.879 [NAL9602](INFO): SBD MO Status=0, MOMSN=12249, MT Status=0, MTMSN=0
2020-12-10T21:26:02.879Z,1607635562.879 [NAL9602](INFO): No messages in MT queue
2020-12-10T21:26:04.501Z,1607635564.501 [DataOverHttps](INFO): Sending 167 bytes from file Logs/20201210T211518/Express0008.lzma
2020-12-10T21:26:05.503Z,1607635565.503 [DataOverHttps](INFO): Moved sent file to Logs/20201210T211518/Express0008.lzma.bak
2020-12-10T21:26:05.503Z,1607635565.503 [DataOverHttps](INFO): SBD MOMSN=61089
2020-12-10T21:26:06.934Z,1607635566.934 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2020-12-10T21:26:06.934Z,1607635566.934 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2020-12-10T21:26:06.934Z,1607635566.934 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-12-10T21:26:33.579Z,1607635593.579 [NAL9602](INFO): Not Powering down - fast GPS
2020-12-10T21:27:55.994Z,1607635675.994 [DataOverHttps](IMPORTANT): SBD MTMSN=20201210T212756
2020-12-10T21:28:00.013Z,1607635680.013 [DataOverHttps](INFO): Received command:restart sys
2020-12-10T21:28:00.082Z,1607635680.082 [CommandLine](IMPORTANT): got command restart system
2020-12-10T21:28:02.149Z,1607635682.149 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2020-12-10T21:28:02.150Z,1607635682.150 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-12-10T21:28:02.161Z,1607635682.161 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2020-12-10T21:28:02.161Z,1607635682.161 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-12-10T21:28:02.162Z,1607635682.162 [CommandLine](INFO): Join timeout helper Thread ID is 1009
2020-12-10T21:28:02.162Z,1607635682.162 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2020-12-10T21:28:02.163Z,1607635682.163 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-12-10T21:28:02.163Z,1607635682.163 [NavChartDb](INFO): Join timeout helper Thread ID is 1010
2020-12-10T21:28:02.429Z,1607635682.429 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2020-12-10T21:28:02.430Z,1607635682.430 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-12-10T21:28:02.449Z,1607635682.449 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2020-12-10T21:28:02.449Z,1607635682.449 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2020-12-10T21:28:02.450Z,1607635682.450 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 1011
2020-12-10T21:28:02.617Z,1607635682.617 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2020-12-10T21:28:02.617Z,1607635682.617 [