2020-09-10T18:26:09.935Z,1599762369.935 [Supervisor](DEBUG): Initializing supervisor.
2020-09-10T18:26:09.938Z,1599762369.938 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-09-10T18:26:09.938Z,1599762369.938 [SyncHandler](INFO): Protected caller Thread ID is 826
2020-09-10T18:26:09.938Z,1599762369.938 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-09-10T18:26:09.939Z,1599762369.939 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-09-10T18:26:09.940Z,1599762369.940 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 827
2020-09-10T18:26:09.942Z,1599762369.942 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-09-10T18:26:09.956Z,1599762369.956 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-09-10T18:26:09.956Z,1599762369.956 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-09-10T18:26:09.957Z,1599762369.957 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 828
2020-09-10T18:26:09.957Z,1599762369.957 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-09-10T18:26:09.958Z,1599762369.958 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-09-10T18:26:09.959Z,1599762369.959 [logger ThreadHandler](INFO): Protected caller Thread ID is 829
2020-09-10T18:26:09.961Z,1599762369.961 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-09-10T18:26:09.961Z,1599762369.961 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-09-10T18:26:09.965Z,1599762369.965 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-09-10T18:26:10.060Z,1599762370.060 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-09-10T18:26:10.062Z,1599762370.062 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-09-10T18:26:10.663Z,1599762370.663 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-09-10T18:26:10.664Z,1599762370.664 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2020-09-10T18:26:10.858Z,1599762370.858 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2020-09-10T18:26:10.860Z,1599762370.860 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-09-10T18:26:10.959Z,1599762370.959 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2020-09-10T18:26:10.961Z,1599762370.961 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-09-10T18:26:11.062Z,1599762371.062 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-09-10T18:26:11.064Z,1599762371.064 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-09-10T18:26:11.145Z,1599762371.145 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-09-10T18:26:11.282Z,1599762371.282 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-09-10T18:26:11.283Z,1599762371.283 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-09-10T18:26:11.587Z,1599762371.587 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-09-10T18:26:11.589Z,1599762371.589 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-09-10T18:26:12.042Z,1599762372.042 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-09-10T18:26:12.043Z,1599762372.043 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-09-10T18:26:12.186Z,1599762372.186 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-09-10T18:26:12.188Z,1599762372.188 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-09-10T18:26:12.384Z,1599762372.384 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-09-10T18:26:12.384Z,1599762372.384 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-09-10T18:26:12.853Z,1599762372.853 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-09-10T18:26:12.855Z,1599762372.855 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-09-10T18:26:13.070Z,1599762373.070 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-09-10T18:26:13.072Z,1599762373.072 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-09-10T18:26:13.275Z,1599762373.275 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-09-10T18:26:13.277Z,1599762373.277 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-09-10T18:26:14.111Z,1599762374.111 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-09-10T18:26:14.114Z,1599762374.114 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-09-10T18:26:14.448Z,1599762374.448 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-09-10T18:26:14.450Z,1599762374.450 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/
2020-09-10T18:26:14.453Z,1599762374.453 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg
2020-09-10T18:26:14.536Z,1599762374.536 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg
2020-09-10T18:26:14.696Z,1599762374.696 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg
2020-09-10T18:26:14.805Z,1599762374.805 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg
2020-09-10T18:26:14.890Z,1599762374.890 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg
2020-09-10T18:26:14.984Z,1599762374.984 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg
2020-09-10T18:26:15.187Z,1599762375.187 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg
2020-09-10T18:26:15.589Z,1599762375.589 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-09-10T18:26:15.591Z,1599762375.591 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg
2020-09-10T18:26:15.687Z,1599762375.687 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg
2020-09-10T18:26:15.785Z,1599762375.785 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg
2020-09-10T18:26:15.917Z,1599762375.917 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg
2020-09-10T18:26:16.017Z,1599762376.017 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/root/
2020-09-10T18:26:16.018Z,1599762376.018 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2020-09-10T18:26:16.021Z,1599762376.021 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2020-09-10T18:26:16.115Z,1599762376.115 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2020-09-10T18:26:16.117Z,1599762376.117 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-09-10T18:26:16.180Z,1599762376.180 [VerticalControl](DEBUG): Construct VerticalControl.
2020-09-10T18:26:16.288Z,1599762376.288 [VerticalControl] Loaded
2020-09-10T18:26:16.288Z,1599762376.288 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-09-10T18:26:16.289Z,1599762376.289 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-09-10T18:26:16.366Z,1599762376.366 [HorizontalControl] Loaded
2020-09-10T18:26:16.366Z,1599762376.366 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-09-10T18:26:16.367Z,1599762376.367 [SpeedControl](DEBUG): Construct SpeedControl.
2020-09-10T18:26:16.372Z,1599762376.372 [SpeedControl] Loaded
2020-09-10T18:26:16.372Z,1599762376.372 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-09-10T18:26:16.373Z,1599762376.373 [LoopControl](DEBUG): Construct LoopControl.
2020-09-10T18:26:16.373Z,1599762376.373 [LoopControl] Loaded
2020-09-10T18:26:16.374Z,1599762376.374 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-09-10T18:26:16.374Z,1599762376.374 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-09-10T18:26:16.374Z,1599762376.374 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-09-10T18:26:16.429Z,1599762376.429 [DepthRateCalculator] Loaded
2020-09-10T18:26:16.429Z,1599762376.429 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-09-10T18:26:16.434Z,1599762376.434 [PitchRateCalculator] Loaded
2020-09-10T18:26:16.434Z,1599762376.434 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-09-10T18:26:16.449Z,1599762376.449 [SpeedCalculator] Loaded
2020-09-10T18:26:16.449Z,1599762376.449 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-09-10T18:26:16.469Z,1599762376.469 [TempGradientCalculator] Loaded
2020-09-10T18:26:16.470Z,1599762376.470 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-09-10T18:26:16.474Z,1599762376.474 [YawRateCalculator] Loaded
2020-09-10T18:26:16.475Z,1599762376.475 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-09-10T18:26:16.503Z,1599762376.503 [ElevatorOffsetCalculator] Loaded
2020-09-10T18:26:16.503Z,1599762376.503 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-09-10T18:26:16.503Z,1599762376.503 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-09-10T18:26:16.505Z,1599762376.505 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-09-10T18:26:16.546Z,1599762376.546 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-09-10T18:26:16.546Z,1599762376.546 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-09-10T18:26:16.673Z,1599762376.673 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-09-10T18:26:16.674Z,1599762376.674 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-09-10T18:26:16.000Z,1599762377.000 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-09-10T18:26:17.001Z,1599762377.001 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-09-10T18:26:17.123Z,1599762377.123 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-09-10T18:26:17.125Z,1599762377.125 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-09-10T18:26:17.685Z,1599762377.685 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2020-09-10T18:26:17.690Z,1599762377.690 [AHRS_M2](INFO): created writer for : platform_orientation
2020-09-10T18:26:17.692Z,1599762377.692 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2020-09-10T18:26:17.697Z,1599762377.697 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2020-09-10T18:26:17.697Z,1599762377.697 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2020-09-10T18:26:17.702Z,1599762377.702 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2020-09-10T18:26:17.703Z,1599762377.703 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2020-09-10T18:26:17.708Z,1599762377.708 [AHRS_M2](INFO): created writer for : platform_roll_angle
2020-09-10T18:26:17.883Z,1599762377.883 [AHRS_M2] Loaded
2020-09-10T18:26:17.883Z,1599762377.883 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2020-09-10T18:26:18.027Z,1599762378.027 [DataOverHttps] Loaded
2020-09-10T18:26:18.027Z,1599762378.027 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-09-10T18:26:18.028Z,1599762378.028 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4090D4E0
2020-09-10T18:26:18.029Z,1599762378.029 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 912
2020-09-10T18:26:18.058Z,1599762378.058 [Depth_Keller] Loaded
2020-09-10T18:26:18.058Z,1599762378.058 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-09-10T18:26:18.063Z,1599762378.063 [DropWeight] Loaded
2020-09-10T18:26:18.063Z,1599762378.063 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2020-09-10T18:26:18.173Z,1599762378.173 [NAL9602] Loaded
2020-09-10T18:26:18.173Z,1599762378.173 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-09-10T18:26:18.220Z,1599762378.220 [Onboard] Loaded
2020-09-10T18:26:18.221Z,1599762378.221 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2020-09-10T18:26:18.222Z,1599762378.222 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4093D4E0
2020-09-10T18:26:18.222Z,1599762378.222 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 913
2020-09-10T18:26:18.241Z,1599762378.241 [Radio_Surface] Loaded
2020-09-10T18:26:18.241Z,1599762378.241 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-09-10T18:26:18.242Z,1599762378.242 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4096D4E0
2020-09-10T18:26:18.242Z,1599762378.242 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 914
2020-09-10T18:26:18.300Z,1599762378.300 [RDI_Pathfinder] Loaded
2020-09-10T18:26:18.300Z,1599762378.300 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2020-09-10T18:26:18.446Z,1599762378.446 [DAT] Loaded
2020-09-10T18:26:18.446Z,1599762378.446 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2020-09-10T18:26:20.365Z,1599762380.365 [BPC1] Loaded
2020-09-10T18:26:20.366Z,1599762380.366 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-09-10T18:26:20.397Z,1599762380.397 [AMEcho] Loaded
2020-09-10T18:26:20.397Z,1599762380.397 [ComponentRegistry](DEBUG): SyncComponent "AMEcho" handled in the control thread.
2020-09-10T18:26:20.397Z,1599762380.397 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-09-10T18:26:20.398Z,1599762380.398 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-09-10T18:26:20.529Z,1599762380.529 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-09-10T18:26:20.530Z,1599762380.530 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-09-10T18:26:20.549Z,1599762380.549 [NavChart] Loaded
2020-09-10T18:26:20.549Z,1599762380.549 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-09-10T18:26:20.553Z,1599762380.553 [UniversalFixResidualReporter] Loaded
2020-09-10T18:26:20.554Z,1599762380.554 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-09-10T18:26:20.554Z,1599762380.554 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-09-10T18:26:20.555Z,1599762380.555 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-09-10T18:26:20.711Z,1599762380.711 [SBIT](DEBUG): Construct Startup Built In Test.
2020-09-10T18:26:20.722Z,1599762380.722 [SBIT] Loaded
2020-09-10T18:26:20.722Z,1599762380.722 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-09-10T18:26:20.723Z,1599762380.723 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-09-10T18:26:20.735Z,1599762380.735 [IBIT] Loaded
2020-09-10T18:26:20.736Z,1599762380.736 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-09-10T18:26:20.739Z,1599762380.739 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-09-10T18:26:20.874Z,1599762380.874 [CBIT] Loaded
2020-09-10T18:26:20.875Z,1599762380.875 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-09-10T18:26:20.875Z,1599762380.875 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-09-10T18:26:20.876Z,1599762380.876 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-09-10T18:26:21.018Z,1599762381.018 [BuoyancyServo] Loaded
2020-09-10T18:26:21.019Z,1599762381.019 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-09-10T18:26:21.047Z,1599762381.047 [ElevatorServo] Loaded
2020-09-10T18:26:21.047Z,1599762381.047 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-09-10T18:26:21.074Z,1599762381.074 [MassServo] Loaded
2020-09-10T18:26:21.074Z,1599762381.074 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-09-10T18:26:21.101Z,1599762381.101 [RudderServo] Loaded
2020-09-10T18:26:21.102Z,1599762381.102 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-09-10T18:26:21.128Z,1599762381.128 [ThrusterServo] Loaded
2020-09-10T18:26:21.128Z,1599762381.128 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-09-10T18:26:21.128Z,1599762381.128 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-09-10T18:26:21.129Z,1599762381.129 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-09-10T18:26:21.158Z,1599762381.158 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-09-10T18:26:21.159Z,1599762381.159 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-09-10T18:26:21.472Z,1599762381.472 [BackSeatDriver] Loaded
2020-09-10T18:26:21.472Z,1599762381.472 [ComponentRegistry](DEBUG): Component "BackSeatDriver" handled in its own thread.
2020-09-10T18:26:21.473Z,1599762381.473 [BackSeatDriver ThreadHandler](DEBUG): Created PCaller Thread at 40B034E0
2020-09-10T18:26:21.474Z,1599762381.474 [BackSeatDriver ThreadHandler](INFO): Protected caller Thread ID is 915
2020-09-10T18:26:21.502Z,1599762381.502 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2020-09-10T18:26:21.507Z,1599762381.507 [CTD_Seabird](INFO): created writer for : sea_water_density
2020-09-10T18:26:21.508Z,1599762381.508 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2020-09-10T18:26:21.512Z,1599762381.512 [CTD_Seabird](INFO): created writer for : depth
2020-09-10T18:26:21.513Z,1599762381.513 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2020-09-10T18:26:21.517Z,1599762381.517 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2020-09-10T18:26:21.518Z,1599762381.518 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2020-09-10T18:26:21.523Z,1599762381.523 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2020-09-10T18:26:21.524Z,1599762381.524 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2020-09-10T18:26:21.529Z,1599762381.529 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2020-09-10T18:26:21.530Z,1599762381.530 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2020-09-10T18:26:21.535Z,1599762381.535 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2020-09-10T18:26:21.535Z,1599762381.535 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2020-09-10T18:26:21.540Z,1599762381.540 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2020-09-10T18:26:21.566Z,1599762381.566 [CTD_Seabird] Loaded
2020-09-10T18:26:21.567Z,1599762381.567 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2020-09-10T18:26:21.568Z,1599762381.568 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40B334E0
2020-09-10T18:26:21.568Z,1599762381.568 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 916
2020-09-10T18:26:21.590Z,1599762381.590 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470
2020-09-10T18:26:21.590Z,1599762381.590 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470
2020-09-10T18:26:21.594Z,1599762381.594 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650
2020-09-10T18:26:21.594Z,1599762381.594 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650
2020-09-10T18:26:21.598Z,1599762381.598 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl
2020-09-10T18:26:21.598Z,1599762381.598 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl
2020-09-10T18:26:21.603Z,1599762381.603 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm
2020-09-10T18:26:21.603Z,1599762381.603 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm
2020-09-10T18:26:21.607Z,1599762381.607 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm
2020-09-10T18:26:21.607Z,1599762381.607 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm
2020-09-10T18:26:21.612Z,1599762381.612 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm
2020-09-10T18:26:21.612Z,1599762381.612 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm
2020-09-10T18:26:21.616Z,1599762381.616 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm
2020-09-10T18:26:21.616Z,1599762381.616 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm
2020-09-10T18:26:21.620Z,1599762381.620 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water
2020-09-10T18:26:21.624Z,1599762381.624 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water
2020-09-10T18:26:21.625Z,1599762381.625 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-09-10T18:26:21.625Z,1599762381.625 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-09-10T18:26:21.629Z,1599762381.629 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-09-10T18:26:21.629Z,1599762381.629 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-09-10T18:26:21.633Z,1599762381.633 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-09-10T18:26:21.634Z,1599762381.634 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-09-10T18:26:21.638Z,1599762381.638 [WetLabsBB2FL] Loaded
2020-09-10T18:26:21.638Z,1599762381.638 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2020-09-10T18:26:21.639Z,1599762381.639 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40B634E0
2020-09-10T18:26:21.640Z,1599762381.640 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 917
2020-09-10T18:26:21.640Z,1599762381.640 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-09-10T18:26:21.644Z,1599762381.644 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-09-10T18:26:21.645Z,1599762381.645 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-09-10T18:26:21.651Z,1599762381.651 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-09-10T18:26:21.652Z,1599762381.652 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B934E0
2020-09-10T18:26:21.653Z,1599762381.653 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 918
2020-09-10T18:26:21.657Z,1599762381.657 [Supervisor](INFO): Main Thread ID is 822
2020-09-10T18:26:21.657Z,1599762381.657 [Supervisor](DEBUG): Running supervisor.
2020-09-10T18:26:21.658Z,1599762381.658 [CommandLine ThreadHandler](INFO): Handler Thread ID is 919
2020-09-10T18:26:21.661Z,1599762381.661 [controlThread ThreadHandler](INFO): Handler Thread ID is 920
2020-09-10T18:26:21.661Z,1599762381.661 [controlThread](DEBUG): Initializing ControlThread
2020-09-10T18:26:21.662Z,1599762381.662 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-09-10T18:26:21.663Z,1599762381.663 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-09-10T18:26:21.664Z,1599762381.664 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-09-10T18:26:21.665Z,1599762381.665 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-09-10T18:26:21.665Z,1599762381.665 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-09-10T18:26:21.665Z,1599762381.665 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-09-10T18:26:21.666Z,1599762381.666 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-09-10T18:26:21.666Z,1599762381.666 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-09-10T18:26:21.667Z,1599762381.667 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-09-10T18:26:21.667Z,1599762381.667 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-09-10T18:26:21.674Z,1599762381.674 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-09-10T18:26:21.675Z,1599762381.675 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-09-10T18:26:21.675Z,1599762381.675 [SBIT](INFO): Initialize SBIT Component.
2020-09-10T18:26:21.675Z,1599762381.675 [SBIT](IMPORTANT): git: 2020-08-31
2020-09-10T18:26:21.676Z,1599762381.676 [SBIT](INFO): git hash: b6c0ec5a69f4280de3f7606c4f2437bb78ebd873
2020-09-10T18:26:21.676Z,1599762381.676 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-09-10T18:26:21.677Z,1599762381.677 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
Kernel Reported: #1 PREEMPT Thu Aug 6 12:04:53 PDT 2020
2020-09-10T18:26:21.678Z,1599762381.678 [SBIT](INFO): Beginning SBIT in 39.000000 seconds.
2020-09-10T18:26:21.679Z,1599762381.679 [IBIT](INFO): Initialize IBIT Component.
2020-09-10T18:26:21.680Z,1599762381.680 [CBIT](DEBUG): Initialize CBIT Component.
2020-09-10T18:26:21.681Z,1599762381.681 [logger ThreadHandler](INFO): Handler Thread ID is 921
2020-09-10T18:26:21.691Z,1599762381.691 [CBIT](DEBUG): Initialized mux pins.
2020-09-10T18:26:21.692Z,1599762381.692 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2020-09-10T18:26:21.692Z,1599762381.692 [CBIT](DEBUG): Initializing the watchdog timer.
2020-09-10T18:26:21.700Z,1599762381.700 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 922
2020-09-10T18:26:21.701Z,1599762381.701 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2020-09-10T18:26:21.712Z,1599762381.712 [Onboard ThreadHandler](INFO): Handler Thread ID is 923
2020-09-10T18:26:21.716Z,1599762381.716 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2020-09-10T18:26:21.716Z,1599762381.716 [CBIT](DEBUG): Initializing heartbeat.
2020-09-10T18:26:21.729Z,1599762381.729 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 924
2020-09-10T18:26:21.752Z,1599762381.752 [BackSeatDriver ThreadHandler](INFO): Handler Thread ID is 925
2020-09-10T18:26:21.772Z,1599762381.772 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 926
2020-09-10T18:26:21.772Z,1599762381.772 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2020-09-10T18:26:21.777Z,1599762381.777 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 928
2020-09-10T18:26:21.778Z,1599762381.778 [WetLabsBB2FL](INFO): Powering down
2020-09-10T18:26:21.788Z,1599762381.788 [CBIT](DEBUG): Deactivating GF circuits.
2020-09-10T18:26:21.788Z,1599762381.788 [CBIT](DEBUG): Deactivating emergency mode.
2020-09-10T18:26:21.823Z,1599762381.823 [CBIT](DEBUG): Backplane powered.
2020-09-10T18:26:21.825Z,1599762381.825 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-09-10T18:26:21.890Z,1599762381.890 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 929
2020-09-10T18:26:21.991Z,1599762381.991 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-09-10T18:26:21.991Z,1599762381.991 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-09-10T18:26:21.991Z,1599762381.991 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-09-10T18:26:21.991Z,1599762381.991 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-09-10T18:26:21.992Z,1599762381.992 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-09-10T18:26:21.992Z,1599762381.992 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-09-10T18:26:21.992Z,1599762381.992 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-09-10T18:26:21.992Z,1599762381.992 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-09-10T18:26:21.992Z,1599762381.992 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-09-10T18:26:21.992Z,1599762381.992 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-09-10T18:26:21.993Z,1599762381.993 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-09-10T18:26:21.993Z,1599762381.993 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-09-10T18:26:21.993Z,1599762381.993 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-09-10T18:26:21.993Z,1599762381.993 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-09-10T18:26:21.993Z,1599762381.993 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-09-10T18:26:21.993Z,1599762381.993 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-09-10T18:26:22.002Z,1599762382.002 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-09-10T18:26:22.111Z,1599762382.111 [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-09-10T18:26:22.124Z,1599762382.124 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2020-09-10T18:26:22.136Z,1599762382.136 [Radio_Surface](INFO): Powering up
2020-09-10T18:26:22.214Z,1599762382.214 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2020-09-10T18:26:22.216Z,1599762382.216 [Default:A.Wait](DEBUG): Construct Wait.
2020-09-10T18:26:22.229Z,1599762382.229 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-09-10T18:26:22.284Z,1599762382.284 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-09-10T18:26:22.287Z,1599762382.287 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-09-10T18:26:22.304Z,1599762382.304 [Default:E.Execute](DEBUG): Construct Execute.
2020-09-10T18:26:22.324Z,1599762382.324 [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>


2020-09-10T18:26:22.328Z,1599762382.328 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,NAL9602,RDI_Pathfinder,DAT,BPC1,AMEcho,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2020-09-10T18:26:22.340Z,1599762382.340 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-09-10T18:26:22.602Z,1599762382.602 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-09-10T18:26:22.603Z,1599762382.603 [DAT](INFO): Powering up
2020-09-10T18:26:22.603Z,1599762382.603 [DAT](DEBUG): Initializing DAT.
2020-09-10T18:26:22.660Z,1599762382.660 [AMEcho](INFO): Powering up
2020-09-10T18:26:22.672Z,1599762382.672 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-09-10T18:26:22.742Z,1599762382.742 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-09-10T18:26:22.752Z,1599762382.752 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-09-10T18:26:22.753Z,1599762382.753 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-09-10T18:26:22.764Z,1599762382.764 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-09-10T18:26:22.765Z,1599762382.765 [MassServo](DEBUG): Initializing EZServoServo.
2020-09-10T18:26:22.776Z,1599762382.776 [MassServo](DEBUG): Initializing MassServo.
2020-09-10T18:26:22.777Z,1599762382.777 [RudderServo](DEBUG): Initializing EZServoServo.
2020-09-10T18:26:22.788Z,1599762382.788 [RudderServo](DEBUG): Initializing RudderServo.
2020-09-10T18:26:22.789Z,1599762382.789 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-09-10T18:26:22.800Z,1599762382.800 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-09-10T18:26:22.884Z,1599762382.884 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2020-09-10T18:26:22.884Z,1599762382.884 [DropWeight] Hardware Fault, FailCount= 1
2020-09-10T18:26:22.884Z,1599762382.884 [DropWeight](ERROR): Hardware Fault
2020-09-10T18:26:23.052Z,1599762383.052 [AMEcho](INFO): Powering down
2020-09-10T18:26:23.073Z,1599762383.073 [CommandLine](FAULT): Scheduling is paused
2020-09-10T18:26:23.074Z,1599762383.074 [CBIT](INFO): Critical error at 20200910T182622
2020-09-10T18:26:23.074Z,1599762383.074 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2020-09-10T18:26:23.076Z,1599762383.076 [CBIT](ERROR): Hardware Fault in component: DropWeight
2020-09-10T18:26:23.077Z,1599762383.077 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2020-09-10T18:26:23.235Z,1599762383.235 [CBIT](INFO): Critical error at 20200910T182623
2020-09-10T18:26:28.804Z,1599762388.804 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2020-09-10T18:26:35.428Z,1599762395.428 [DAT](INFO): commRate: 800
2020-09-10T18:26:35.428Z,1599762395.428 [DAT](INFO): commRate: 800
2020-09-10T18:26:35.826Z,1599762395.826 [DAT](INFO): entering command mode
2020-09-10T18:26:36.230Z,1599762396.230 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:36.660Z,1599762396.660 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:37.038Z,1599762397.038 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:37.442Z,1599762397.442 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:37.846Z,1599762397.846 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:38.250Z,1599762398.250 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:38.654Z,1599762398.654 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:39.058Z,1599762399.058 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:39.473Z,1599762399.473 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:39.866Z,1599762399.866 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:40.270Z,1599762400.270 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:40.674Z,1599762400.674 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:41.078Z,1599762401.078 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:41.494Z,1599762401.494 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:41.887Z,1599762401.887 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:42.290Z,1599762402.290 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:42.694Z,1599762402.694 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:43.098Z,1599762403.098 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:43.502Z,1599762403.502 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:43.906Z,1599762403.906 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:44.310Z,1599762404.310 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:44.717Z,1599762404.717 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2020-09-10T18:26:44.717Z,1599762404.717 [RDI_Pathfinder] Communications Fault, FailCount= 1
2020-09-10T18:26:44.717Z,1599762404.717 [RDI_Pathfinder](ERROR): Communications Fault
2020-09-10T18:26:44.718Z,1599762404.718 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:44.789Z,1599762404.789 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2020-09-10T18:26:45.184Z,1599762405.184 [RDI_Pathfinder](INFO): Powering down
2020-09-10T18:26:45.185Z,1599762405.185 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:45.517Z,1599762405.517 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:45.933Z,1599762405.933 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:46.032Z,1599762406.032 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2020-09-10T18:26:46.032Z,1599762406.032 [RDI_Pathfinder] No Fault, FailCount= 1
2020-09-10T18:26:46.340Z,1599762406.340 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:46.729Z,1599762406.729 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:47.137Z,1599762407.137 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:47.541Z,1599762407.541 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:47.949Z,1599762407.949 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:48.363Z,1599762408.363 [NAL9602](INFO): Powering up NAL9602
2020-09-10T18:26:48.365Z,1599762408.365 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:48.757Z,1599762408.757 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:49.157Z,1599762409.157 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:49.561Z,1599762409.561 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:49.965Z,1599762409.965 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:50.365Z,1599762410.365 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:50.769Z,1599762410.769 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:51.177Z,1599762411.177 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T18:26:51.177Z,1599762411.177 [DAT](FAULT): failed to enter command mode
2020-09-10T18:26:51.577Z,1599762411.577 [DAT](INFO): entering command mode
2020-09-10T18:26:51.986Z,1599762411.986 [DAT](INFO): setting verbose to 3
2020-09-10T18:26:52.390Z,1599762412.390 [DAT](INFO): set verbose to 3
2020-09-10T18:26:52.391Z,1599762412.391 [DAT](INFO): setting DatVerbose to 27440
2020-09-10T18:26:52.794Z,1599762412.794 [DAT](INFO): set DatVerbose to 27440
2020-09-10T18:26:52.795Z,1599762412.795 [DAT](INFO): setting transmit power to 8
2020-09-10T18:26:53.194Z,1599762413.194 [DAT](INFO): set transmit power to 8
2020-09-10T18:26:53.195Z,1599762413.195 [DAT](INFO): setting local address to 9
2020-09-10T18:26:53.602Z,1599762413.602 [DAT](INFO): set local address to 9
2020-09-10T18:26:59.270Z,1599762419.270 [NAL9602](INFO): NAL9602 initialized
2020-09-10T18:27:01.318Z,1599762421.318 [SBIT](IMPORTANT): Beginning Startup BIT
2020-09-10T18:27:01.330Z,1599762421.330 [CBIT](IMPORTANT): Beginning ground fault scan
2020-09-10T18:27:08.557Z,1599762428.557 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2020-09-10T18:27:08.557Z,1599762428.557 [RDI_Pathfinder] Communications Fault, FailCount= 2
2020-09-10T18:27:08.557Z,1599762428.557 [RDI_Pathfinder](ERROR): Communications Fault
2020-09-10T18:27:08.708Z,1599762428.708 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2020-09-10T18:27:09.032Z,1599762429.032 [RDI_Pathfinder](INFO): Powering down
2020-09-10T18:27:09.913Z,1599762429.913 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2020-09-10T18:27:09.913Z,1599762429.913 [RDI_Pathfinder] No Fault, FailCount= 2
2020-09-10T18:27:12.339Z,1599762432.339 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.012341
CHAN A1 (24V): 0.038366
CHAN A2 (12V): -0.007209
CHAN A3 (5V): -0.002019
CHAN B0 (3.3V): 0.001826
CHAN B1 (3.15aV): 0.000072
CHAN B2 (3.15bV): -0.000761
CHAN B3 (GND): 0.002504
OPEN: -0.002258
Full Scale Calc: 4.765 mA, -1.589 mA
2020-09-10T18:27:32.400Z,1599762452.400 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2020-09-10T18:27:32.400Z,1599762452.400 [RDI_Pathfinder] Communications Fault, FailCount= 3
2020-09-10T18:27:32.400Z,1599762452.400 [RDI_Pathfinder](ERROR): Communications Fault
2020-09-10T18:27:32.604Z,1599762452.604 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2020-09-10T18:27:32.604Z,1599762452.604 [CBIT](CRITICAL): Communications Fault in component: RDI_Pathfinder
2020-09-10T18:27:32.856Z,1599762452.856 [RDI_Pathfinder](INFO): Powering down
2020-09-10T18:27:32.907Z,1599762452.907 [CBIT](INFO): Critical error at 20200910T182732
2020-09-10T18:27:55.041Z,1599762475.041 [SBIT](IMPORTANT): SBIT PASSED
2020-09-10T18:27:55.042Z,1599762475.042 [SBIT](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2020-09-10T18:27:55.424Z,1599762475.424 [MissionManager](IMPORTANT): Started mission Startup
2020-09-10T18:27:55.424Z,1599762475.424 [Startup] Running Loop=1
2020-09-10T18:27:55.425Z,1599762475.425 [Startup](DEBUG): Aggregate::initialize Startup
2020-09-10T18:27:55.425Z,1599762475.425 [Startup:A.GoToSurface] Running Loop=1
2020-09-10T18:27:55.425Z,1599762475.425 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-09-10T18:27:55.425Z,1599762475.425 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-09-10T18:27:55.426Z,1599762475.426 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-09-10T18:27:55.426Z,1599762475.426 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-09-10T18:27:55.427Z,1599762475.427 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-09-10T18:27:55.427Z,1599762475.427 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-09-10T18:27:55.428Z,1599762475.428 [Startup:StartupSatComms] Running Loop=1
2020-09-10T18:27:55.429Z,1599762475.429 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2020-09-10T18:27:55.429Z,1599762475.429 [Startup:StartupSatComms:A] Running Loop=1
2020-09-10T18:27:55.825Z,1599762475.825 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2020-09-10T18:27:56.227Z,1599762476.227 [AMEcho](INFO): Powering up
2020-09-10T18:28:10.373Z,1599762490.373 [AMEcho](ERROR): No EchoSounder communication! Re-initializing
2020-09-10T18:28:10.373Z,1599762490.373 [AMEcho] Communications Fault, FailCount= 1
2020-09-10T18:28:10.373Z,1599762490.373 [AMEcho](ERROR): Communications Fault
2020-09-10T18:28:10.418Z,1599762490.418 [CBIT](ERROR): Communications Fault in component: AMEcho
2020-09-10T18:28:10.944Z,1599762490.944 [AMEcho](INFO): Powering down
2020-09-10T18:28:11.600Z,1599762491.600 [CBIT](INFO): Clearing failed state for component AMEcho
2020-09-10T18:28:11.600Z,1599762491.600 [AMEcho] No Fault, FailCount= 1
2020-09-10T18:28:11.975Z,1599762491.975 [AMEcho](INFO): Powering up
2020-09-10T18:28:26.134Z,1599762506.134 [AMEcho](ERROR): No EchoSounder communication! Re-initializing
2020-09-10T18:28:26.134Z,1599762506.134 [AMEcho] Communications Fault, FailCount= 2
2020-09-10T18:28:26.134Z,1599762506.134 [AMEcho](ERROR): Communications Fault
2020-09-10T18:28:26.149Z,1599762506.149 [CBIT](ERROR): Communications Fault in component: AMEcho
2020-09-10T18:28:26.696Z,1599762506.696 [AMEcho](INFO): Powering down
2020-09-10T18:28:27.351Z,1599762507.351 [CBIT](INFO): Clearing failed state for component AMEcho
2020-09-10T18:28:27.351Z,1599762507.351 [AMEcho] No Fault, FailCount= 2
2020-09-10T18:28:27.735Z,1599762507.735 [AMEcho](INFO): Powering up
2020-09-10T18:28:41.999Z,1599762521.999 [AMEcho](ERROR): No EchoSounder communication! Re-initializing
2020-09-10T18:28:41.999Z,1599762521.999 [AMEcho] Communications Fault, FailCount= 3
2020-09-10T18:28:41.999Z,1599762521.999 [AMEcho](ERROR): Communications Fault
2020-09-10T18:28:42.014Z,1599762522.014 [CBIT](ERROR): Communications Fault in component: AMEcho
2020-09-10T18:28:42.014Z,1599762522.014 [CBIT](CRITICAL): Communications Fault in component: AMEcho
2020-09-10T18:28:42.480Z,1599762522.480 [AMEcho](INFO): Powering down
2020-09-10T18:28:42.499Z,1599762522.499 [CBIT](INFO): Critical error at 20200910T182842
2020-09-10T18:28:55.620Z,1599762535.620 [Startup:StartupSatComms:A](INFO): Timed out from 2020-09-10T18:27:55.4Z
2020-09-10T18:28:55.620Z,1599762535.620 [Startup:StartupSatComms:A] Stopped
2020-09-10T18:28:55.620Z,1599762535.620 [Startup:StartupSatComms:B] Running Loop=1
2020-09-10T18:28:56.028Z,1599762536.028 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-09-10T18:28:56.690Z,1599762536.690 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004995
2020-09-10T18:29:03.855Z,1599762543.855 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20200908T230902/Courier0048.lzma
2020-09-10T18:29:04.857Z,1599762544.857 [DataOverHttps](INFO): Moved sent file to Logs/20200908T230902/Courier0048.lzma.bak
2020-09-10T18:29:04.857Z,1599762544.857 [DataOverHttps](INFO): SBD MOMSN=12647527
2020-09-10T18:29:19.145Z,1599762559.145 [DataOverHttps](INFO): Sending 271 bytes from file Logs/20200910T181850/Courier0000.lzma
2020-09-10T18:29:20.145Z,1599762560.145 [DataOverHttps](INFO): Moved sent file to Logs/20200910T181850/Courier0000.lzma.bak
2020-09-10T18:29:20.145Z,1599762560.145 [DataOverHttps](INFO): SBD MOMSN=12647529
2020-09-10T18:29:22.027Z,1599762562.027 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2020-09-10T18:29:22.027Z,1599762562.027 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-09-10T18:29:22.066Z,1599762562.066 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-09-10T18:29:22.293Z,1599762562.293 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-09-10T18:29:22.293Z,1599762562.293 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2020-09-10T18:29:35.467Z,1599762575.467 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20200910T181850/Courier0004.lzma
2020-09-10T18:29:36.469Z,1599762576.469 [DataOverHttps](INFO): Moved sent file to Logs/20200910T181850/Courier0004.lzma.bak
2020-09-10T18:29:36.469Z,1599762576.469 [DataOverHttps](INFO): SBD MOMSN=12647535
2020-09-10T18:29:40.864Z,1599762580.864 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2020-09-10T18:29:51.848Z,1599762591.848 [DataOverHttps](INFO): Sending 290 bytes from file Logs/20200910T182609/Courier0000.lzma
2020-09-10T18:29:52.849Z,1599762592.849 [DataOverHttps](INFO): Moved sent file to Logs/20200910T182609/Courier0000.lzma.bak
2020-09-10T18:29:52.849Z,1599762592.849 [DataOverHttps](INFO): SBD MOMSN=12647537
2020-09-10T18:29:55.837Z,1599762595.837 [Startup:StartupSatComms:B](INFO): Timed out from 2020-09-10T18:28:55.6Z
2020-09-10T18:29:55.837Z,1599762595.837 [Startup:StartupSatComms:B] Stopped
2020-09-10T18:29:55.837Z,1599762595.837 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2020-09-10T18:29:55.837Z,1599762595.837 [Startup:StartupSatComms] Stopped
2020-09-10T18:29:55.837Z,1599762595.837 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2020-09-10T18:29:55.838Z,1599762595.838 [Startup](INFO): Completed Startup
2020-09-10T18:29:55.838Z,1599762595.838 [MissionManager](INFO): Startup is completed.
2020-09-10T18:29:55.838Z,1599762595.838 [MissionManager](INFO): Uninitializing Mission Startup
2020-09-10T18:29:55.838Z,1599762595.838 [Startup] Stopped
2020-09-10T18:29:55.838Z,1599762595.838 [Startup](DEBUG): Aggregate::uninitialize Startup
2020-09-10T18:29:55.838Z,1599762595.838 [Startup:A.GoToSurface] Stopped
2020-09-10T18:29:55.839Z,1599762595.839 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-09-10T18:29:56.248Z,1599762596.248 [MissionManager](IMPORTANT): Started mission Default
2020-09-10T18:29:56.248Z,1599762596.248 [Default] Running Loop=1
2020-09-10T18:29:56.248Z,1599762596.248 [Default](DEBUG): Aggregate::initialize Default
2020-09-10T18:29:56.248Z,1599762596.248 [Default:B.GoToSurface] Running Loop=1
2020-09-10T18:29:56.249Z,1599762596.249 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-09-10T18:29:56.249Z,1599762596.249 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-09-10T18:29:56.249Z,1599762596.249 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-09-10T18:29:56.249Z,1599762596.249 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-09-10T18:29:56.250Z,1599762596.250 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-09-10T18:29:56.250Z,1599762596.250 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-09-10T18:29:56.250Z,1599762596.250 [Default:A.Wait] Running Loop=1
2020-09-10T18:29:56.250Z,1599762596.250 [Default:A.Wait](DEBUG): Initialize Wait Component.
2020-09-10T18:30:05.323Z,1599762605.323 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20200908T230902/Express0049.lzma
2020-09-10T18:30:06.325Z,1599762606.325 [DataOverHttps](INFO): Moved sent file to Logs/20200908T230902/Express0049.lzma.bak
2020-09-10T18:30:06.326Z,1599762606.326 [DataOverHttps](INFO): SBD MOMSN=12647544
2020-09-10T18:30:09.485Z,1599762609.485 [Default:A.Wait](INFO): Done Waiting.
2020-09-10T18:30:09.485Z,1599762609.485 [Default:A.Wait] Stopped
2020-09-10T18:30:09.485Z,1599762609.485 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2020-09-10T18:30:09.896Z,1599762609.896 [Default:CheckIn] Running Loop=1
2020-09-10T18:30:09.897Z,1599762609.897 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-09-10T18:30:09.897Z,1599762609.897 [Default:CheckIn:Read_GPS] Running Loop=1
2020-09-10T18:30:10.318Z,1599762610.318 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-09-10T18:30:32.537Z,1599762632.537 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2020-09-10T18:30:32.538Z,1599762632.538 [RDI_Pathfinder] No Fault, FailCount= 3
2020-09-10T18:30:45.443Z,1599762645.443 [RDI_Pathfinder](FAULT): DVL failed to acquire valid data within timeout.
2020-09-10T18:30:45.443Z,1599762645.443 [RDI_Pathfinder] Data Fault, FailCount= 1
2020-09-10T18:30:45.443Z,1599762645.443 [RDI_Pathfinder](ERROR): Data Fault
2020-09-10T18:30:45.467Z,1599762645.467 [CBIT](ERROR): Data Fault in component: RDI_Pathfinder
2020-09-10T18:30:45.916Z,1599762645.916 [RDI_Pathfinder](INFO): Powering down
2020-09-10T18:30:46.693Z,1599762646.693 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2020-09-10T18:30:46.693Z,1599762646.693 [RDI_Pathfinder] No Fault, FailCount= 1
2020-09-10T18:31:09.274Z,1599762669.274 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2020-09-10T18:31:09.274Z,1599762669.274 [RDI_Pathfinder] Communications Fault, FailCount= 2
2020-09-10T18:31:09.274Z,1599762669.274 [RDI_Pathfinder](ERROR): Communications Fault
2020-09-10T18:31:09.290Z,1599762669.290 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2020-09-10T18:31:09.756Z,1599762669.756 [RDI_Pathfinder](INFO): Powering down
2020-09-10T18:31:10.529Z,1599762670.529 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2020-09-10T18:31:10.529Z,1599762670.529 [RDI_Pathfinder] No Fault, FailCount= 2
2020-09-10T18:31:33.110Z,1599762693.110 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2020-09-10T18:31:33.110Z,1599762693.110 [RDI_Pathfinder] Communications Fault, FailCount= 3
2020-09-10T18:31:33.110Z,1599762693.110 [RDI_Pathfinder](ERROR): Communications Fault
2020-09-10T18:31:33.162Z,1599762693.162 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2020-09-10T18:31:33.162Z,1599762693.162 [CBIT](CRITICAL): Communications Fault in component: RDI_Pathfinder
2020-09-10T18:31:33.580Z,1599762693.580 [RDI_Pathfinder](INFO): Powering down
2020-09-10T18:31:33.604Z,1599762693.604 [CBIT](INFO): Critical error at 20200910T183133
2020-09-10T18:31:42.084Z,1599762702.084 [CBIT](INFO): Clearing failed state for component AMEcho
2020-09-10T18:31:42.084Z,1599762702.084 [AMEcho] No Fault, FailCount= 3
2020-09-10T18:31:42.406Z,1599762702.406 [AMEcho](INFO): Powering up
2020-09-10T18:31:56.557Z,1599762716.557 [AMEcho](ERROR): No EchoSounder communication! Re-initializing
2020-09-10T18:31:56.557Z,1599762716.557 [AMEcho] Communications Fault, FailCount= 1
2020-09-10T18:31:56.557Z,1599762716.557 [AMEcho](ERROR): Communications Fault
2020-09-10T18:31:56.599Z,1599762716.599 [CBIT](ERROR): Communications Fault in component: AMEcho
2020-09-10T18:31:57.108Z,1599762717.108 [AMEcho](INFO): Powering down
2020-09-10T18:31:57.780Z,1599762717.780 [CBIT](INFO): Clearing failed state for component AMEcho
2020-09-10T18:31:57.780Z,1599762717.780 [AMEcho] No Fault, FailCount= 1
2020-09-10T18:31:58.169Z,1599762718.169 [AMEcho](INFO): Powering up
2020-09-10T18:32:02.193Z,1599762722.193 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-09-10T18:32:12.309Z,1599762732.309 [AMEcho](ERROR): No EchoSounder communication! Re-initializing
2020-09-10T18:32:12.309Z,1599762732.309 [AMEcho] Communications Fault, FailCount= 2
2020-09-10T18:32:12.310Z,1599762732.310 [AMEcho](ERROR): Communications Fault
2020-09-10T18:32:12.356Z,1599762732.356 [CBIT](ERROR): Communications Fault in component: AMEcho
2020-09-10T18:32:12.872Z,1599762732.872 [AMEcho](INFO): Powering down
2020-09-10T18:32:13.535Z,1599762733.535 [CBIT](INFO): Clearing failed state for component AMEcho
2020-09-10T18:32:13.535Z,1599762733.535 [AMEcho] No Fault, FailCount= 2
2020-09-10T18:32:13.911Z,1599762733.911 [AMEcho](INFO): Powering up
2020-09-10T18:32:22.824Z,1599762742.824 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2020-09-10T18:32:22.824Z,1599762742.824 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-09-10T18:32:22.862Z,1599762742.862 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-09-10T18:32:23.249Z,1599762743.249 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-09-10T18:32:23.249Z,1599762743.249 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2020-09-10T18:32:28.055Z,1599762748.055 [AMEcho](ERROR): No EchoSounder communication! Re-initializing
2020-09-10T18:32:28.055Z,1599762748.055 [AMEcho] Communications Fault, FailCount= 3
2020-09-10T18:32:28.055Z,1599762748.055 [AMEcho](ERROR): Communications Fault
2020-09-10T18:32:28.078Z,1599762748.078 [CBIT](ERROR): Communications Fault in component: AMEcho
2020-09-10T18:32:28.078Z,1599762748.078 [CBIT](CRITICAL): Communications Fault in component: AMEcho
2020-09-10T18:32:28.636Z,1599762748.636 [AMEcho](INFO): Powering down
2020-09-10T18:32:28.663Z,1599762748.663 [CBIT](INFO): Critical error at 20200910T183228
2020-09-10T18:34:33.341Z,1599762873.341 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2020-09-10T18:34:33.341Z,1599762873.341 [RDI_Pathfinder] No Fault, FailCount= 3
2020-09-10T18:34:46.254Z,1599762886.254 [RDI_Pathfinder](FAULT): DVL failed to acquire valid data within timeout.
2020-09-10T18:34:46.254Z,1599762886.254 [RDI_Pathfinder] Data Fault, FailCount= 1
2020-09-10T18:34:46.254Z,1599762886.254 [RDI_Pathfinder](ERROR): Data Fault
2020-09-10T18:34:46.275Z,1599762886.275 [CBIT](ERROR): Data Fault in component: RDI_Pathfinder
2020-09-10T18:34:46.724Z,1599762886.724 [RDI_Pathfinder](INFO): Powering down
2020-09-10T18:34:47.512Z,1599762887.512 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2020-09-10T18:34:47.512Z,1599762887.512 [RDI_Pathfinder] No Fault, FailCount= 1
2020-09-10T18:35:10.070Z,1599762910.070 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2020-09-10T18:35:10.070Z,1599762910.070 [RDI_Pathfinder] Communications Fault, FailCount= 2
2020-09-10T18:35:10.070Z,1599762910.070 [RDI_Pathfinder](ERROR): Communications Fault
2020-09-10T18:35:10.078Z,1599762910.078 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-09-10T18:30:09.9Z
2020-09-10T18:35:10.078Z,1599762910.078 [Default:CheckIn:Read_GPS] Stopped
2020-09-10T18:35:10.078Z,1599762910.078 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-09-10T18:35:10.087Z,1599762910.087 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2020-09-10T18:35:10.552Z,1599762910.552 [RDI_Pathfinder](INFO): Powering down
2020-09-10T18:35:10.576Z,1599762910.576 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-09-10T18:35:11.323Z,1599762911.323 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2020-09-10T18:35:11.323Z,1599762911.323 [RDI_Pathfinder] No Fault, FailCount= 2
2020-09-10T18:35:17.687Z,1599762917.687 [DataOverHttps](INFO): Sending 111 bytes from file Logs/20200910T182609/Courier0004.lzma
2020-09-10T18:35:18.689Z,1599762918.689 [DataOverHttps](INFO): Moved sent file to Logs/20200910T182609/Courier0004.lzma.bak
2020-09-10T18:35:18.690Z,1599762918.690 [DataOverHttps](INFO): SBD MOMSN=12647546
2020-09-10T18:35:23.838Z,1599762923.838 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2020-09-10T18:35:23.838Z,1599762923.838 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-09-10T18:35:23.885Z,1599762923.885 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-09-10T18:35:24.236Z,1599762924.236 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-09-10T18:35:24.236Z,1599762924.236 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2020-09-10T18:35:28.266Z,1599762928.266 [CBIT](INFO): Clearing failed state for component AMEcho
2020-09-10T18:35:28.266Z,1599762928.266 [AMEcho] No Fault, FailCount= 3
2020-09-10T18:35:28.671Z,1599762928.671 [AMEcho](INFO): Powering up
2020-09-10T18:35:29.256Z,1599762929.256 [AMEcho](INFO): Powering down
2020-09-10T18:35:33.910Z,1599762933.910 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2020-09-10T18:35:33.910Z,1599762933.910 [RDI_Pathfinder] Communications Fault, FailCount= 3
2020-09-10T18:35:33.910Z,1599762933.910 [RDI_Pathfinder](ERROR): Communications Fault
2020-09-10T18:35:34.007Z,1599762934.007 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2020-09-10T18:35:34.007Z,1599762934.007 [CBIT](CRITICAL): Communications Fault in component: RDI_Pathfinder
2020-09-10T18:35:34.388Z,1599762934.388 [RDI_Pathfinder](INFO): Powering down
2020-09-10T18:35:34.404Z,1599762934.404 [AMEcho](INFO): Powering up
2020-09-10T18:35:34.470Z,1599762934.470 [CBIT](INFO): Critical error at 20200910T183534
2020-09-10T18:35:35.674Z,1599762935.674 [DataOverHttps](INFO): Sending 947 bytes from file Logs/20200910T181850/Express0001.lzma
2020-09-10T18:35:36.674Z,1599762936.674 [DataOverHttps](INFO): Moved sent file to Logs/20200910T181850/Express0001.lzma.bak
2020-09-10T18:35:36.674Z,1599762936.674 [DataOverHttps](INFO): SBD MOMSN=12647550
2020-09-10T18:35:48.866Z,1599762948.866 [AMEcho](ERROR): No EchoSounder communication! Re-initializing
2020-09-10T18:35:48.866Z,1599762948.866 [AMEcho] Communications Fault, FailCount= 1
2020-09-10T18:35:48.866Z,1599762948.866 [AMEcho](ERROR): Communications Fault
2020-09-10T18:35:48.897Z,1599762948.897 [CBIT](ERROR): Communications Fault in component: AMEcho
2020-09-10T18:35:49.424Z,1599762949.424 [AMEcho](INFO): Powering down
2020-09-10T18:35:50.132Z,1599762950.132 [CBIT](INFO): Clearing failed state for component AMEcho
2020-09-10T18:35:50.132Z,1599762950.132 [AMEcho] No Fault, FailCount= 1
2020-09-10T18:35:50.489Z,1599762950.489 [AMEcho](INFO): Powering up
2020-09-10T18:35:52.944Z,1599762952.944 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20200910T181850/Express0005.lzma
2020-09-10T18:35:53.945Z,1599762953.945 [DataOverHttps](INFO): Moved sent file to Logs/20200910T181850/Express0005.lzma.bak
2020-09-10T18:35:53.946Z,1599762953.946 [DataOverHttps](INFO): SBD MOMSN=12647576
2020-09-10T18:36:04.622Z,1599762964.622 [AMEcho](ERROR): No EchoSounder communication! Re-initializing
2020-09-10T18:36:04.622Z,1599762964.622 [AMEcho] Communications Fault, FailCount= 2
2020-09-10T18:36:04.622Z,1599762964.622 [AMEcho](ERROR): Communications Fault
2020-09-10T18:36:04.679Z,1599762964.679 [CBIT](ERROR): Communications Fault in component: AMEcho
2020-09-10T18:36:05.200Z,1599762965.200 [AMEcho](INFO): Powering down
2020-09-10T18:36:05.855Z,1599762965.855 [CBIT](INFO): Clearing failed state for component AMEcho
2020-09-10T18:36:05.855Z,1599762965.855 [AMEcho] No Fault, FailCount= 2
2020-09-10T18:36:06.231Z,1599762966.231 [AMEcho](INFO): Powering up
2020-09-10T18:36:10.805Z,1599762970.805 [DataOverHttps](INFO): Sending 722 bytes from file Logs/20200910T182609/Express0001.lzma
2020-09-10T18:36:11.806Z,1599762971.806 [DataOverHttps](INFO): Moved sent file to Logs/20200910T182609/Express0001.lzma.bak
2020-09-10T18:36:11.806Z,1599762971.806 [DataOverHttps](INFO): SBD MOMSN=12647578
2020-09-10T18:36:20.389Z,1599762980.389 [AMEcho](ERROR): No EchoSounder communication! Re-initializing
2020-09-10T18:36:20.389Z,1599762980.389 [AMEcho] Communications Fault, FailCount= 3
2020-09-10T18:36:20.389Z,1599762980.389 [AMEcho](ERROR): Communications Fault
2020-09-10T18:36:20.410Z,1599762980.410 [CBIT](ERROR): Communications Fault in component: AMEcho
2020-09-10T18:36:20.410Z,1599762980.410 [CBIT](CRITICAL): Communications Fault in component: AMEcho
2020-09-10T18:36:20.932Z,1599762980.932 [AMEcho](INFO): Powering down
2020-09-10T18:36:20.971Z,1599762980.971 [CBIT](INFO): Critical error at 20200910T183620
2020-09-10T18:36:27.808Z,1599762987.808 [DataOverHttps](INFO): Sending 241 bytes from file Logs/20200910T182609/Express0005.lzma
2020-09-10T18:36:28.809Z,1599762988.809 [DataOverHttps](INFO): Moved sent file to Logs/20200910T182609/Express0005.lzma.bak
2020-09-10T18:36:28.810Z,1599762988.810 [DataOverHttps](INFO): SBD MOMSN=12647593
2020-09-10T18:36:30.482Z,1599762990.482 [Default:CheckIn:Read_Iridium] Stopped
2020-09-10T18:36:30.482Z,1599762990.482 [Default:CheckIn:C.Wait] Running Loop=1
2020-09-10T18:36:30.482Z,1599762990.482 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-09-10T18:37:01.581Z,1599763021.581 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-09-10T18:37:01.581Z,1599763021.581 [NAL9602] Data Fault, FailCount= 1
2020-09-10T18:37:01.581Z,1599763021.581 [NAL9602](ERROR): Data Fault
2020-09-10T18:37:01.597Z,1599763021.597 [CBIT](ERROR): Data Fault in component: NAL9602
2020-09-10T18:37:01.977Z,1599763021.977 [NAL9602](INFO): Powering down
2020-09-10T18:37:02.834Z,1599763022.834 [CBIT](INFO): Clearing failed state for component NAL9602
2020-09-10T18:37:02.834Z,1599763022.834 [NAL9602] No Fault, FailCount= 1
2020-09-10T18:37:32.281Z,1599763052.281 [NAL9602](INFO): Powering up NAL9602
2020-09-10T18:37:43.189Z,1599763063.189 [NAL9602](INFO): NAL9602 initialized
2020-09-10T18:38:24.828Z,1599763104.828 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2020-09-10T18:38:24.828Z,1599763104.828 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-09-10T18:38:24.862Z,1599763104.862 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-09-10T18:38:25.235Z,1599763105.235 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-09-10T18:38:25.235Z,1599763105.235 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2020-09-10T18:38:34.129Z,1599763114.129 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2020-09-10T18:38:34.129Z,1599763114.129 [RDI_Pathfinder] No Fault, FailCount= 3
2020-09-10T18:38:47.030Z,1599763127.030 [RDI_Pathfinder](FAULT): DVL failed to acquire valid data within timeout.
2020-09-10T18:38:47.030Z,1599763127.030 [RDI_Pathfinder] Data Fault, FailCount= 1
2020-09-10T18:38:47.031Z,1599763127.031 [RDI_Pathfinder](ERROR): Data Fault
2020-09-10T18:38:47.082Z,1599763127.082 [CBIT](ERROR): Data Fault in component: RDI_Pathfinder
2020-09-10T18:38:47.488Z,1599763127.488 [RDI_Pathfinder](INFO): Powering down
2020-09-10T18:38:48.319Z,1599763128.319 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2020-09-10T18:38:48.319Z,1599763128.319 [RDI_Pathfinder] No Fault, FailCount= 1
2020-09-10T18:39:10.878Z,1599763150.878 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2020-09-10T18:39:10.878Z,1599763150.878 [RDI_Pathfinder] Communications Fault, FailCount= 2
2020-09-10T18:39:10.878Z,1599763150.878 [RDI_Pathfinder](ERROR): Communications Fault
2020-09-10T18:39:10.898Z,1599763150.898 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2020-09-10T18:39:11.336Z,1599763151.336 [RDI_Pathfinder](INFO): Powering down
2020-09-10T18:39:12.097Z,1599763152.097 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2020-09-10T18:39:12.097Z,1599763152.097 [RDI_Pathfinder] No Fault, FailCount= 2
2020-09-10T18:39:20.583Z,1599763160.583 [CBIT](INFO): Clearing failed state for component AMEcho
2020-09-10T18:39:20.583Z,1599763160.583 [AMEcho] No Fault, FailCount= 3
2020-09-10T18:39:20.967Z,1599763160.967 [AMEcho](INFO): Powering up
2020-09-10T18:39:21.524Z,1599763161.524 [AMEcho](INFO): Powering down
2020-09-10T18:39:34.708Z,1599763174.708 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2020-09-10T18:39:34.708Z,1599763174.708 [RDI_Pathfinder] Communications Fault, FailCount= 3
2020-09-10T18:39:34.708Z,1599763174.708 [RDI_Pathfinder](ERROR): Communications Fault
2020-09-10T18:39:34.778Z,1599763174.778 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2020-09-10T18:39:34.778Z,1599763174.778 [CBIT](CRITICAL): Communications Fault in component: RDI_Pathfinder
2020-09-10T18:39:35.176Z,1599763175.176 [RDI_Pathfinder](INFO): Powering down
2020-09-10T18:39:35.178Z,1599763175.178 [AMEcho](INFO): Powering up
2020-09-10T18:39:35.208Z,1599763175.208 [CBIT](INFO): Critical error at 20200910T183934
2020-09-10T18:39:49.654Z,1599763189.654 [AMEcho](ERROR): No EchoSounder communication! Re-initializing
2020-09-10T18:39:49.654Z,1599763189.654 [AMEcho] Communications Fault, FailCount= 1
2020-09-10T18:39:49.654Z,1599763189.654 [AMEcho](ERROR): Communications Fault
2020-09-10T18:39:49.674Z,1599763189.674 [CBIT](ERROR): Communications Fault in component: AMEcho
2020-09-10T18:39:50.228Z,1599763190.228 [AMEcho](INFO): Powering down
2020-09-10T18:39:50.869Z,1599763190.869 [CBIT](INFO): Clearing failed state for component AMEcho
2020-09-10T18:39:50.870Z,1599763190.870 [AMEcho] No Fault, FailCount= 1
2020-09-10T18:39:51.259Z,1599763191.259 [AMEcho](INFO): Powering up
2020-09-10T18:40:05.518Z,1599763205.518 [AMEcho](ERROR): No EchoSounder communication! Re-initializing
2020-09-10T18:40:05.518Z,1599763205.518 [AMEcho] Communications Fault, FailCount= 2
2020-09-10T18:40:05.518Z,1599763205.518 [AMEcho](ERROR): Communications Fault
2020-09-10T18:40:05.572Z,1599763205.572 [CBIT](ERROR): Communications Fault in component: AMEcho
2020-09-10T18:40:05.972Z,1599763205.972 [AMEcho](INFO): Powering down
2020-09-10T18:40:06.664Z,1599763206.664 [CBIT](INFO): Clearing failed state for component AMEcho
2020-09-10T18:40:06.664Z,1599763206.664 [AMEcho] No Fault, FailCount= 2
2020-09-10T18:40:07.011Z,1599763207.011 [AMEcho](INFO): Powering up
2020-09-10T18:40:21.151Z,1599763221.151 [AMEcho](ERROR): No EchoSounder communication! Re-initializing
2020-09-10T18:40:21.151Z,1599763221.151 [AMEcho] Communications Fault, FailCount= 3
2020-09-10T18:40:21.151Z,1599763221.151 [AMEcho](ERROR): Communications Fault
2020-09-10T18:40:21.204Z,1599763221.204 [CBIT](ERROR): Communications Fault in component: AMEcho
2020-09-10T18:40:21.204Z,1599763221.204 [CBIT](CRITICAL): Communications Fault in component: AMEcho
2020-09-10T18:40:21.727Z,1599763221.727 [AMEcho](INFO): Powering down
2020-09-10T18:40:21.771Z,1599763221.771 [CBIT](INFO): Critical error at 20200910T184021
2020-09-10T18:40:22.767Z,1599763222.767 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184021.00,A,3648.16594,N,12147.28401,W,0.175,273.89,100920,,,A*74
2020-09-10T18:40:22.770Z,1599763222.770 [NAL9602](INFO): GPS fix at 20200910T184021: (36.802766, -121.788067)
2020-09-10T18:40:55.502Z,1599763255.502 [NAL9602](INFO): Not Powering down - fast GPS
2020-09-10T18:41:23.006Z,1599763283.006 [CBIT](INFO): Clearing failed state for component DropWeight
2020-09-10T18:41:23.006Z,1599763283.006 [DropWeight] No Fault, FailCount= 1
2020-09-10T18:41:31.063Z,1599763291.063 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-09-10T18:41:31.063Z,1599763291.063 [Default:CheckIn:C.Wait] Stopped
2020-09-10T18:41:31.063Z,1599763291.063 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-09-10T18:41:31.063Z,1599763291.063 [Default:CheckIn:D] Running Loop=1
2020-09-10T18:41:31.478Z,1599763291.478 [Default:CheckIn:D] Stopped
2020-09-10T18:41:31.478Z,1599763291.478 [Default:CheckIn:E] Running Loop=1
2020-09-10T18:41:31.866Z,1599763291.866 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.587162 min 
2020-09-10T18:41:31.866Z,1599763291.866 [Default:CheckIn:E] Stopped
2020-09-10T18:41:31.866Z,1599763291.866 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-09-10T18:41:31.866Z,1599763291.866 [Default:CheckIn] Stopped
2020-09-10T18:41:31.866Z,1599763291.866 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-09-10T18:41:31.866Z,1599763291.866 [Default:CheckIn](INFO): Running loop #2
2020-09-10T18:41:31.866Z,1599763291.866 [Default:CheckIn] Running Loop=2
2020-09-10T18:41:31.866Z,1599763291.866 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-09-10T18:41:31.867Z,1599763291.867 [Default:CheckIn:Read_GPS] Running Loop=1
2020-09-10T18:41:33.874Z,1599763293.874 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184132.00,A,3648.16964,N,12147.27479,W,0.641,273.89,100920,,,A*74
2020-09-10T18:41:33.877Z,1599763293.877 [NAL9602](INFO): GPS fix at 20200910T184132: (36.802827, -121.787913)
2020-09-10T18:41:33.886Z,1599763293.886 [Default:CheckIn:Read_GPS] Stopped
2020-09-10T18:41:33.886Z,1599763293.886 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-09-10T18:41:41.552Z,1599763301.552 [DataOverHttps](INFO): Sending 305 bytes from file Logs/20200910T182609/Courier0007.lzma
2020-09-10T18:41:42.553Z,1599763302.553 [DataOverHttps](INFO): Moved sent file to Logs/20200910T182609/Courier0007.lzma.bak
2020-09-10T18:41:42.554Z,1599763302.554 [DataOverHttps](INFO): SBD MOMSN=12647599
2020-09-10T18:41:58.380Z,1599763318.380 [DataOverHttps](INFO): Sending 351 bytes from file Logs/20200910T182609/Express0008.lzma
2020-09-10T18:41:59.381Z,1599763319.381 [DataOverHttps](INFO): Moved sent file to Logs/20200910T182609/Express0008.lzma.bak
2020-09-10T18:41:59.382Z,1599763319.382 [DataOverHttps](INFO): SBD MOMSN=12647606
2020-09-10T18:42:00.962Z,1599763320.962 [Default:CheckIn:Read_Iridium] Stopped
2020-09-10T18:42:00.962Z,1599763320.962 [Default:CheckIn:C.Wait] Running Loop=1
2020-09-10T18:42:00.963Z,1599763320.963 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-09-10T18:42:34.913Z,1599763354.913 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2020-09-10T18:42:34.913Z,1599763354.913 [RDI_Pathfinder] No Fault, FailCount= 3
2020-09-10T18:42:47.832Z,1599763367.832 [RDI_Pathfinder](FAULT): DVL failed to acquire valid data within timeout.
2020-09-10T18:42:47.832Z,1599763367.832 [RDI_Pathfinder] Data Fault, FailCount= 1
2020-09-10T18:42:47.832Z,1599763367.832 [RDI_Pathfinder](ERROR): Data Fault
2020-09-10T18:42:47.900Z,1599763367.900 [CBIT](ERROR): Data Fault in component: RDI_Pathfinder
2020-09-10T18:42:48.276Z,1599763368.276 [RDI_Pathfinder](INFO): Powering down
2020-09-10T18:42:49.039Z,1599763369.039 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2020-09-10T18:42:49.039Z,1599763369.039 [RDI_Pathfinder] No Fault, FailCount= 1
2020-09-10T18:43:11.656Z,1599763391.656 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2020-09-10T18:43:11.656Z,1599763391.656 [RDI_Pathfinder] Communications Fault, FailCount= 2
2020-09-10T18:43:11.656Z,1599763391.656 [RDI_Pathfinder](ERROR): Communications Fault
2020-09-10T18:43:11.675Z,1599763391.675 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2020-09-10T18:43:12.132Z,1599763392.132 [RDI_Pathfinder](INFO): Powering down
2020-09-10T18:43:12.888Z,1599763392.888 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2020-09-10T18:43:12.888Z,1599763392.888 [RDI_Pathfinder] No Fault, FailCount= 2
2020-09-10T18:43:21.384Z,1599763401.384 [CBIT](INFO): Clearing failed state for component AMEcho
2020-09-10T18:43:21.384Z,1599763401.384 [AMEcho] No Fault, FailCount= 3
2020-09-10T18:43:21.788Z,1599763401.788 [AMEcho](INFO): Powering up
2020-09-10T18:43:22.328Z,1599763402.328 [AMEcho](INFO): Powering down
2020-09-10T18:43:35.484Z,1599763415.484 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2020-09-10T18:43:35.484Z,1599763415.484 [RDI_Pathfinder] Communications Fault, FailCount= 3
2020-09-10T18:43:35.484Z,1599763415.484 [RDI_Pathfinder](ERROR): Communications Fault
2020-09-10T18:43:35.503Z,1599763415.503 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2020-09-10T18:43:35.503Z,1599763415.503 [CBIT](CRITICAL): Communications Fault in component: RDI_Pathfinder
2020-09-10T18:43:35.952Z,1599763415.952 [RDI_Pathfinder](INFO): Powering down
2020-09-10T18:43:35.954Z,1599763415.954 [AMEcho](INFO): Powering up
2020-09-10T18:43:35.990Z,1599763415.990 [CBIT](INFO): Critical error at 20200910T184335
2020-09-10T18:43:50.426Z,1599763430.426 [AMEcho](ERROR): No EchoSounder communication! Re-initializing
2020-09-10T18:43:50.426Z,1599763430.426 [AMEcho] Communications Fault, FailCount= 1
2020-09-10T18:43:50.427Z,1599763430.427 [AMEcho](ERROR): Communications Fault
2020-09-10T18:43:50.463Z,1599763430.463 [CBIT](ERROR): Communications Fault in component: AMEcho
2020-09-10T18:43:50.996Z,1599763430.996 [AMEcho](INFO): Powering down
2020-09-10T18:43:51.676Z,1599763431.676 [CBIT](INFO): Clearing failed state for component AMEcho
2020-09-10T18:43:51.676Z,1599763431.676 [AMEcho] No Fault, FailCount= 1
2020-09-10T18:43:52.043Z,1599763432.043 [AMEcho](INFO): Powering up
2020-09-10T18:44:06.187Z,1599763446.187 [AMEcho](ERROR): No EchoSounder communication! Re-initializing
2020-09-10T18:44:06.187Z,1599763446.187 [AMEcho] Communications Fault, FailCount= 2
2020-09-10T18:44:06.187Z,1599763446.187 [AMEcho](ERROR): Communications Fault
2020-09-10T18:44:06.231Z,1599763446.231 [CBIT](ERROR): Communications Fault in component: AMEcho
2020-09-10T18:44:06.756Z,1599763446.756 [AMEcho](INFO): Powering down
2020-09-10T18:44:07.483Z,1599763447.483 [CBIT](INFO): Clearing failed state for component AMEcho
2020-09-10T18:44:07.483Z,1599763447.483 [AMEcho] No Fault, FailCount= 2
2020-09-10T18:44:07.816Z,1599763447.816 [AMEcho](INFO): Powering up
2020-09-10T18:44:22.032Z,1599763462.032 [AMEcho](ERROR): No EchoSounder communication! Re-initializing
2020-09-10T18:44:22.032Z,1599763462.032 [AMEcho] Communications Fault, FailCount= 3
2020-09-10T18:44:22.032Z,1599763462.032 [AMEcho](ERROR): Communications Fault
2020-09-10T18:44:22.070Z,1599763462.070 [CBIT](ERROR): Communications Fault in component: AMEcho
2020-09-10T18:44:22.071Z,1599763462.071 [CBIT](CRITICAL): Communications Fault in component: AMEcho
2020-09-10T18:44:22.528Z,1599763462.528 [AMEcho](INFO): Powering down
2020-09-10T18:44:22.550Z,1599763462.550 [CBIT](INFO): Critical error at 20200910T184422
2020-09-10T18:46:35.728Z,1599763595.728 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2020-09-10T18:46:35.728Z,1599763595.728 [RDI_Pathfinder] No Fault, FailCount= 3
2020-09-10T18:46:36.073Z,1599763596.073 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-09-10T18:46:48.607Z,1599763608.607 [RDI_Pathfinder](FAULT): DVL failed to acquire valid data within timeout.
2020-09-10T18:46:48.607Z,1599763608.607 [RDI_Pathfinder] Data Fault, FailCount= 1
2020-09-10T18:46:48.607Z,1599763608.607 [RDI_Pathfinder](ERROR): Data Fault
2020-09-10T18:46:48.684Z,1599763608.684 [CBIT](ERROR): Data Fault in component: RDI_Pathfinder
2020-09-10T18:46:49.064Z,1599763609.064 [RDI_Pathfinder](INFO): Powering down
2020-09-10T18:46:49.860Z,1599763609.860 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2020-09-10T18:46:49.860Z,1599763609.860 [RDI_Pathfinder] No Fault, FailCount= 1
2020-09-10T18:47:01.551Z,1599763621.551 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-09-10T18:47:01.551Z,1599763621.551 [Default:CheckIn:C.Wait] Stopped
2020-09-10T18:47:01.551Z,1599763621.551 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-09-10T18:47:01.551Z,1599763621.551 [Default:CheckIn:D] Running Loop=1
2020-09-10T18:47:01.962Z,1599763621.962 [Default:CheckIn:D] Stopped
2020-09-10T18:47:01.962Z,1599763621.962 [Default:CheckIn:E] Running Loop=1
2020-09-10T18:47:02.351Z,1599763622.351 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 17.095225 min 
2020-09-10T18:47:02.351Z,1599763622.351 [Default:CheckIn:E] Stopped
2020-09-10T18:47:02.352Z,1599763622.352 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-09-10T18:47:02.353Z,1599763622.353 [Default:CheckIn] Stopped
2020-09-10T18:47:02.353Z,1599763622.353 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-09-10T18:47:02.354Z,1599763622.354 [Default:CheckIn](INFO): Running loop #3
2020-09-10T18:47:02.354Z,1599763622.354 [Default:CheckIn] Running Loop=3
2020-09-10T18:47:02.354Z,1599763622.354 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-09-10T18:47:02.355Z,1599763622.355 [Default:CheckIn:Read_GPS] Running Loop=1
2020-09-10T18:47:04.351Z,1599763624.351 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184703.00,A,3648.16166,N,12147.26793,W,0.078,268.55,100920,,,A*7B
2020-09-10T18:47:04.353Z,1599763624.353 [NAL9602](INFO): GPS fix at 20200910T184703: (36.802694, -121.787799)
2020-09-10T18:47:04.384Z,1599763624.384 [Default:CheckIn:Read_GPS] Stopped
2020-09-10T18:47:04.384Z,1599763624.384 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-09-10T18:47:12.403Z,1599763632.403 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20200910T182609/Courier0010.lzma
2020-09-10T18:47:12.429Z,1599763632.429 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2020-09-10T18:47:12.429Z,1599763632.429 [RDI_Pathfinder] Communications Fault, FailCount= 2
2020-09-10T18:47:12.429Z,1599763632.429 [RDI_Pathfinder](ERROR): Communications Fault
2020-09-10T18:47:12.468Z,1599763632.468 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2020-09-10T18:47:12.900Z,1599763632.900 [RDI_Pathfinder](INFO): Powering down
2020-09-10T18:47:13.405Z,1599763633.405 [DataOverHttps](INFO): Moved sent file to Logs/20200910T182609/Courier0010.lzma.bak
2020-09-10T18:47:13.406Z,1599763633.406 [DataOverHttps](INFO): SBD MOMSN=12647611
2020-09-10T18:47:13.668Z,1599763633.668 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2020-09-10T18:47:13.668Z,1599763633.668 [RDI_Pathfinder] No Fault, FailCount= 2
2020-09-10T18:47:22.154Z,1599763642.154 [CBIT](INFO): Clearing failed state for component AMEcho
2020-09-10T18:47:22.154Z,1599763642.154 [AMEcho] No Fault, FailCount= 3
2020-09-10T18:47:22.540Z,1599763642.540 [AMEcho](INFO): Powering up
2020-09-10T18:47:23.096Z,1599763643.096 [AMEcho](INFO): Powering down
2020-09-10T18:47:29.812Z,1599763649.812 [DataOverHttps](INFO): Sending 239 bytes from file Logs/20200910T182609/Express0011.lzma
2020-09-10T18:47:30.813Z,1599763650.813 [DataOverHttps](INFO): Moved sent file to Logs/20200910T182609/Express0011.lzma.bak
2020-09-10T18:47:30.814Z,1599763650.814 [DataOverHttps](INFO): SBD MOMSN=12647616
2020-09-10T18:47:32.643Z,1599763652.643 [Default:CheckIn:Read_Iridium] Stopped
2020-09-10T18:47:32.643Z,1599763652.643 [Default:CheckIn:C.Wait] Running Loop=1
2020-09-10T18:47:32.643Z,1599763652.643 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-09-10T18:47:36.281Z,1599763656.281 [NAL9602](INFO): Not Powering down - fast GPS
2020-09-10T18:47:36.283Z,1599763656.283 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2020-09-10T18:47:36.283Z,1599763656.283 [RDI_Pathfinder] Communications Fault, FailCount= 3
2020-09-10T18:47:36.283Z,1599763656.283 [RDI_Pathfinder](ERROR): Communications Fault
2020-09-10T18:47:36.531Z,1599763656.531 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2020-09-10T18:47:36.531Z,1599763656.531 [CBIT](CRITICAL): Communications Fault in component: RDI_Pathfinder
2020-09-10T18:47:36.760Z,1599763656.760 [RDI_Pathfinder](INFO): Powering down
2020-09-10T18:47:36.769Z,1599763656.769 [AMEcho](INFO): Powering up
2020-09-10T18:47:36.840Z,1599763656.840 [CBIT](INFO): Critical error at 20200910T184736
2020-09-10T18:47:51.228Z,1599763671.228 [AMEcho](ERROR): No EchoSounder communication! Re-initializing
2020-09-10T18:47:51.229Z,1599763671.229 [AMEcho] Communications Fault, FailCount= 1
2020-09-10T18:47:51.229Z,1599763671.229 [AMEcho](ERROR): Communications Fault
2020-09-10T18:47:51.262Z,1599763671.262 [CBIT](ERROR): Communications Fault in component: AMEcho
2020-09-10T18:47:51.804Z,1599763671.804 [AMEcho](INFO): Powering down
2020-09-10T18:47:52.464Z,1599763672.464 [CBIT](INFO): Clearing failed state for component AMEcho
2020-09-10T18:47:52.464Z,1599763672.464 [AMEcho] No Fault, FailCount= 1
2020-09-10T18:47:52.851Z,1599763672.851 [AMEcho](INFO): Powering up
2020-09-10T18:48:06.991Z,1599763686.991 [AMEcho](ERROR): No EchoSounder communication! Re-initializing
2020-09-10T18:48:06.991Z,1599763686.991 [AMEcho] Communications Fault, FailCount= 2
2020-09-10T18:48:06.991Z,1599763686.991 [AMEcho](ERROR): Communications Fault
2020-09-10T18:48:07.008Z,1599763687.008 [CBIT](ERROR): Communications Fault in component: AMEcho
2020-09-10T18:48:07.560Z,1599763687.560 [AMEcho](INFO): Powering down
2020-09-10T18:48:08.221Z,1599763688.221 [CBIT](INFO): Clearing failed state for component AMEcho
2020-09-10T18:48:08.221Z,1599763688.221 [AMEcho] No Fault, FailCount= 2
2020-09-10T18:48:08.610Z,1599763688.610 [AMEcho](INFO): Powering up
2020-09-10T18:48:19.518Z,1599763699.518 [AHRS_M2](FAULT): Failed to acquire valid data within timeout.
2020-09-10T18:48:19.518Z,1599763699.518 [AHRS_M2] Data Fault, FailCount= 1
2020-09-10T18:48:19.518Z,1599763699.518 [AHRS_M2](ERROR): Data Fault
2020-09-10T18:48:19.542Z,1599763699.542 [CBIT](ERROR): Data Fault in component: AHRS_M2
2020-09-10T18:48:19.900Z,1599763699.900 [AHRS_M2](INFO): Powering down
2020-09-10T18:48:20.736Z,1599763700.736 [CBIT](INFO): Clearing failed state for component AHRS_M2
2020-09-10T18:48:20.736Z,1599763700.736 [AHRS_M2] No Fault, FailCount= 1
2020-09-10T18:48:21.112Z,1599763701.112 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-09-10T18:48:22.741Z,1599763702.741 [AMEcho](ERROR): No EchoSounder communication! Re-initializing
2020-09-10T18:48:22.741Z,1599763702.741 [AMEcho] Communications Fault, FailCount= 3
2020-09-10T18:48:22.741Z,1599763702.741 [AMEcho](ERROR): Communications Fault
2020-09-10T18:48:22.786Z,1599763702.786 [CBIT](ERROR): Communications Fault in component: AMEcho
2020-09-10T18:48:22.786Z,1599763702.786 [CBIT](CRITICAL): Communications Fault in component: AMEcho
2020-09-10T18:48:23.320Z,1599763703.320 [AMEcho](INFO): Powering down
2020-09-10T18:48:23.341Z,1599763703.341 [CBIT](INFO): Critical error at 20200910T184822
2020-09-10T18:49:43.141Z,1599763783.141 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file).
2020-09-10T18:50:36.511Z,1599763836.511 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2020-09-10T18:50:36.511Z,1599763836.511 [RDI_Pathfinder] No Fault, FailCount= 3
2020-09-10T18:50:49.407Z,1599763849.407 [RDI_Pathfinder](FAULT): DVL failed to acquire valid data within timeout.
2020-09-10T18:50:49.407Z,1599763849.407 [RDI_Pathfinder] Data Fault, FailCount= 1
2020-09-10T18:50:49.407Z,1599763849.407 [RDI_Pathfinder](ERROR): Data Fault
2020-09-10T18:50:49.515Z,1599763849.515 [CBIT](ERROR): Data Fault in component: RDI_Pathfinder
2020-09-10T18:50:49.864Z,1599763849.864 [RDI_Pathfinder](INFO): Powering down
2020-09-10T18:50:50.640Z,1599763850.640 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2020-09-10T18:50:50.640Z,1599763850.640 [RDI_Pathfinder] No Fault, FailCount= 1
2020-09-10T18:51:13.233Z,1599763873.233 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2020-09-10T18:51:13.233Z,1599763873.233 [RDI_Pathfinder] Communications Fault, FailCount= 2
2020-09-10T18:51:13.233Z,1599763873.233 [RDI_Pathfinder](ERROR): Communications Fault
2020-09-10T18:51:13.252Z,1599763873.252 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2020-09-10T18:51:13.704Z,1599763873.704 [RDI_Pathfinder](INFO): Powering down
2020-09-10T18:51:14.458Z,1599763874.458 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2020-09-10T18:51:14.458Z,1599763874.458 [RDI_Pathfinder] No Fault, FailCount= 2
2020-09-10T18:51:22.955Z,1599763882.955 [CBIT](INFO): Clearing failed state for component AMEcho
2020-09-10T18:51:22.955Z,1599763882.955 [AMEcho] No Fault, FailCount= 3
2020-09-10T18:51:23.343Z,1599763883.343 [AMEcho](INFO): Powering up
2020-09-10T18:51:23.896Z,1599763883.896 [AMEcho](INFO): Powering down
2020-09-10T18:51:37.069Z,1599763897.069 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2020-09-10T18:51:37.069Z,1599763897.069 [RDI_Pathfinder] Communications Fault, FailCount= 3
2020-09-10T18:51:37.069Z,1599763897.069 [RDI_Pathfinder](ERROR): Communications Fault
2020-09-10T18:51:37.088Z,1599763897.088 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2020-09-10T18:51:37.088Z,1599763897.088 [CBIT](CRITICAL): Communications Fault in component: RDI_Pathfinder
2020-09-10T18:51:37.544Z,1599763897.544 [RDI_Pathfinder](INFO): Powering down
2020-09-10T18:51:37.546Z,1599763897.546 [AMEcho](INFO): Powering up
2020-09-10T18:51:37.595Z,1599763897.595 [CBIT](INFO): Critical error at 20200910T185137
2020-09-10T18:51:52.018Z,1599763912.018 [AMEcho](ERROR): No EchoSounder communication! Re-initializing
2020-09-10T18:51:52.018Z,1599763912.018 [AMEcho] Communications Fault, FailCount= 1
2020-09-10T18:51:52.018Z,1599763912.018 [AMEcho](ERROR): Communications Fault
2020-09-10T18:51:52.064Z,1599763912.064 [CBIT](ERROR): Communications Fault in component: AMEcho
2020-09-10T18:51:52.592Z,1599763912.592 [AMEcho](INFO): Powering down
2020-09-10T18:51:53.247Z,1599763913.247 [CBIT](INFO): Clearing failed state for component AMEcho
2020-09-10T18:51:53.247Z,1599763913.247 [AMEcho] No Fault, FailCount= 1
2020-09-10T18:51:53.630Z,1599763913.630 [AMEcho](INFO): Powering up
2020-09-10T18:52:07.774Z,1599763927.774 [AMEcho](ERROR): No EchoSounder communication! Re-initializing
2020-09-10T18:52:07.775Z,1599763927.775 [AMEcho] Communications Fault, FailCount= 2
2020-09-10T18:52:07.775Z,1599763927.775 [AMEcho](ERROR): Communications Fault
2020-09-10T18:52:07.808Z,1599763927.808 [CBIT](ERROR): Communications Fault in component: AMEcho
2020-09-10T18:52:08.336Z,1599763928.336 [AMEcho](INFO): Powering down
2020-09-10T18:52:09.015Z,1599763929.015 [CBIT](INFO): Clearing failed state for component AMEcho
2020-09-10T18:52:09.016Z,1599763929.016 [AMEcho] No Fault, FailCount= 2
2020-09-10T18:52:09.386Z,1599763929.386 [AMEcho](INFO): Powering up
2020-09-10T18:52:23.596Z,1599763943.596 [AMEcho](ERROR): No EchoSounder communication! Re-initializing
2020-09-10T18:52:23.596Z,1599763943.596 [AMEcho] Communications Fault, FailCount= 3
2020-09-10T18:52:23.596Z,1599763943.596 [AMEcho](ERROR): Communications Fault
2020-09-10T18:52:23.618Z,1599763943.618 [CBIT](ERROR): Communications Fault in component: AMEcho
2020-09-10T18:52:23.618Z,1599763943.618 [CBIT](CRITICAL): Communications Fault in component: AMEcho
2020-09-10T18:52:24.100Z,1599763944.100 [AMEcho](INFO): Powering down
2020-09-10T18:52:24.131Z,1599763944.131 [CBIT](INFO): Critical error at 20200910T185223
2020-09-10T18:52:33.242Z,1599763953.242 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-09-10T18:52:33.242Z,1599763953.242 [Default:CheckIn:C.Wait] Stopped
2020-09-10T18:52:33.242Z,1599763953.242 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-09-10T18:52:33.242Z,1599763953.242 [Default:CheckIn:D] Running Loop=1
2020-09-10T18:52:33.637Z,1599763953.637 [Default:CheckIn:D] Stopped
2020-09-10T18:52:33.638Z,1599763953.638 [Default:CheckIn:E] Running Loop=1
2020-09-10T18:52:34.042Z,1599763954.042 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 22.623153 min 
2020-09-10T18:52:34.042Z,1599763954.042 [Default:CheckIn:E] Stopped
2020-09-10T18:52:34.042Z,1599763954.042 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-09-10T18:52:34.042Z,1599763954.042 [Default:CheckIn] Stopped
2020-09-10T18:52:34.042Z,1599763954.042 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-09-10T18:52:34.043Z,1599763954.043 [Default:CheckIn](INFO): Running loop #4
2020-09-10T18:52:34.043Z,1599763954.043 [Default:CheckIn] Running Loop=4
2020-09-10T18:52:34.043Z,1599763954.043 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-09-10T18:52:34.043Z,1599763954.043 [Default:CheckIn:Read_GPS] Running Loop=1
2020-09-10T18:52:36.054Z,1599763956.054 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185235.00,A,3648.16443,N,12147.28333,W,0.603,169.38,100920,,,A*7B
2020-09-10T18:52:36.057Z,1599763956.057 [NAL9602](INFO): GPS fix at 20200910T185235: (36.802740, -121.788055)
2020-09-10T18:52:36.066Z,1599763956.066 [Default:CheckIn:Read_GPS] Stopped
2020-09-10T18:52:36.066Z,1599763956.066 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-09-10T18:52:43.715Z,1599763963.715 [DataOverHttps](INFO): Sending 156 bytes from file Logs/20200910T182609/Courier0013.lzma
2020-09-10T18:52:44.717Z,1599763964.717 [DataOverHttps](INFO): Moved sent file to Logs/20200910T182609/Courier0013.lzma.bak
2020-09-10T18:52:44.718Z,1599763964.718 [DataOverHttps](INFO): SBD MOMSN=12647622
2020-09-10T18:53:00.639Z,1599763980.639 [DataOverHttps](INFO): Sending 217 bytes from file Logs/20200910T182609/Express0014.lzma
2020-09-10T18:53:01.641Z,1599763981.641 [DataOverHttps](INFO): Moved sent file to Logs/20200910T182609/Express0014.lzma.bak
2020-09-10T18:53:01.642Z,1599763981.642 [DataOverHttps](INFO): SBD MOMSN=12647629
2020-09-10T18:53:03.196Z,1599763983.196 [Default:CheckIn:Read_Iridium] Stopped
2020-09-10T18:53:03.196Z,1599763983.196 [Default:CheckIn:C.Wait] Running Loop=1
2020-09-10T18:53:03.197Z,1599763983.197 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-09-10T18:54:37.284Z,1599764077.284 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2020-09-10T18:54:37.284Z,1599764077.284 [RDI_Pathfinder] No Fault, FailCount= 3
2020-09-10T18:54:50.191Z,1599764090.191 [RDI_Pathfinder](FAULT): DVL failed to acquire valid data within timeout.
2020-09-10T18:54:50.191Z,1599764090.191 [RDI_Pathfinder] Data Fault, FailCount= 1
2020-09-10T18:54:50.191Z,1599764090.191 [RDI_Pathfinder](ERROR): Data Fault
2020-09-10T18:54:50.218Z,1599764090.218 [CBIT](ERROR): Data Fault in component: RDI_Pathfinder
2020-09-10T18:54:50.672Z,1599764090.672 [RDI_Pathfinder](INFO): Powering down
2020-09-10T18:54:51.468Z,1599764091.468 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2020-09-10T18:54:51.468Z,1599764091.468 [RDI_Pathfinder] No Fault, FailCount= 1
2020-09-10T18:55:14.013Z,1599764114.013 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2020-09-10T18:55:14.013Z,1599764114.013 [RDI_Pathfinder] Communications Fault, FailCount= 2
2020-09-10T18:55:14.013Z,1599764114.013 [RDI_Pathfinder](ERROR): Communications Fault
2020-09-10T18:55:14.032Z,1599764114.032 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2020-09-10T18:55:14.496Z,1599764114.496 [RDI_Pathfinder](INFO): Powering down
2020-09-10T18:55:15.247Z,1599764115.247 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2020-09-10T18:55:15.247Z,1599764115.247 [RDI_Pathfinder] No Fault, FailCount= 2
2020-09-10T18:55:23.731Z,1599764123.731 [CBIT](INFO): Clearing failed state for component AMEcho
2020-09-10T18:55:23.731Z,1599764123.731 [AMEcho] No Fault, FailCount= 3
2020-09-10T18:55:24.129Z,1599764124.129 [AMEcho](INFO): Powering up
2020-09-10T18:55:24.688Z,1599764124.688 [AMEcho](INFO): Powering down
2020-09-10T18:55:37.850Z,1599764137.850 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2020-09-10T18:55:37.850Z,1599764137.850 [RDI_Pathfinder] Communications Fault, FailCount= 3
2020-09-10T18:55:37.850Z,1599764137.850 [RDI_Pathfinder](ERROR): Communications Fault
2020-09-10T18:55:37.926Z,1599764137.926 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2020-09-10T18:55:37.926Z,1599764137.926 [CBIT](CRITICAL): Communications Fault in component: RDI_Pathfinder
2020-09-10T18:55:38.334Z,1599764138.334 [RDI_Pathfinder](INFO): Powering down
2020-09-10T18:55:38.337Z,1599764138.337 [AMEcho](INFO): Powering up
2020-09-10T18:55:38.382Z,1599764138.382 [CBIT](INFO): Critical error at 20200910T185537
2020-09-10T18:55:52.813Z,1599764152.813 [AMEcho](ERROR): No EchoSounder communication! Re-initializing
2020-09-10T18:55:52.813Z,1599764152.813 [AMEcho] Communications Fault, FailCount= 1
2020-09-10T18:55:52.813Z,1599764152.813 [AMEcho](ERROR): Communications Fault
2020-09-10T18:55:52.836Z,1599764152.836 [CBIT](ERROR): Communications Fault in component: AMEcho
2020-09-10T18:55:53.368Z,1599764153.368 [AMEcho](INFO): Powering down
2020-09-10T18:55:54.036Z,1599764154.036 [CBIT](INFO): Clearing failed state for component AMEcho
2020-09-10T18:55:54.036Z,1599764154.036 [AMEcho] No Fault, FailCount= 1
2020-09-10T18:55:54.413Z,1599764154.413 [AMEcho](INFO): Powering up
2020-09-10T18:56:08.562Z,1599764168.562 [AMEcho](ERROR): No EchoSounder communication! Re-initializing
2020-09-10T18:56:08.562Z,1599764168.562 [AMEcho] Communications Fault, FailCount= 2
2020-09-10T18:56:08.563Z,1599764168.563 [AMEcho](ERROR): Communications Fault
2020-09-10T18:56:08.579Z,1599764168.579 [CBIT](ERROR): Communications Fault in component: AMEcho
2020-09-10T18:56:09.128Z,1599764169.128 [AMEcho](INFO): Powering down
2020-09-10T18:56:09.841Z,1599764169.841 [CBIT](INFO): Clearing failed state for component AMEcho
2020-09-10T18:56:09.842Z,1599764169.842 [AMEcho] No Fault, FailCount= 2
2020-09-10T18:56:10.171Z,1599764170.171 [AMEcho](INFO): Powering up
2020-09-10T18:56:24.329Z,1599764184.329 [AMEcho](ERROR): No EchoSounder communication! Re-initializing
2020-09-10T18:56:24.329Z,1599764184.329 [AMEcho] Communications Fault, FailCount= 3
2020-09-10T18:56:24.329Z,1599764184.329 [AMEcho](ERROR): Communications Fault
2020-09-10T18:56:24.352Z,1599764184.352 [CBIT](ERROR): Communications Fault in component: AMEcho
2020-09-10T18:56:24.352Z,1599764184.352 [CBIT](CRITICAL): Communications Fault in component: AMEcho
2020-09-10T18:56:24.892Z,1599764184.892 [AMEcho](INFO): Powering down
2020-09-10T18:56:24.910Z,1599764184.910 [CBIT](INFO): Critical error at 20200910T185624
2020-09-10T18:57:22.910Z,1599764242.910 [BPC1](INFO): Calculating totals. Valid battery stick count: 49. Valid reserve battery stick count: 5.
2020-09-10T18:57:22.912Z,1599764242.912 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle.
2020-09-10T18:57:38.239Z,1599764258.239 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-09-10T18:58:03.702Z,1599764283.702 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-09-10T18:58:03.702Z,1599764283.702 [Default:CheckIn:C.Wait] Stopped
2020-09-10T18:58:03.702Z,1599764283.702 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-09-10T18:58:03.702Z,1599764283.702 [Default:CheckIn:D] Running Loop=1
2020-09-10T18:58:04.109Z,1599764284.109 [Default:CheckIn:D] Stopped
2020-09-10T18:58:04.110Z,1599764284.110 [Default:CheckIn:E] Running Loop=1
2020-09-10T18:58:04.510Z,1599764284.510 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 28.131018 min 
2020-09-10T18:58:04.510Z,1599764284.510 [Default:CheckIn:E] Stopped
2020-09-10T18:58:04.510Z,1599764284.510 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-09-10T18:58:04.510Z,1599764284.510 [Default:CheckIn] Stopped
2020-09-10T18:58:04.510Z,1599764284.510 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-09-10T18:58:04.510Z,1599764284.510 [Default:CheckIn](INFO): Running loop #5
2020-09-10T18:58:04.510Z,1599764284.510 [Default:CheckIn] Running Loop=5
2020-09-10T18:58:04.510Z,1599764284.510 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-09-10T18:58:04.510Z,1599764284.510 [Default:CheckIn:Read_GPS] Running Loop=1
2020-09-10T18:58:06.527Z,1599764286.527 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185805.00,A,3648.16546,N,12147.28265,W,0.194,169.38,100920,,,A*7D
2020-09-10T18:58:06.538Z,1599764286.538 [NAL9602](INFO): GPS fix at 20200910T185805: (36.802758, -121.788044)
2020-09-10T18:58:06.547Z,1599764286.547 [Default:CheckIn:Read_GPS] Stopped
2020-09-10T18:58:06.547Z,1599764286.547 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-09-10T18:58:13.395Z,1599764293.395 [DataOverHttps](INFO): Sending 266 bytes from file Logs/20200910T182609/Courier0016.lzma
2020-09-10T18:58:14.397Z,1599764294.397 [DataOverHttps](INFO): Moved sent file to Logs/20200910T182609/Courier0016.lzma.bak
2020-09-10T18:58:14.398Z,1599764294.398 [DataOverHttps](INFO): SBD MOMSN=12647634
2020-09-10T18:58:32.343Z,1599764312.343 [DataOverHttps](INFO): Sending 232 bytes from file Logs/20200910T182609/Express0017.lzma
2020-09-10T18:58:33.345Z,1599764313.345 [DataOverHttps](INFO): Moved sent file to Logs/20200910T182609/Express0017.lzma.bak
2020-09-10T18:58:33.346Z,1599764313.346 [DataOverHttps](INFO): SBD MOMSN=12647639
2020-09-10T18:58:34.819Z,1599764314.819 [Default:CheckIn:Read_Iridium] Stopped
2020-09-10T18:58:34.819Z,1599764314.819 [Default:CheckIn:C.Wait] Running Loop=1
2020-09-10T18:58:34.819Z,1599764314.819 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-09-10T18:58:38.076Z,1599764318.076 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2020-09-10T18:58:38.076Z,1599764318.076 [RDI_Pathfinder] No Fault, FailCount= 3
2020-09-10T18:58:38.445Z,1599764318.445 [NAL9602](INFO): Not Powering down - fast GPS
2020-09-10T18:58:50.986Z,1599764330.986 [RDI_Pathfinder](FAULT): DVL failed to acquire valid data within timeout.
2020-09-10T18:58:50.986Z,1599764330.986 [RDI_Pathfinder] Data Fault, FailCount= 1
2020-09-10T18:58:50.986Z,1599764330.986 [RDI_Pathfinder](ERROR): Data Fault
2020-09-10T18:58:51.032Z,1599764331.032 [CBIT](ERROR): Data Fault in component: RDI_Pathfinder
2020-09-10T18:58:51.448Z,1599764331.448 [RDI_Pathfinder](INFO): Powering down
2020-09-10T18:58:52.211Z,1599764332.211 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2020-09-10T18:58:52.211Z,1599764332.211 [RDI_Pathfinder] No Fault, FailCount= 1
2020-09-10T18:59:14.805Z,1599764354.805 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2020-09-10T18:59:14.805Z,1599764354.805 [RDI_Pathfinder] Communications Fault, FailCount= 2
2020-09-10T18:59:14.805Z,1599764354.805 [RDI_Pathfinder](ERROR): Communications Fault
2020-09-10T18:59:14.849Z,1599764354.849 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2020-09-10T18:59:15.276Z,1599764355.276 [RDI_Pathfinder](INFO): Powering down
2020-09-10T18:59:16.058Z,1599764356.058 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2020-09-10T18:59:16.058Z,1599764356.058 [RDI_Pathfinder] No Fault, FailCount= 2
2020-09-10T18:59:24.522Z,1599764364.522 [CBIT](INFO): Clearing failed state for component AMEcho
2020-09-10T18:59:24.522Z,1599764364.522 [AMEcho] No Fault, FailCount= 3
2020-09-10T18:59:24.926Z,1599764364.926 [AMEcho](INFO): Powering up
2020-09-10T18:59:25.492Z,1599764365.492 [AMEcho](INFO): Powering down
2020-09-10T18:59:38.639Z,1599764378.639 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2020-09-10T18:59:38.639Z,1599764378.639 [RDI_Pathfinder] Communications Fault, FailCount= 3
2020-09-10T18:59:38.639Z,1599764378.639 [RDI_Pathfinder](ERROR): Communications Fault
2020-09-10T18:59:38.658Z,1599764378.658 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2020-09-10T18:59:38.658Z,1599764378.658 [CBIT](CRITICAL): Communications Fault in component: RDI_Pathfinder
2020-09-10T18:59:39.120Z,1599764379.120 [RDI_Pathfinder](INFO): Powering down
2020-09-10T18:59:39.122Z,1599764379.122 [AMEcho](INFO): Powering up
2020-09-10T18:59:39.175Z,1599764379.175 [CBIT](INFO): Critical error at 20200910T185938
2020-09-10T18:59:53.590Z,1599764393.590 [AMEcho](ERROR): No EchoSounder communication! Re-initializing
2020-09-10T18:59:53.590Z,1599764393.590 [AMEcho] Communications Fault, FailCount= 1
2020-09-10T18:59:53.590Z,1599764393.590 [AMEcho](ERROR): Communications Fault
2020-09-10T18:59:53.612Z,1599764393.612 [CBIT](ERROR): Communications Fault in component: AMEcho
2020-09-10T18:59:54.160Z,1599764394.160 [AMEcho](INFO): Powering down
2020-09-10T18:59:54.824Z,1599764394.824 [CBIT](INFO): Clearing failed state for component AMEcho
2020-09-10T18:59:54.824Z,1599764394.824 [AMEcho] No Fault, FailCount= 1
2020-09-10T18:59:55.206Z,1599764395.206 [AMEcho](INFO): Powering up
2020-09-10T19:00:09.346Z,1599764409.346 [AMEcho](ERROR): No EchoSounder communication! Re-initializing
2020-09-10T19:00:09.346Z,1599764409.346 [AMEcho] Communications Fault, FailCount= 2
2020-09-10T19:00:09.346Z,1599764409.346 [AMEcho](ERROR): Communications Fault
2020-09-10T19:00:09.386Z,1599764409.386 [CBIT](ERROR): Communications Fault in component: AMEcho
2020-09-10T19:00:09.916Z,1599764409.916 [AMEcho](INFO): Powering down
2020-09-10T19:00:10.583Z,1599764410.583 [CBIT](INFO): Clearing failed state for component AMEcho
2020-09-10T19:00:10.583Z,1599764410.583 [AMEcho] No Fault, FailCount= 2
2020-09-10T19:00:10.962Z,1599764410.962 [AMEcho](INFO): Powering up
2020-09-10T19:00:25.102Z,1599764425.102 [AMEcho](ERROR): No EchoSounder communication! Re-initializing
2020-09-10T19:00:25.102Z,1599764425.102 [AMEcho] Communications Fault, FailCount= 3
2020-09-10T19:00:25.102Z,1599764425.102 [AMEcho](ERROR): Communications Fault
2020-09-10T19:00:25.140Z,1599764425.140 [CBIT](ERROR): Communications Fault in component: AMEcho
2020-09-10T19:00:25.140Z,1599764425.140 [CBIT](CRITICAL): Communications Fault in component: AMEcho
2020-09-10T19:00:25.672Z,1599764425.672 [AMEcho](INFO): Powering down
2020-09-10T19:00:25.700Z,1599764425.700 [CBIT](INFO): Critical error at 20200910T190025
2020-09-10T19:01:32.101Z,1599764492.101 [CommandLine](IMPORTANT): got command restart application
2020-09-10T19:01:33.108Z,1599764493.108 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-10T19:01:33.109Z,1599764493.109 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-09-10T19:01:33.172Z,1599764493.172 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2020-09-10T19:01:33.172Z,1599764493.172 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-09-10T19:01:33.173Z,1599764493.173 [CommandLine](INFO): Join timeout helper Thread ID is 1091
2020-09-10T19:01:33.173Z,1599764493.173 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2020-09-10T19:01:33.173Z,1599764493.173 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-09-10T19:01:33.173Z,1599764493.173 [NavChartDb](INFO): Join timeout helper Thread ID is 1092
2020-09-10T19:01:33.484Z,1599764493.484 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-10T19:01:33.484Z,1599764493.484 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-09-10T19:01:33.500Z,1599764493.500 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2020-09-10T19:01:33.500Z,1599764493.500 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-09-10T19:01:33.500Z,1599764493.500 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1093
2020-09-10T19:01:33.784Z,1599764493.784 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-10T19:01:33.784Z,1599764493.784 [WetLabsBB2FL](INFO): Powering down
2020-09-10T19:01:33.785Z,1599764493.785 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-09-10T19:01:33.786Z,1599764493.786 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2020-09-10T19:01:33.786Z,1599764493.786 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-09-10T19:01:33.786Z,1599764493.786 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1094
2020-09-10T19:01:33.848Z,1599764493.848 [CTD_Seabird](INFO): Powering down
2020-09-10T19:01:33.860Z,1599764493.860 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-10T19:01:33.860Z,1599764493.860 [CTD_Seabird](INFO): Powering down
2020-09-10T19:01:33.872Z,1599764493.872 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-09-10T19:01:33.888Z,1599764493.888 [ComponentRegistry](INFO): Shutting down BackSeatDriver ThreadHandler
2020-09-10T19:01:33.888Z,1599764493.888 [BackSeatDriver ThreadHandler](INFO): Thread cancelled.
2020-09-10T19:01:33.888Z,1599764493.888 [BackSeatDriver](INFO): Join timeout helper Thread ID is 1095
2020-09-10T19:01:34.048Z,1599764494.048 [BackSeatDriver ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-10T19:01:34.048Z,1599764494.048 [BackSeatDriver ThreadHandler](INFO): Thread cancelled.
2020-09-10T19:01:34.069Z,1599764494.069 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2020-09-10T19:01:34.069Z,1599764494.069 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-09-10T19:01:34.069Z,1599764494.069 [Radio_Surface](INFO): Join timeout helper Thread ID is 1096
2020-09-10T19:01:34.380Z,1599764494.380 [Radio_Surface](INFO): Powering down
2020-09-10T19:01:34.381Z,1599764494.381 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-10T19:01:34.381Z,1599764494.381 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-09-10T19:01:34.385Z,1599764494.385 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2020-09-10T19:01:34.385Z,1599764494.385 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-09-10T19:01:34.385Z,1599764494.385 [Onboard](INFO): Join timeout helper Thread ID is 1097
2020-09-10T19:01:37.848Z,1599764497.848 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-10T19:01:37.848Z,1599764497.848 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-09-10T19:01:37.860Z,1599764497.860 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2020-09-10T19:01:37.861Z,1599764497.861 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-09-10T19:01:37.861Z,1599764497.861 [DataOverHttps](INFO): Join timeout helper Thread ID is 1098
2020-09-10T19:01:38.321Z,1599764498.321 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-10T19:01:38.326Z,1599764498.326 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-09-10T19:01:38.340Z,1599764498.340 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2020-09-10T19:01:38.341Z,1599764498.341 [logger ThreadHandler](INFO): Thread cancelled.
2020-09-10T19:01:38.341Z,1599764498.341 [logger](INFO): Join timeout helper Thread ID is 1099
2020-09-10T19:01:38.388Z,1599764498.388 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-10T19:01:38.388Z,1599764498.388 [logger ThreadHandler](INFO): Thread cancelled.
2020-09-10T19:01:38.400Z,1599764498.400 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2020-09-10T19:01:38.400Z,1599764498.400 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-09-10T19:01:38.401Z,1599764498.401 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2020-09-10T19:01:38.401Z,1599764498.401 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-09-10T19:01:38.401Z,1599764498.401 [controlThread](INFO): Join timeout helper Thread ID is 1100
2020-09-10T19:01:38.612Z,1599764498.612 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-10T19:01:38.612Z,1599764498.612 [controlThread](DEBUG): Uninitializing ControlThread
2020-09-10T19:01:38.612Z,1599764498.612 [AHRS_M2](INFO): Powering down
2020-09-10T19:01:38.684Z,1599764498.684 [NAL9602](INFO): Powering down
2020-09-10T19:01:38.685Z,1599764498.685 [RDI_Pathfinder](INFO): Powering down
2020-09-10T19:01:38.686Z,1599764498.686 [DAT](INFO): Powering down
2020-09-10T19:01:38.804Z,1599764498.804 [AMEcho](INFO): Powering down
2020-09-10T19:01:38.805Z,1599764498.805 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2020-09-10T19:01:38.806Z,1599764498.806 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2020-09-10T19:01:38.807Z,1599764498.807 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2020-09-10T19:01:38.807Z,1599764498.807 [MissionManager](INFO): Uninitializing Mission Default
2020-09-10T19:01:38.807Z,1599764498.807 [Default] Stopped
2020-09-10T19:01:38.807Z,1599764498.807 [Default](DEBUG): Aggregate::uninitialize Default
2020-09-10T19:01:38.808Z,1599764498.808 [Default:B.GoToSurface] Stopped
2020-09-10T19:01:38.808Z,1599764498.808 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-09-10T19:01:38.808Z,1599764498.808 [Default:CheckIn] Stopped
2020-09-10T19:01:38.808Z,1599764498.808 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-09-10T19:01:38.808Z,1599764498.808 [Default:CheckIn:C.Wait] Stopped
2020-09-10T19:01:38.808Z,1599764498.808 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-09-10T19:01:38.810Z,1599764498.810 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2020-09-10T19:01:38.811Z,1599764498.811 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2020-09-10T19:01:38.811Z,1599764498.811 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2020-09-10T19:01:38.811Z,1599764498.811 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2020-09-10T19:01:38.811Z,1599764498.811 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2020-09-10T19:01:38.812Z,1599764498.812 [BuoyancyServo](INFO): Powering down
2020-09-10T19:01:38.824Z,1599764498.824 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2020-09-10T19:01:38.824Z,1599764498.824 [ElevatorServo](INFO): Powering down
2020-09-10T19:01:38.825Z,1599764498.825 [MassServo](DEBUG): Uninitialize Mass Servo.
2020-09-10T19:01:38.825Z,1599764498.825 [MassServo](INFO): Powering down
2020-09-10T19:01:38.826Z,1599764498.826 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-09-10T19:01:38.826Z,1599764498.826 [RudderServo](INFO): Powering down
2020-09-10T19:01:38.827Z,1599764498.827 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2020-09-10T19:01:38.827Z,1599764498.827 [ThrusterServo](INFO): Powering down
2020-09-10T19:01:38.827Z,1599764498.827 [SBIT](DEBUG): Uninitialize SBIT Component.
2020-09-10T19:01:38.828Z,1599764498.828 [IBIT](DEBUG): Uninitialize IBIT Component.
2020-09-10T19:01:38.828Z,1599764498.828 [CBIT](DEBUG): Uninitialize CBIT Component.
2020-09-10T19:01:38.828Z,1599764498.828 [CBIT](DEBUG): Powering off loads.
2020-09-10T19:01:38.840Z,1599764498.840 [CBIT](DEBUG): Disabling WDT.
2020-09-10T19:01:38.852Z,1599764498.852 [CBIT](DEBUG): Opening all GF detection circuits.
2020-09-10T19:01:38.852Z,1599764498.852 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-09-10T19:01:38.949Z,1599764498.949 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-09-10T19:01:38.951Z,1599764498.951 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-09-10T19:01:38.957Z,1599764498.957 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-09-10T19:01:39.020Z,1599764499.020 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-09-10T19:01:39.024Z,1599764499.024 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-09-10T19:01:39.027Z,1599764499.027 [BackSeatDriver ThreadHandler](INFO): Thread cancelled.
2020-09-10T19:01:39.037Z,1599764499.037 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-09-10T19:01:39.111Z,1599764499.111 [logger ThreadHandler](INFO): Thread cancelled.