2020-01-17T02:05:07.210Z,1579226707.210 [Supervisor](DEBUG): Initializing supervisor.
2020-01-17T02:05:07.212Z,1579226707.212 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-01-17T02:05:07.213Z,1579226707.213 [SyncHandler](INFO): Protected caller Thread ID is 7382
2020-01-17T02:05:07.214Z,1579226707.214 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-01-17T02:05:07.215Z,1579226707.215 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-01-17T02:05:07.215Z,1579226707.215 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 7383
2020-01-17T02:05:07.218Z,1579226707.218 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-01-17T02:05:07.230Z,1579226707.230 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-01-17T02:05:07.231Z,1579226707.231 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-01-17T02:05:07.231Z,1579226707.231 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 7384
2020-01-17T02:05:07.232Z,1579226707.232 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-01-17T02:05:07.233Z,1579226707.233 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-01-17T02:05:07.234Z,1579226707.234 [logger ThreadHandler](INFO): Protected caller Thread ID is 7385
2020-01-17T02:05:07.235Z,1579226707.235 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-01-17T02:05:07.236Z,1579226707.236 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-01-17T02:05:07.237Z,1579226707.237 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-01-17T02:05:07.878Z,1579226707.878 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-01-17T02:05:07.879Z,1579226707.879 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-01-17T02:05:08.002Z,1579226708.002 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2020-01-17T02:05:08.003Z,1579226708.003 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-01-17T02:05:08.321Z,1579226708.321 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-01-17T02:05:08.322Z,1579226708.322 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-01-17T02:05:08.461Z,1579226708.461 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-01-17T02:05:08.462Z,1579226708.462 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-01-17T02:05:08.656Z,1579226708.656 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-01-17T02:05:08.656Z,1579226708.656 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-01-17T02:05:09.103Z,1579226709.103 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-01-17T02:05:09.103Z,1579226709.103 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-01-17T02:05:09.314Z,1579226709.314 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-01-17T02:05:09.315Z,1579226709.315 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-01-17T02:05:09.460Z,1579226709.460 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-01-17T02:05:09.460Z,1579226709.460 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-01-17T02:05:09.654Z,1579226709.654 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-01-17T02:05:09.654Z,1579226709.654 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-01-17T02:05:09.751Z,1579226709.751 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-01-17T02:05:09.751Z,1579226709.751 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-01-17T02:05:10.053Z,1579226710.053 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-01-17T02:05:10.053Z,1579226710.053 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-01-17T02:05:10.134Z,1579226710.134 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-01-17T02:05:10.238Z,1579226710.238 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-01-17T02:05:10.239Z,1579226710.239 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-01-17T02:05:10.881Z,1579226710.881 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-01-17T02:05:10.881Z,1579226710.881 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-01-17T02:05:11.291Z,1579226711.291 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-01-17T02:05:11.293Z,1579226711.293 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2020-01-17T02:05:11.294Z,1579226711.294 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2020-01-17T02:05:11.508Z,1579226711.508 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2020-01-17T02:05:11.610Z,1579226711.610 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2020-01-17T02:05:11.711Z,1579226711.711 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2020-01-17T02:05:11.938Z,1579226711.938 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-01-17T02:05:11.938Z,1579226711.938 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2020-01-17T02:05:12.024Z,1579226712.024 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2020-01-17T02:05:12.118Z,1579226712.118 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2020-01-17T02:05:12.218Z,1579226712.218 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2020-01-17T02:05:12.302Z,1579226712.302 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2020-01-17T02:05:12.411Z,1579226712.411 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/workSite.cfg
2020-01-17T02:05:12.505Z,1579226712.505 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2020-01-17T02:05:12.692Z,1579226712.692 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2020-01-17T02:05:13.094Z,1579226713.094 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/root/
2020-01-17T02:05:13.095Z,1579226713.095 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2020-01-17T02:05:13.101Z,1579226713.101 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-01-17T02:05:13.708Z,1579226713.708 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2020-01-17T02:05:13.713Z,1579226713.713 [AHRS_M2](INFO): created writer for : platform_orientation
2020-01-17T02:05:13.715Z,1579226713.715 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2020-01-17T02:05:13.720Z,1579226713.720 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2020-01-17T02:05:13.720Z,1579226713.720 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2020-01-17T02:05:13.725Z,1579226713.725 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2020-01-17T02:05:13.726Z,1579226713.726 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2020-01-17T02:05:13.731Z,1579226713.731 [AHRS_M2](INFO): created writer for : platform_roll_angle
2020-01-17T02:05:13.798Z,1579226713.798 [AHRS_M2] Loaded
2020-01-17T02:05:13.798Z,1579226713.798 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2020-01-17T02:05:13.878Z,1579226713.878 [DataOverHttps] Loaded
2020-01-17T02:05:13.879Z,1579226713.879 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-01-17T02:05:13.880Z,1579226713.880 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407684E0
2020-01-17T02:05:13.880Z,1579226713.880 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 7467
2020-01-17T02:05:13.903Z,1579226713.903 [DDM] Loaded
2020-01-17T02:05:13.903Z,1579226713.903 [ComponentRegistry](DEBUG): SyncComponent "DDM" handled in the control thread.
2020-01-17T02:05:13.915Z,1579226713.915 [Depth_Keller] Loaded
2020-01-17T02:05:13.916Z,1579226713.916 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-01-17T02:05:13.920Z,1579226713.920 [DropWeight] Loaded
2020-01-17T02:05:13.920Z,1579226713.920 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2020-01-17T02:05:13.979Z,1579226713.979 [DUSBL_Hydroid] Loaded
2020-01-17T02:05:13.979Z,1579226713.979 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2020-01-17T02:05:14.024Z,1579226714.024 [Micromodem] Loaded
2020-01-17T02:05:14.024Z,1579226714.024 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2020-01-17T02:05:14.116Z,1579226714.116 [NAL9602] Loaded
2020-01-17T02:05:14.117Z,1579226714.117 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-01-17T02:05:14.152Z,1579226714.152 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/voltage_now
2020-01-17T02:05:14.152Z,1579226714.152 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/current_now
2020-01-17T02:05:14.153Z,1579226714.153 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/charge_now
2020-01-17T02:05:14.153Z,1579226714.153 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/charge_full
2020-01-17T02:05:14.154Z,1579226714.154 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/voltage_now
2020-01-17T02:05:14.154Z,1579226714.154 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/current_now
2020-01-17T02:05:14.155Z,1579226714.155 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/charge_now
2020-01-17T02:05:14.155Z,1579226714.155 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/charge_full
2020-01-17T02:05:14.156Z,1579226714.156 [Onboard] Loaded
2020-01-17T02:05:14.156Z,1579226714.156 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2020-01-17T02:05:14.162Z,1579226714.162 [PowerOnly] Loaded
2020-01-17T02:05:14.162Z,1579226714.162 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2020-01-17T02:05:14.168Z,1579226714.168 [Radio_Surface] Loaded
2020-01-17T02:05:14.168Z,1579226714.168 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-01-17T02:05:14.169Z,1579226714.169 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407984E0
2020-01-17T02:05:14.170Z,1579226714.170 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 7468
2020-01-17T02:05:14.211Z,1579226714.211 [RDI_Pathfinder] Loaded
2020-01-17T02:05:14.211Z,1579226714.211 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2020-01-17T02:05:15.598Z,1579226715.598 [BPC1] Loaded
2020-01-17T02:05:15.599Z,1579226715.599 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-01-17T02:05:15.599Z,1579226715.599 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-01-17T02:05:15.599Z,1579226715.599 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-01-17T02:05:15.612Z,1579226715.612 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-01-17T02:05:15.613Z,1579226715.613 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-01-17T02:05:15.712Z,1579226715.712 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-01-17T02:05:15.712Z,1579226715.712 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-01-17T02:05:15.732Z,1579226715.732 [NavChart] Loaded
2020-01-17T02:05:15.732Z,1579226715.732 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-01-17T02:05:15.736Z,1579226715.736 [UniversalFixResidualReporter] Loaded
2020-01-17T02:05:15.736Z,1579226715.736 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-01-17T02:05:15.736Z,1579226715.736 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-01-17T02:05:15.737Z,1579226715.737 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-01-17T02:05:15.840Z,1579226715.840 [BuoyancyServo] Loaded
2020-01-17T02:05:15.840Z,1579226715.840 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-01-17T02:05:15.855Z,1579226715.855 [ElevatorServo] Loaded
2020-01-17T02:05:15.855Z,1579226715.855 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-01-17T02:05:15.869Z,1579226715.869 [MassServo] Loaded
2020-01-17T02:05:15.870Z,1579226715.870 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-01-17T02:05:15.884Z,1579226715.884 [RudderServo] Loaded
2020-01-17T02:05:15.884Z,1579226715.884 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-01-17T02:05:15.899Z,1579226715.899 [ThrusterServo] Loaded
2020-01-17T02:05:15.899Z,1579226715.899 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-01-17T02:05:15.899Z,1579226715.899 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-01-17T02:05:15.900Z,1579226715.900 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-01-17T02:05:16.144Z,1579226716.144 [CTD_NeilBrown] Loaded
2020-01-17T02:05:16.144Z,1579226716.144 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2020-01-17T02:05:16.145Z,1579226716.145 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408EC4E0
2020-01-17T02:05:16.145Z,1579226716.145 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 7469
2020-01-17T02:05:16.159Z,1579226716.159 [PAR_Licor] Loaded
2020-01-17T02:05:16.159Z,1579226716.159 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2020-01-17T02:05:16.201Z,1579226716.201 [WetLabsSeaOWL_UV_A] Loaded
2020-01-17T02:05:16.202Z,1579226716.202 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2020-01-17T02:05:16.203Z,1579226716.203 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 4091C4E0
2020-01-17T02:05:16.203Z,1579226716.203 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 7470
2020-01-17T02:05:16.203Z,1579226716.203 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-01-17T02:05:16.204Z,1579226716.204 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-01-17T02:05:16.521Z,1579226716.521 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-01-17T02:05:16.522Z,1579226716.522 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-01-17T02:05:16.560Z,1579226716.560 [DepthRateCalculator] Loaded
2020-01-17T02:05:16.561Z,1579226716.561 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-01-17T02:05:16.566Z,1579226716.566 [PitchRateCalculator] Loaded
2020-01-17T02:05:16.566Z,1579226716.566 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-01-17T02:05:16.578Z,1579226716.578 [SpeedCalculator] Loaded
2020-01-17T02:05:16.578Z,1579226716.578 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-01-17T02:05:16.598Z,1579226716.598 [TempGradientCalculator] Loaded
2020-01-17T02:05:16.599Z,1579226716.599 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-01-17T02:05:16.604Z,1579226716.604 [YawRateCalculator] Loaded
2020-01-17T02:05:16.604Z,1579226716.604 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-01-17T02:05:16.644Z,1579226716.644 [ElevatorOffsetCalculator] Loaded
2020-01-17T02:05:16.644Z,1579226716.644 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-01-17T02:05:16.644Z,1579226716.644 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-01-17T02:05:16.645Z,1579226716.645 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-01-17T02:05:16.770Z,1579226716.770 [SBIT](DEBUG): Construct Startup Built In Test.
2020-01-17T02:05:16.791Z,1579226716.791 [SBIT] Loaded
2020-01-17T02:05:16.791Z,1579226716.791 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-01-17T02:05:16.792Z,1579226716.792 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-01-17T02:05:16.804Z,1579226716.804 [IBIT] Loaded
2020-01-17T02:05:16.804Z,1579226716.804 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-01-17T02:05:16.807Z,1579226716.807 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-01-17T02:05:16.941Z,1579226716.941 [CBIT] Loaded
2020-01-17T02:05:16.941Z,1579226716.941 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-01-17T02:05:16.942Z,1579226716.942 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-01-17T02:05:16.942Z,1579226716.942 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-01-17T02:05:17.019Z,1579226717.019 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-01-17T02:05:17.019Z,1579226717.019 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-01-17T02:05:17.112Z,1579226717.112 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-01-17T02:05:17.112Z,1579226717.112 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-01-17T02:05:17.158Z,1579226717.158 [VerticalControl](DEBUG): Construct VerticalControl.
2020-01-17T02:05:17.239Z,1579226717.239 [VerticalControl] Loaded
2020-01-17T02:05:17.240Z,1579226717.240 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-01-17T02:05:17.240Z,1579226717.240 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-01-17T02:05:17.306Z,1579226717.306 [HorizontalControl] Loaded
2020-01-17T02:05:17.307Z,1579226717.307 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-01-17T02:05:17.307Z,1579226717.307 [SpeedControl](DEBUG): Construct SpeedControl.
2020-01-17T02:05:17.309Z,1579226717.309 [SpeedControl] Loaded
2020-01-17T02:05:17.309Z,1579226717.309 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-01-17T02:05:17.310Z,1579226717.310 [LoopControl](DEBUG): Construct LoopControl.
2020-01-17T02:05:17.310Z,1579226717.310 [LoopControl] Loaded
2020-01-17T02:05:17.311Z,1579226717.311 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-01-17T02:05:17.311Z,1579226717.311 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-01-17T02:05:17.312Z,1579226717.312 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-01-17T02:05:17.342Z,1579226717.342 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-01-17T02:05:17.346Z,1579226717.346 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-01-17T02:05:17.347Z,1579226717.347 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-01-17T02:05:17.353Z,1579226717.353 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-01-17T02:05:17.354Z,1579226717.354 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B034E0
2020-01-17T02:05:17.355Z,1579226717.355 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 7471
2020-01-17T02:05:17.359Z,1579226717.359 [Supervisor](INFO): Main Thread ID is 6780
2020-01-17T02:05:17.359Z,1579226717.359 [Supervisor](DEBUG): Running supervisor.
2020-01-17T02:05:17.360Z,1579226717.360 [CommandLine ThreadHandler](INFO): Handler Thread ID is 7472
2020-01-17T02:05:17.362Z,1579226717.362 [controlThread ThreadHandler](INFO): Handler Thread ID is 7473
2020-01-17T02:05:17.363Z,1579226717.363 [controlThread](DEBUG): Initializing ControlThread
2020-01-17T02:05:17.368Z,1579226717.368 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-01-17T02:05:17.368Z,1579226717.368 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-01-17T02:05:17.373Z,1579226717.373 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-01-17T02:05:17.373Z,1579226717.373 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-01-17T02:05:17.374Z,1579226717.374 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-01-17T02:05:17.374Z,1579226717.374 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-01-17T02:05:17.374Z,1579226717.374 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-01-17T02:05:17.375Z,1579226717.375 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-01-17T02:05:17.375Z,1579226717.375 [SBIT](INFO): Initialize SBIT Component.
2020-01-17T02:05:17.376Z,1579226717.376 [SBIT](IMPORTANT): git: 2019-12-03-52-gd057a2e
2020-01-17T02:05:17.376Z,1579226717.376 [SBIT](INFO): git hash: d057a2e09e1011d41925b307b61fea8285a57da1
2020-01-17T02:05:17.376Z,1579226717.376 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-01-17T02:05:17.377Z,1579226717.377 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #2 PREEMPT Wed May 15 08:34:03 PDT 2019
2020-01-17T02:05:17.378Z,1579226717.378 [SBIT](INFO): Beginning SBIT in 39.000000 seconds.
2020-01-17T02:05:17.379Z,1579226717.379 [IBIT](INFO): Initialize IBIT Component.
2020-01-17T02:05:17.380Z,1579226717.380 [CBIT](DEBUG): Initialize CBIT Component.
2020-01-17T02:05:17.381Z,1579226717.381 [logger ThreadHandler](INFO): Handler Thread ID is 7474
2020-01-17T02:05:17.393Z,1579226717.393 [CBIT](DEBUG): Initialized mux pins.
2020-01-17T02:05:17.393Z,1579226717.393 [CBIT](DEBUG): Initializing the watchdog timer.
2020-01-17T02:05:17.401Z,1579226717.401 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 7475
2020-01-17T02:05:17.402Z,1579226717.402 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2020-01-17T02:05:17.413Z,1579226717.413 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 7476
2020-01-17T02:05:17.417Z,1579226717.417 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2020-01-17T02:05:17.417Z,1579226717.417 [CBIT](DEBUG): Initializing heartbeat.
2020-01-17T02:05:17.425Z,1579226717.425 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 7477
2020-01-17T02:05:17.426Z,1579226717.426 [CTD_NeilBrown](INFO): Powering down
2020-01-17T02:05:17.453Z,1579226717.453 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 7478
2020-01-17T02:05:17.454Z,1579226717.454 [WetLabsSeaOWL_UV_A](INFO): Powering down
2020-01-17T02:05:17.477Z,1579226717.477 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 7479
2020-01-17T02:05:17.480Z,1579226717.480 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-01-17T02:05:17.480Z,1579226717.480 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-01-17T02:05:17.480Z,1579226717.480 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-01-17T02:05:17.481Z,1579226717.481 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-01-17T02:05:17.481Z,1579226717.481 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-01-17T02:05:17.481Z,1579226717.481 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-01-17T02:05:17.481Z,1579226717.481 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-01-17T02:05:17.481Z,1579226717.481 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-01-17T02:05:17.482Z,1579226717.482 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-01-17T02:05:17.482Z,1579226717.482 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-01-17T02:05:17.482Z,1579226717.482 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-01-17T02:05:17.482Z,1579226717.482 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-01-17T02:05:17.482Z,1579226717.482 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-01-17T02:05:17.482Z,1579226717.482 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-01-17T02:05:17.483Z,1579226717.483 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-01-17T02:05:17.483Z,1579226717.483 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-01-17T02:05:17.489Z,1579226717.489 [CBIT](DEBUG): Deactivating GF circuits.
2020-01-17T02:05:17.490Z,1579226717.490 [CBIT](DEBUG): Deactivating emergency mode.
2020-01-17T02:05:17.525Z,1579226717.525 [CBIT](DEBUG): Backplane powered.
2020-01-17T02:05:17.525Z,1579226717.525 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-01-17T02:05:17.527Z,1579226717.527 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-01-17T02:05:17.528Z,1579226717.528 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-01-17T02:05:17.528Z,1579226717.528 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-01-17T02:05:17.529Z,1579226717.529 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-01-17T02:05:17.539Z,1579226717.539 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-01-17T02:05:17.578Z,1579226717.578 [MissionManager](DEBUG):
2020-01-17T02:05:17.579Z,1579226717.579 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2020-01-17T02:05:17.650Z,1579226717.650 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2020-01-17T02:05:17.651Z,1579226717.651 [Default:A.Wait](DEBUG): Construct Wait.
2020-01-17T02:05:17.661Z,1579226717.661 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-01-17T02:05:17.695Z,1579226717.695 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-01-17T02:05:17.721Z,1579226717.721 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-01-17T02:05:17.746Z,1579226717.746 [Default:E.Execute](DEBUG): Construct Execute.
2020-01-17T02:05:17.750Z,1579226717.750 [MissionManager](DEBUG):
0
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
13
Burn on
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2020-01-17T02:05:17.761Z,1579226717.761 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,DDM,Depth_Keller,DropWeight,DUSBL_Hydroid,Micromodem,NAL9602,Onboard,PowerOnly,RDI_Pathfinder,BPC1,PAR_Licor,Depth_Keller,PAR_Licor,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-01-17T02:05:17.773Z,1579226717.773 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-01-17T02:05:17.817Z,1579226717.817 [Radio_Surface](INFO): Powering up
2020-01-17T02:05:17.818Z,1579226717.818 [DDM](INFO): Powering up
2020-01-17T02:05:17.818Z,1579226717.818 [DDM](DEBUG): Initializing DDM.
2020-01-17T02:05:17.843Z,1579226717.843 [DUSBL_Hydroid](INFO): Powering up
2020-01-17T02:05:17.843Z,1579226717.843 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2020-01-17T02:05:18.034Z,1579226718.034 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-01-17T02:05:18.041Z,1579226718.041 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-01-17T02:05:18.042Z,1579226718.042 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-01-17T02:05:18.049Z,1579226718.049 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-01-17T02:05:18.050Z,1579226718.050 [MassServo](DEBUG): Initializing EZServoServo.
2020-01-17T02:05:18.057Z,1579226718.057 [MassServo](DEBUG): Initializing MassServo.
2020-01-17T02:05:18.058Z,1579226718.058 [RudderServo](DEBUG): Initializing EZServoServo.
2020-01-17T02:05:18.065Z,1579226718.065 [RudderServo](DEBUG): Initializing RudderServo.
2020-01-17T02:05:18.066Z,1579226718.066 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-01-17T02:05:18.073Z,1579226718.073 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-01-17T02:05:18.192Z,1579226718.192 [Micromodem](INFO): Powering up
2020-01-17T02:05:18.193Z,1579226718.193 [Micromodem](DEBUG): Initializing Micromodem.
2020-01-17T02:05:18.953Z,1579226718.953 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2020-01-17T02:05:18.953Z,1579226718.953 [RudderServo](FAULT): Rudder failed to initialize
2020-01-17T02:05:18.953Z,1579226718.953 [RudderServo] Communications Fault, FailCount= 1
2020-01-17T02:05:18.953Z,1579226718.953 [RudderServo](ERROR): Communications Fault
2020-01-17T02:05:19.064Z,1579226719.064 [CBIT](ERROR): Communications Fault in component: RudderServo
2020-01-17T02:05:19.286Z,1579226719.286 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-01-17T02:05:19.286Z,1579226719.286 [RudderServo](INFO): Powering down
2020-01-17T02:05:19.940Z,1579226719.940 [RudderServo](DEBUG): Initializing EZServoServo.
2020-01-17T02:05:20.058Z,1579226720.058 [RudderServo](DEBUG): Initializing RudderServo.
2020-01-17T02:05:20.062Z,1579226720.062 [CBIT](INFO): Clearing failed state for component RudderServo
2020-01-17T02:05:20.062Z,1579226720.062 [RudderServo] No Fault, FailCount= 1
2020-01-17T02:05:23.175Z,1579226723.175 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33
2020-01-17T02:05:23.560Z,1579226723.560 [Micromodem](INFO): Nmea in: $CATMG,2020-01-17T02:05:23.095358Z,RTC,RTC*53
2020-01-17T02:05:23.560Z,1579226723.560 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2020-01-17T02:05:23.095358Z,RTC,RTC*53
2020-01-17T02:05:23.959Z,1579226723.959 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31
2020-01-17T02:05:23.959Z,1579226723.959 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31
2020-01-17T02:05:24.367Z,1579226724.367 [Micromodem](INFO): Nmea in: $CACFG,SRC,1*33
2020-01-17T02:05:24.367Z,1579226724.367 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64
2020-01-17T02:05:24.775Z,1579226724.775 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66
2020-01-17T02:05:24.776Z,1579226724.776 [Micromodem](INFO): Nmea out: $CCCFG,pwramp.txlevel,0*2F
2020-01-17T02:05:25.175Z,1579226725.175 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,0*2D
2020-01-17T02:05:25.175Z,1579226725.175 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E
2020-01-17T02:05:25.579Z,1579226725.579 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C
2020-01-17T02:05:25.579Z,1579226725.579 [Micromodem](INFO): Nmea out: $CCCFG,FC0,10000*46
2020-01-17T02:05:25.979Z,1579226725.979 [Micromodem](INFO): Nmea in: $CACFG,FC0,10000*44
2020-01-17T02:05:25.979Z,1579226725.979 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63
2020-01-17T02:05:26.395Z,1579226726.395 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61
2020-01-17T02:05:26.395Z,1579226726.395 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A
2020-01-17T02:05:26.765Z,1579226726.765 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38
2020-01-17T02:05:26.766Z,1579226726.766 [Micromodem](INFO): Nmea out: $CCCLK,2020,01,17,02,05,27*41
2020-01-17T02:05:27.176Z,1579226727.176 [Micromodem](INFO): Nmea in: $CACLK,2020,1,17,2,5,27*73
2020-01-17T02:05:27.177Z,1579226727.177 [Micromodem](INFO): Nmea in: $CATMS,0,2020-01-17T02:05:28Z*7C
2020-01-17T02:05:27.179Z,1579226727.179 [Micromodem](INFO): Nmea in: $CATMG,2020-01-17T02:05:28.027326Z,USER_CMD,RTC*19
2020-01-17T02:05:28.380Z,1579226728.380 [DDM](INFO): Dynamic Docking Module:!C REMUS Capture Rev 1.1
2020-01-17T02:05:31.244Z,1579226731.244 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2020-01-17T02:05:36.056Z,1579226736.056 [DUSBL_Hydroid](INFO): DUSBL Version:O
2020-01-17T02:05:44.136Z,1579226744.136 [NAL9602](INFO): Powering up NAL9602
2020-01-17T02:05:55.059Z,1579226755.059 [NAL9602](INFO): NAL9602 initialized
2020-01-17T02:05:57.171Z,1579226757.171 [SBIT](IMPORTANT): Beginning Startup BIT
2020-01-17T02:05:57.175Z,1579226757.175 [CBIT](IMPORTANT): Beginning ground fault scan
2020-01-17T02:05:57.483Z,1579226757.483 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-01-17T02:05:57.483Z,1579226757.483 [RDI_Pathfinder](ERROR): Failed to parse:
:RA, 0.00, 0.00, 0.00, 0.00
2020-01-17T02:06:04.863Z,1579226764.863 [CommandLine](IMPORTANT): got command strobe off
2020-01-17T02:06:04.863Z,1579226764.863 [CommandLine](IMPORTANT): Deactivating strobe
2020-01-17T02:06:08.240Z,1579226768.240 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.018628
CHAN A1 (24V): -0.028376
CHAN A2 (12V): -0.006749
CHAN A3 (5V): -0.001786
CHAN B0 (3.3V): 0.000653
CHAN B1 (3.15aV): -0.000202
CHAN B2 (3.15bV): 0.000069
CHAN B3 (GND): 0.002050
OPEN: 0.005041
Full Scale Calc: 4.765 mA, -1.589 mA
2020-01-17T02:06:50.852Z,1579226810.852 [SBIT](IMPORTANT): SBIT PASSED
2020-01-17T02:06:50.882Z,1579226810.882 [CommandLine](IMPORTANT): got command configSet list
2020-01-17T02:06:50.882Z,1579226810.882 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-01-17T02:06:50.883Z,1579226810.883 [CommandLine](IMPORTANT): DDM.verbosity=3 count;
2020-01-17T02:06:50.883Z,1579226810.883 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold=30 count;
2020-01-17T02:06:50.884Z,1579226810.884 [CommandLine](IMPORTANT): Micromodem.sendExpress=1 bool;
2020-01-17T02:06:50.884Z,1579226810.884 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=105 cubic_centimeter;
2020-01-17T02:06:50.884Z,1579226810.884 [CommandLine](IMPORTANT): VerticalControl.massDefault=-5 millimeter;
2020-01-17T02:06:51.303Z,1579226811.303 [MissionManager](IMPORTANT): Started mission Startup
2020-01-17T02:06:51.303Z,1579226811.303 [Startup] Running Loop=1
2020-01-17T02:06:51.304Z,1579226811.304 [Startup](DEBUG): Aggregate::initialize Startup
2020-01-17T02:06:51.304Z,1579226811.304 [Startup:A.GoToSurface] Running Loop=1
2020-01-17T02:06:51.304Z,1579226811.304 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-01-17T02:06:51.304Z,1579226811.304 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-01-17T02:06:51.305Z,1579226811.305 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-01-17T02:06:51.305Z,1579226811.305 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-01-17T02:06:51.306Z,1579226811.306 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-01-17T02:06:51.306Z,1579226811.306 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-01-17T02:06:51.307Z,1579226811.307 [Startup:StartupSatComms] Running Loop=1
2020-01-17T02:06:51.307Z,1579226811.307 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2020-01-17T02:06:51.307Z,1579226811.307 [Startup:StartupSatComms:A] Running Loop=1
2020-01-17T02:06:51.720Z,1579226811.720 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2020-01-17T02:07:48.871Z,1579226868.871 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004884
2020-01-17T02:07:51.449Z,1579226871.449 [Startup:StartupSatComms:A](INFO): Timed out from 2020-01-17T02:06:51.3Z
2020-01-17T02:07:51.449Z,1579226871.449 [Startup:StartupSatComms:A] Stopped
2020-01-17T02:07:51.449Z,1579226871.449 [Startup:StartupSatComms:B] Running Loop=1
2020-01-17T02:07:51.825Z,1579226871.825 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-01-17T02:08:00.664Z,1579226880.664 [DataOverHttps](INFO): Sending 2439 bytes from file Logs/20200117T015454/Courier0004.lzma
2020-01-17T02:08:02.666Z,1579226882.666 [DataOverHttps](INFO): Moved sent file to Logs/20200117T015454/Courier0004.lzma.bak
2020-01-17T02:08:02.667Z,1579226882.667 [DataOverHttps](INFO): SBD MOMSN=12196330
2020-01-17T02:08:17.676Z,1579226897.676 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2020-01-17T02:08:17.676Z,1579226897.676 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-17T02:08:17.686Z,1579226897.686 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-17T02:08:18.092Z,1579226898.092 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-17T02:08:18.092Z,1579226898.092 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2020-01-17T02:08:29.300Z,1579226909.300 [DataOverHttps](INFO): Sending 181 bytes from file Logs/20200117T020507/Courier0000.lzma
2020-01-17T02:08:29.422Z,1579226909.422 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2020-01-17T02:08:29.423Z,1579226909.423 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,32768,-32768,V
2020-01-17T02:08:31.306Z,1579226911.306 [DataOverHttps](INFO): Moved sent file to Logs/20200117T020507/Courier0000.lzma.bak
2020-01-17T02:08:31.306Z,1579226911.306 [DataOverHttps](INFO): SBD MOMSN=12196332
2020-01-17T02:08:51.658Z,1579226931.658 [Startup:StartupSatComms:B](INFO): Timed out from 2020-01-17T02:07:51.4Z
2020-01-17T02:08:51.658Z,1579226931.658 [Startup:StartupSatComms:B] Stopped
2020-01-17T02:08:51.659Z,1579226931.659 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2020-01-17T02:08:51.659Z,1579226931.659 [Startup:StartupSatComms] Stopped
2020-01-17T02:08:51.659Z,1579226931.659 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2020-01-17T02:08:51.659Z,1579226931.659 [Startup](INFO): Completed Startup
2020-01-17T02:08:51.660Z,1579226931.660 [MissionManager](INFO): Startup is completed.
2020-01-17T02:08:51.660Z,1579226931.660 [MissionManager](INFO): Uninitializing Mission Startup
2020-01-17T02:08:51.660Z,1579226931.660 [Startup] Stopped
2020-01-17T02:08:51.660Z,1579226931.660 [Startup](DEBUG): Aggregate::uninitialize Startup
2020-01-17T02:08:51.660Z,1579226931.660 [Startup:A.GoToSurface] Stopped
2020-01-17T02:08:51.660Z,1579226931.660 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-01-17T02:08:52.065Z,1579226932.065 [MissionManager](IMPORTANT): Started mission Default
2020-01-17T02:08:52.065Z,1579226932.065 [Default] Running Loop=1
2020-01-17T02:08:52.066Z,1579226932.066 [Default](DEBUG): Aggregate::initialize Default
2020-01-17T02:08:52.066Z,1579226932.066 [Default:B.GoToSurface] Running Loop=1
2020-01-17T02:08:52.066Z,1579226932.066 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-01-17T02:08:52.066Z,1579226932.066 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-01-17T02:08:52.066Z,1579226932.066 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-01-17T02:08:52.067Z,1579226932.067 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-01-17T02:08:52.067Z,1579226932.067 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-01-17T02:08:52.067Z,1579226932.067 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-01-17T02:08:52.067Z,1579226932.067 [Default:A.Wait] Running Loop=1
2020-01-17T02:08:52.067Z,1579226932.067 [Default:A.Wait](DEBUG): Initialize Wait Component.
2020-01-17T02:08:54.059Z,1579226934.059 [DataOverHttps](INFO): Sending 572 bytes from file Logs/20200117T015454/Express0005.lzma
2020-01-17T02:08:56.068Z,1579226936.068 [DataOverHttps](INFO): Moved sent file to Logs/20200117T015454/Express0005.lzma.bak
2020-01-17T02:08:56.069Z,1579226936.069 [DataOverHttps](INFO): SBD MOMSN=12196335
2020-01-17T02:09:05.370Z,1579226945.370 [Default:A.Wait](INFO): Done Waiting.
2020-01-17T02:09:05.370Z,1579226945.370 [Default:A.Wait] Stopped
2020-01-17T02:09:05.370Z,1579226945.370 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2020-01-17T02:09:05.756Z,1579226945.756 [Default:CheckIn] Running Loop=1
2020-01-17T02:09:05.756Z,1579226945.756 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-01-17T02:09:05.756Z,1579226945.756 [Default:CheckIn:Read_GPS] Running Loop=1
2020-01-17T02:09:06.255Z,1579226946.255 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-01-17T02:09:26.387Z,1579226966.387 [CommandLine](IMPORTANT): got command load ./Missions/Docked.xml
2020-01-17T02:09:26.387Z,1579226966.387 [MissionManager](INFO): Loading Mission: ./Missions/Docked.xml
2020-01-17T02:09:26.474Z,1579226966.474 [MissionManager](INFO): DefineArg Docked.MaxDockRange = 8.000000 m
2020-01-17T02:09:26.477Z,1579226966.477 [MissionManager](INFO): DefineArg Docked.DetachedTimeout = 5.000000 min
2020-01-17T02:09:26.481Z,1579226966.481 [MissionManager](INFO): DefineArg Docked.DockedTimeout = 30.000000 s
2020-01-17T02:09:26.484Z,1579226966.484 [MissionManager](INFO): DefineArg Docked.TransponderCode = 2.000000 count
2020-01-17T02:09:26.488Z,1579226966.488 [MissionManager](INFO): DefineArg Docked.TrackingUpdatePeriod = 60.000000 s
2020-01-17T02:09:26.491Z,1579226966.491 [MissionManager](INFO): DefineArg Docked.NumberOfPings = 1.000000 count
2020-01-17T02:09:26.495Z,1579226966.495 [MissionManager](INFO): DefineArg Docked.DepthDeadband = 1.500000 m
2020-01-17T02:09:26.498Z,1579226966.498 [MissionManager](INFO): DefineArg Docked.PitchLimit = 20.000000 arcdeg
2020-01-17T02:09:26.502Z,1579226966.502 [MissionManager](INFO): DefineArg Docked.MinDepth = 1.000000 m
2020-01-17T02:09:26.526Z,1579226966.526 [MissionManager](INFO): DefineArg Docked.MaxDepth = 215.000000 m
2020-01-17T02:09:26.527Z,1579226966.527 [Docked:A.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2020-01-17T02:09:26.803Z,1579226966.803 [Docked:E.Docked](DEBUG): Construct.
2020-01-17T02:09:26.830Z,1579226966.830 [Docked:G.Wait](DEBUG): Construct Wait.
2020-01-17T02:09:26.846Z,1579226966.846 [MissionManager](DEBUG):
Maximum range allowed from the dock.
8
Time duration limit for determining if the vehicle is detached from the dock.
5
Time duration limit for determining if the vehicle is ON the dock.
30
Transponder Address.
2
How long to wait between acoustic queries.
60
Number of pings requested each time.
1
How much vertical drift from the specified depth is allowed while docked.
1.5
Max vehicle pitch (+/-) while on dock.
20
Minimum depth while docked.
Maximum depth while docked.
Docked satisfied!
5
2020-01-17T02:09:26.846Z,1579226966.846 [CommandLine](IMPORTANT): Loaded ./Missions/Docked.xml
2020-01-17T02:09:34.429Z,1579226974.429 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-01-17T02:09:34.429Z,1579226974.429 [RDI_Pathfinder](ERROR): Failed to parse:
:TS9213470,35.0, -0.1, 0.0,1448.9, 0
2020-01-17T02:09:36.859Z,1579226976.859 [CommandLine](IMPORTANT): got command set Docked.DockedTimeout 30.000000 second
2020-01-17T02:09:40.442Z,1579226980.442 [CommandLine](IMPORTANT): got command run
2020-01-17T02:09:40.444Z,1579226980.444 [CommandLine](IMPORTANT): Running
2020-01-17T02:09:40.532Z,1579226980.532 [Default] Stopped
2020-01-17T02:09:40.532Z,1579226980.532 [Default](DEBUG): Aggregate::uninitialize Default
2020-01-17T02:09:40.532Z,1579226980.532 [Default:B.GoToSurface] Stopped
2020-01-17T02:09:40.532Z,1579226980.532 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-01-17T02:09:40.532Z,1579226980.532 [Default:CheckIn] Stopped
2020-01-17T02:09:40.532Z,1579226980.532 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-01-17T02:09:40.532Z,1579226980.532 [Default:CheckIn:Read_GPS] Stopped
2020-01-17T02:09:40.533Z,1579226980.533 [MissionManager](IMPORTANT): Started mission Docked
2020-01-17T02:09:40.533Z,1579226980.533 [Docked] Running Loop=1
2020-01-17T02:09:40.533Z,1579226980.533 [Docked](DEBUG): Aggregate::initialize Docked
2020-01-17T02:09:40.533Z,1579226980.533 [Docked:A.DepthEnvelope] Running Loop=1
2020-01-17T02:09:40.533Z,1579226980.533 [Docked:A.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2020-01-17T02:09:40.534Z,1579226980.534 [Docked:B.] Running Loop=1
2020-01-17T02:09:40.534Z,1579226980.534 [Docked:B.](INFO): Initializing TrackAcousticContact.
2020-01-17T02:09:40.534Z,1579226980.534 [Docked:C] Running Loop=1
2020-01-17T02:09:40.534Z,1579226980.534 [Docked:D] Running Loop=1
2020-01-17T02:09:40.534Z,1579226980.534 [Docked:E.Docked] Running Loop=1
2020-01-17T02:09:40.534Z,1579226980.534 [Docked:E.Docked](DEBUG): Initialize.
2020-01-17T02:09:40.535Z,1579226980.535 [Docked:E.Docked](INFO): Depth unspecified. Maintaining workSite beacon depth of 6.000000 m.
2020-01-17T02:09:40.536Z,1579226980.536 [Docked:D] Running Loop=1
2020-01-17T02:09:40.536Z,1579226980.536 [Docked:C] Running Loop=1
2020-01-17T02:09:40.536Z,1579226980.536 [Docked:B.] Running Loop=1
2020-01-17T02:09:40.537Z,1579226980.537 [Docked:A.DepthEnvelope] Running Loop=1
2020-01-17T02:09:48.617Z,1579226988.617 [RDI_Pathfinder](ERROR): Failed to parse:
:BI,-32768,-32768,-32768,-3276,-32768,-32768,-32768,V
2020-01-17T02:09:50.859Z,1579226990.859 [CommandLine](IMPORTANT): got command show stack
2020-01-17T02:09:50.859Z,1579226990.859 [CommandLine](IMPORTANT): Behavior Stack:
2020-01-17T02:09:50.859Z,1579226990.859 [Docked](IMPORTANT): Priority 0: Docked:A.DepthEnvelope
2020-01-17T02:09:50.859Z,1579226990.859 [Docked](IMPORTANT): Priority 1: Docked:B.
2020-01-17T02:09:50.860Z,1579226990.860 [Docked](IMPORTANT): Priority 2: Docked:C
2020-01-17T02:09:50.860Z,1579226990.860 [Docked](IMPORTANT): Priority 3: Docked:D
2020-01-17T02:09:50.860Z,1579226990.860 [Docked](IMPORTANT): Priority 4: Docked:E.Docked
2020-01-17T02:10:01.939Z,1579227001.939 [Docked:E.Docked](INFO): State switch to DETACHED. starting timer
2020-01-17T02:10:30.780Z,1579227030.780 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-01-17T02:10:30.780Z,1579227030.780 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,20011619223070,35.0, -0.1, 0.0,10
2020-01-17T02:10:40.564Z,1579227040.564 [Docked:B.](INFO): *** querying acoustic contact ***
2020-01-17T02:10:41.252Z,1579227041.252 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77
2020-01-17T02:10:41.657Z,1579227041.657 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A
2020-01-17T02:10:42.479Z,1579227042.479 [Micromodem](INFO): Nmea in: $SNTTA,,,,,021042.36*5E
2020-01-17T02:10:44.610Z,1579227044.610 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-01-17T02:10:45.061Z,1579227045.061 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2020-01-17T02:10:45.061Z,1579227045.061 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,-3278,-32768,V
2020-01-17T02:10:58.355Z,1579227058.355 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-01-17T02:10:58.378Z,1579227058.378 [RDI_Pathfinder](ERROR): only read -1 of 4 data items
2020-01-17T02:10:58.378Z,1579227058.378 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,
2020-01-17T02:11:04.691Z,1579227064.691 [CommandLine](IMPORTANT): got command show stack
2020-01-17T02:11:04.691Z,1579227064.691 [CommandLine](IMPORTANT): Behavior Stack:
2020-01-17T02:11:04.691Z,1579227064.691 [Docked](IMPORTANT): Priority 0: Docked:A.DepthEnvelope
2020-01-17T02:11:04.691Z,1579227064.691 [Docked](IMPORTANT): Priority 1: Docked:B.
2020-01-17T02:11:04.691Z,1579227064.691 [Docked](IMPORTANT): Priority 2: Docked:C
2020-01-17T02:11:04.692Z,1579227064.692 [Docked](IMPORTANT): Priority 3: Docked:D
2020-01-17T02:11:04.692Z,1579227064.692 [Docked](IMPORTANT): Priority 4: Docked:E.Docked
2020-01-17T02:11:18.698Z,1579227078.698 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2020-01-17T02:11:18.698Z,1579227078.698 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-17T02:11:18.779Z,1579227078.779 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-17T02:11:19.150Z,1579227079.150 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-17T02:11:19.150Z,1579227079.150 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2020-01-17T02:11:26.099Z,1579227086.099 [CommandLine](IMPORTANT): got command get DDM.cablePresent
2020-01-17T02:11:26.100Z,1579227086.100 [CommandLine](IMPORTANT): DDM.cablePresent 0 bool
2020-01-17T02:11:34.056Z,1579227094.056 [RDI_Pathfinder](ERROR): Failed to parse:
:BE,-32768,-32768,-32768,V
2020-01-17T02:11:40.920Z,1579227100.920 [Docked:B.](INFO): *** querying acoustic contact ***
2020-01-17T02:11:41.684Z,1579227101.684 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77
2020-01-17T02:11:42.104Z,1579227102.104 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A
2020-01-17T02:11:42.903Z,1579227102.903 [Micromodem](INFO): Nmea in: $SNTTA,,,,,021142.79*54
2020-01-17T02:11:45.315Z,1579227105.315 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-01-17T02:12:04.498Z,1579227124.498 [Docked:E.Docked](INFO): State switch to DETACHED. starting timer
2020-01-17T02:12:06.520Z,1579227126.520 [Docked:E.Docked](INFO): State switch to DETACHED. starting timer
2020-01-17T02:12:21.079Z,1579227141.079 [RDI_Pathfinder](ERROR): Failed to parse:
68,-32768,-32768,V
2020-01-17T02:12:37.292Z,1579227157.292 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2020-01-17T02:12:37.296Z,1579227157.296 [BPC1](INFO): Received data from all battery sticks.
2020-01-17T02:12:41.324Z,1579227161.324 [Docked:B.](INFO): *** querying acoustic contact ***
2020-01-17T02:12:42.103Z,1579227162.103 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77
2020-01-17T02:12:42.509Z,1579227162.509 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A
2020-01-17T02:12:43.322Z,1579227163.322 [Micromodem](INFO): Nmea in: $SNTTA,,,,,021243.21*5B
2020-01-17T02:12:45.738Z,1579227165.738 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-01-17T02:13:41.680Z,1579227221.680 [Docked:B.](INFO): *** querying acoustic contact ***
2020-01-17T02:13:42.456Z,1579227222.456 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77
2020-01-17T02:13:42.869Z,1579227222.869 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A
2020-01-17T02:13:43.667Z,1579227223.667 [Micromodem](INFO): Nmea in: $SNTTA,,,,,021343.56*5A
2020-01-17T02:13:46.105Z,1579227226.105 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-01-17T02:14:19.752Z,1579227259.752 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2020-01-17T02:14:19.752Z,1579227259.752 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-17T02:14:19.775Z,1579227259.775 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-17T02:14:20.159Z,1579227260.159 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-17T02:14:20.159Z,1579227260.159 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2020-01-17T02:14:37.129Z,1579227277.129 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2020-01-17T02:14:37.129Z,1579227277.129 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,-32768,-32768V
2020-01-17T02:14:42.083Z,1579227282.083 [Docked:B.](INFO): *** querying acoustic contact ***
2020-01-17T02:14:42.820Z,1579227282.820 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77
2020-01-17T02:14:43.234Z,1579227283.234 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A
2020-01-17T02:14:44.044Z,1579227284.044 [Micromodem](INFO): Nmea in: $SNTTA,,,,,021443.93*54
2020-01-17T02:14:46.446Z,1579227286.446 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-01-17T02:15:42.331Z,1579227342.331 [Docked:B.](INFO): *** querying acoustic contact ***
2020-01-17T02:15:43.099Z,1579227343.099 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77
2020-01-17T02:15:43.514Z,1579227343.514 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A
2020-01-17T02:15:44.315Z,1579227344.315 [Micromodem](INFO): Nmea in: $SNTTA,,,,,021544.21*5B
2020-01-17T02:15:46.435Z,1579227346.435 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-01-17T02:15:57.751Z,1579227357.751 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-01-17T02:15:57.751Z,1579227357.751 [NAL9602] Data Fault, FailCount= 1
2020-01-17T02:15:57.751Z,1579227357.751 [NAL9602](ERROR): Data Fault
2020-01-17T02:15:57.806Z,1579227357.806 [CBIT](ERROR): Data Fault in component: NAL9602
2020-01-17T02:15:58.156Z,1579227358.156 [NAL9602](INFO): Powering down
2020-01-17T02:15:58.998Z,1579227358.998 [CBIT](INFO): Clearing failed state for component NAL9602
2020-01-17T02:15:58.998Z,1579227358.998 [NAL9602] No Fault, FailCount= 1
2020-01-17T02:15:59.790Z,1579227359.790 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-01-17T02:15:59.790Z,1579227359.790 [RDI_Pathfinder](ERROR): Failed to parse:
:RA, 0.00, 0.00, 0.00, 0.00, :BI,-32768,-32768,-32768,-32768,V
2020-01-17T02:16:28.520Z,1579227388.520 [NAL9602](INFO): Powering up NAL9602
2020-01-17T02:16:39.440Z,1579227399.440 [NAL9602](INFO): NAL9602 initialized
2020-01-17T02:16:42.714Z,1579227402.714 [Docked:B.](INFO): *** querying acoustic contact ***
2020-01-17T02:16:43.472Z,1579227403.472 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77
2020-01-17T02:16:43.874Z,1579227403.874 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A
2020-01-17T02:16:44.679Z,1579227404.679 [Micromodem](INFO): Nmea in: $SNTTA,,,,,021644.58*56
2020-01-17T02:16:47.119Z,1579227407.119 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-01-17T02:17:20.812Z,1579227440.812 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2020-01-17T02:17:20.812Z,1579227440.812 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-17T02:17:20.832Z,1579227440.832 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-17T02:17:21.230Z,1579227441.230 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-17T02:17:21.230Z,1579227441.230 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2020-01-17T02:17:43.070Z,1579227463.070 [Docked:B.](INFO): *** querying acoustic contact ***
2020-01-17T02:17:43.820Z,1579227463.819 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77
2020-01-17T02:17:44.217Z,1579227464.217 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A
2020-01-17T02:17:45.049Z,1579227465.049 [Micromodem](INFO): Nmea in: $SNTTA,,,,,021744.93*50
2020-01-17T02:17:47.447Z,1579227467.447 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-01-17T02:18:43.103Z,1579227523.103 [Docked:B.](INFO): *** querying acoustic contact ***
2020-01-17T02:18:43.853Z,1579227523.853 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77
2020-01-17T02:18:44.257Z,1579227524.257 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A
2020-01-17T02:18:45.075Z,1579227525.075 [Micromodem](INFO): Nmea in: $SNTTA,,,,,021844.96*5A
2020-01-17T02:18:47.485Z,1579227527.485 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-01-17T02:19:18.234Z,1579227558.234 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2020-01-17T02:19:18.235Z,1579227558.235 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,-32768,-32768,
2020-01-17T02:19:42.065Z,1579227582.065 [RDI_Pathfinder](ERROR): Failed to parse:
:8,-32768,-32768,V
2020-01-17T02:19:43.289Z,1579227583.289 [Docked:B.](INFO): *** querying acoustic contact ***
2020-01-17T02:19:44.050Z,1579227584.050 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77
2020-01-17T02:19:44.445Z,1579227584.445 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A
2020-01-17T02:19:45.256Z,1579227585.256 [Micromodem](INFO): Nmea in: $SNTTA,,,,,021945.16*52
2020-01-17T02:19:47.678Z,1579227587.678 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-01-17T02:19:49.910Z,1579227589.910 [CommandLine](IMPORTANT): got command stop
2020-01-17T02:19:49.911Z,1579227589.911 [CommandLine](IMPORTANT): Scheduling is paused
2020-01-17T02:19:49.911Z,1579227589.911 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2020-01-17T02:19:50.130Z,1579227590.130 [MissionManager](INFO): MissionManager is completed.
2020-01-17T02:19:50.130Z,1579227590.130 [MissionManager](INFO): Uninitializing Mission Docked
2020-01-17T02:19:50.130Z,1579227590.130 [Docked] Stopped
2020-01-17T02:19:50.131Z,1579227590.131 [Docked](DEBUG): Aggregate::uninitialize Docked
2020-01-17T02:19:50.131Z,1579227590.131 [Docked:A.DepthEnvelope] Stopped
2020-01-17T02:19:50.131Z,1579227590.131 [Docked:A.DepthEnvelope](DEBUG): Uninitialize.
2020-01-17T02:19:50.131Z,1579227590.131 [Docked:B.] Stopped
2020-01-17T02:19:50.131Z,1579227590.131 [Docked:C] Stopped
2020-01-17T02:19:50.131Z,1579227590.131 [Docked:D] Stopped
2020-01-17T02:19:50.131Z,1579227590.131 [Docked:E.Docked] Stopped
2020-01-17T02:19:50.508Z,1579227590.508 [MissionManager](IMPORTANT): Started mission Default
2020-01-17T02:19:50.508Z,1579227590.508 [Default] Running Loop=1
2020-01-17T02:19:50.508Z,1579227590.508 [Default](DEBUG): Aggregate::initialize Default
2020-01-17T02:19:50.508Z,1579227590.508 [Default:B.GoToSurface] Running Loop=1
2020-01-17T02:19:50.508Z,1579227590.508 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-01-17T02:19:50.509Z,1579227590.509 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-01-17T02:19:50.509Z,1579227590.509 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-01-17T02:19:50.509Z,1579227590.509 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-01-17T02:19:50.510Z,1579227590.510 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-01-17T02:19:50.510Z,1579227590.510 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-01-17T02:19:50.511Z,1579227590.511 [Default:A.Wait] Running Loop=1
2020-01-17T02:19:50.511Z,1579227590.511 [Default:A.Wait](DEBUG): Initialize Wait Component.
2020-01-17T02:20:03.571Z,1579227603.571 [Default:A.Wait](INFO): Done Waiting.
2020-01-17T02:20:03.571Z,1579227603.571 [Default:A.Wait] Stopped
2020-01-17T02:20:03.571Z,1579227603.571 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2020-01-17T02:20:03.968Z,1579227603.968 [Default:CheckIn] Running Loop=1
2020-01-17T02:20:03.968Z,1579227603.968 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-01-17T02:20:03.968Z,1579227603.968 [Default:CheckIn:Read_GPS] Running Loop=1
2020-01-17T02:20:21.724Z,1579227621.724 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2020-01-17T02:20:21.724Z,1579227621.724 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-17T02:20:21.777Z,1579227621.777 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-17T02:20:22.173Z,1579227622.173 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-17T02:20:22.173Z,1579227622.173 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2020-01-17T02:22:05.535Z,1579227725.535 [CommandLine](IMPORTANT): got command restart application
2020-01-17T02:22:06.541Z,1579227726.541 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-17T02:22:06.541Z,1579227726.541 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:22:06.689Z,1579227726.689 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2020-01-17T02:22:06.689Z,1579227726.689 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:22:06.690Z,1579227726.690 [CommandLine](INFO): Join timeout helper Thread ID is 7541
2020-01-17T02:22:06.701Z,1579227726.701 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2020-01-17T02:22:06.701Z,1579227726.701 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:22:06.701Z,1579227726.701 [NavChartDb](INFO): Join timeout helper Thread ID is 7542
2020-01-17T02:22:06.781Z,1579227726.781 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-17T02:22:06.781Z,1579227726.781 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:22:06.793Z,1579227726.793 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2020-01-17T02:22:06.793Z,1579227726.793 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:22:06.793Z,1579227726.793 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 7543
2020-01-17T02:22:06.953Z,1579227726.953 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-17T02:22:06.953Z,1579227726.953 [WetLabsSeaOWL_UV_A](INFO): Powering down
2020-01-17T02:22:06.954Z,1579227726.954 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:22:06.969Z,1579227726.969 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2020-01-17T02:22:06.969Z,1579227726.969 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:22:06.969Z,1579227726.969 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 7544
2020-01-17T02:22:07.073Z,1579227727.073 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-17T02:22:07.073Z,1579227727.073 [CTD_NeilBrown](INFO): Powering down
2020-01-17T02:22:07.085Z,1579227727.085 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:22:07.087Z,1579227727.087 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2020-01-17T02:22:07.087Z,1579227727.087 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:22:07.088Z,1579227727.088 [Radio_Surface](INFO): Join timeout helper Thread ID is 7545
2020-01-17T02:22:07.273Z,1579227727.273 [Radio_Surface](INFO): Powering down
2020-01-17T02:22:07.274Z,1579227727.274 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-17T02:22:07.274Z,1579227727.274 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:22:07.294Z,1579227727.294 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2020-01-17T02:22:07.294Z,1579227727.294 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:22:07.294Z,1579227727.294 [DataOverHttps](INFO): Join timeout helper Thread ID is 7546
2020-01-17T02:22:10.284Z,1579227730.284 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-17T02:22:10.287Z,1579227730.287 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:22:10.290Z,1579227730.290 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2020-01-17T02:22:10.290Z,1579227730.290 [logger ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:22:10.290Z,1579227730.290 [logger](INFO): Join timeout helper Thread ID is 7547
2020-01-17T02:22:10.309Z,1579227730.309 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-17T02:22:10.309Z,1579227730.309 [logger ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:22:10.329Z,1579227730.329 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2020-01-17T02:22:10.330Z,1579227730.330 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:22:10.330Z,1579227730.330 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2020-01-17T02:22:10.330Z,1579227730.330 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:22:10.330Z,1579227730.330 [controlThread](INFO): Join timeout helper Thread ID is 7548
2020-01-17T02:22:10.373Z,1579227730.373 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-17T02:22:10.374Z,1579227730.374 [controlThread](DEBUG): Uninitializing ControlThread
2020-01-17T02:22:10.376Z,1579227730.376 [AHRS_M2](INFO): Powering down
2020-01-17T02:22:10.449Z,1579227730.449 [DDM](INFO): Powering down
2020-01-17T02:22:10.537Z,1579227730.537 [DUSBL_Hydroid](INFO): Powering down
2020-01-17T02:22:10.609Z,1579227730.609 [Micromodem](INFO): Powering down
2020-01-17T02:22:10.705Z,1579227730.705 [NAL9602](INFO): Powering down
2020-01-17T02:22:10.777Z,1579227730.777 [RDI_Pathfinder](INFO): Powering down
2020-01-17T02:22:10.778Z,1579227730.778 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2020-01-17T02:22:10.779Z,1579227730.779 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2020-01-17T02:22:10.780Z,1579227730.780 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2020-01-17T02:22:10.780Z,1579227730.780 [MissionManager](INFO): Uninitializing Mission Default
2020-01-17T02:22:10.780Z,1579227730.780 [Default] Stopped
2020-01-17T02:22:10.780Z,1579227730.780 [Default](DEBUG): Aggregate::uninitialize Default
2020-01-17T02:22:10.780Z,1579227730.780 [Default:B.GoToSurface] Stopped
2020-01-17T02:22:10.780Z,1579227730.780 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-01-17T02:22:10.780Z,1579227730.780 [Default:CheckIn] Stopped
2020-01-17T02:22:10.781Z,1579227730.781 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-01-17T02:22:10.781Z,1579227730.781 [Default:CheckIn:Read_GPS] Stopped
2020-01-17T02:22:10.783Z,1579227730.783 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2020-01-17T02:22:10.783Z,1579227730.783 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2020-01-17T02:22:10.784Z,1579227730.784 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2020-01-17T02:22:10.784Z,1579227730.784 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2020-01-17T02:22:10.784Z,1579227730.784 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2020-01-17T02:22:10.784Z,1579227730.784 [BuoyancyServo](INFO): Powering down
2020-01-17T02:22:10.797Z,1579227730.797 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2020-01-17T02:22:10.797Z,1579227730.797 [ElevatorServo](INFO): Powering down
2020-01-17T02:22:10.798Z,1579227730.798 [MassServo](DEBUG): Uninitialize Mass Servo.
2020-01-17T02:22:10.798Z,1579227730.798 [MassServo](INFO): Powering down
2020-01-17T02:22:10.799Z,1579227730.799 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-01-17T02:22:10.799Z,1579227730.799 [RudderServo](INFO): Powering down
2020-01-17T02:22:10.799Z,1579227730.799 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2020-01-17T02:22:10.799Z,1579227730.799 [ThrusterServo](INFO): Powering down
2020-01-17T02:22:10.800Z,1579227730.800 [SBIT](DEBUG): Uninitialize SBIT Component.
2020-01-17T02:22:10.800Z,1579227730.800 [IBIT](DEBUG): Uninitialize IBIT Component.
2020-01-17T02:22:10.801Z,1579227730.801 [CBIT](DEBUG): Uninitialize CBIT Component.
2020-01-17T02:22:10.801Z,1579227730.801 [CBIT](DEBUG): Powering off loads.
2020-01-17T02:22:10.813Z,1579227730.813 [CBIT](DEBUG): Disabling WDT.
2020-01-17T02:22:10.825Z,1579227730.825 [CBIT](DEBUG): Opening all GF detection circuits.
2020-01-17T02:22:10.826Z,1579227730.826 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:22:10.935Z,1579227730.935 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:22:10.945Z,1579227730.945 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:22:11.061Z,1579227731.061 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:22:11.064Z,1579227731.064 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:22:11.138Z,1579227731.138 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:22:11.198Z,1579227731.198 [logger ThreadHandler](INFO): Thread cancelled.