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.