2020-01-13T20:57:10.955Z,1578949030.955 [Supervisor](DEBUG): Initializing supervisor. 2020-01-13T20:57:10.958Z,1578949030.958 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2020-01-13T20:57:10.958Z,1578949030.958 [SyncHandler](INFO): Protected caller Thread ID is 2232 2020-01-13T20:57:10.959Z,1578949030.959 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2020-01-13T20:57:10.960Z,1578949030.960 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2020-01-13T20:57:10.960Z,1578949030.960 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2233 2020-01-13T20:57:10.963Z,1578949030.963 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2020-01-13T20:57:10.975Z,1578949030.975 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2020-01-13T20:57:10.976Z,1578949030.976 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2020-01-13T20:57:10.976Z,1578949030.976 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2234 2020-01-13T20:57:10.977Z,1578949030.977 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2020-01-13T20:57:10.978Z,1578949030.978 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2020-01-13T20:57:10.978Z,1578949030.978 [logger ThreadHandler](INFO): Protected caller Thread ID is 2235 2020-01-13T20:57:10.980Z,1578949030.980 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2020-01-13T20:57:10.980Z,1578949030.980 [Supervisor](INFO): Looking for Config files in directory: Config/ 2020-01-13T20:57:10.982Z,1578949030.982 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2020-01-13T20:57:11.404Z,1578949031.404 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2020-01-13T20:57:11.405Z,1578949031.405 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2020-01-13T20:57:11.499Z,1578949031.499 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2020-01-13T20:57:11.499Z,1578949031.499 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2020-01-13T20:57:11.798Z,1578949031.798 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2020-01-13T20:57:11.799Z,1578949031.799 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2020-01-13T20:57:11.932Z,1578949031.932 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2020-01-13T20:57:11.933Z,1578949031.933 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2020-01-13T20:57:12.113Z,1578949032.113 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2020-01-13T20:57:12.114Z,1578949032.114 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2020-01-13T20:57:12.541Z,1578949032.541 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2020-01-13T20:57:12.541Z,1578949032.541 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2020-01-13T20:57:12.744Z,1578949032.744 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2020-01-13T20:57:12.744Z,1578949032.744 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2020-01-13T20:57:12.883Z,1578949032.883 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2020-01-13T20:57:12.883Z,1578949032.883 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2020-01-13T20:57:13.062Z,1578949033.062 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2020-01-13T20:57:13.062Z,1578949033.062 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2020-01-13T20:57:13.155Z,1578949033.155 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2020-01-13T20:57:13.155Z,1578949033.155 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2020-01-13T20:57:13.442Z,1578949033.442 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2020-01-13T20:57:13.443Z,1578949033.443 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2020-01-13T20:57:13.521Z,1578949033.521 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2020-01-13T20:57:13.621Z,1578949033.621 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2020-01-13T20:57:13.622Z,1578949033.622 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2020-01-13T20:57:14.235Z,1578949034.235 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2020-01-13T20:57:14.235Z,1578949034.235 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2020-01-13T20:57:14.629Z,1578949034.629 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2020-01-13T20:57:14.631Z,1578949034.631 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/ 2020-01-13T20:57:14.632Z,1578949034.632 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg 2020-01-13T20:57:14.828Z,1578949034.828 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg 2020-01-13T20:57:14.929Z,1578949034.929 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg 2020-01-13T20:57:15.023Z,1578949035.023 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg 2020-01-13T20:57:15.243Z,1578949035.243 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2020-01-13T20:57:15.243Z,1578949035.243 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg 2020-01-13T20:57:15.325Z,1578949035.325 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg 2020-01-13T20:57:15.415Z,1578949035.415 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg 2020-01-13T20:57:15.514Z,1578949035.514 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg 2020-01-13T20:57:15.594Z,1578949035.594 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg 2020-01-13T20:57:15.700Z,1578949035.700 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg 2020-01-13T20:57:15.875Z,1578949035.875 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg 2020-01-13T20:57:16.053Z,1578949036.053 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/root/ 2020-01-13T20:57:16.053Z,1578949036.053 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2020-01-13T20:57:16.074Z,1578949036.074 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2020-01-13T20:57:16.857Z,1578949036.857 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation 2020-01-13T20:57:16.862Z,1578949036.862 [AHRS_M2](INFO): created writer for : platform_orientation 2020-01-13T20:57:16.864Z,1578949036.864 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation 2020-01-13T20:57:16.869Z,1578949036.869 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation 2020-01-13T20:57:16.869Z,1578949036.869 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle 2020-01-13T20:57:16.874Z,1578949036.874 [AHRS_M2](INFO): created writer for : platform_pitch_angle 2020-01-13T20:57:16.875Z,1578949036.875 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle 2020-01-13T20:57:16.891Z,1578949036.891 [AHRS_M2](INFO): created writer for : platform_roll_angle 2020-01-13T20:57:16.996Z,1578949036.996 [AHRS_M2] Loaded 2020-01-13T20:57:16.996Z,1578949036.996 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2020-01-13T20:57:17.201Z,1578949037.201 [DataOverHttps] Loaded 2020-01-13T20:57:17.201Z,1578949037.201 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2020-01-13T20:57:17.202Z,1578949037.202 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4076F4E0 2020-01-13T20:57:17.203Z,1578949037.203 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 2314 2020-01-13T20:57:17.226Z,1578949037.226 [DDM] Loaded 2020-01-13T20:57:17.226Z,1578949037.226 [ComponentRegistry](DEBUG): SyncComponent "DDM" handled in the control thread. 2020-01-13T20:57:17.239Z,1578949037.239 [Depth_Keller] Loaded 2020-01-13T20:57:17.239Z,1578949037.239 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2020-01-13T20:57:17.243Z,1578949037.243 [DropWeight] Loaded 2020-01-13T20:57:17.243Z,1578949037.243 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2020-01-13T20:57:17.302Z,1578949037.302 [DUSBL_Hydroid] Loaded 2020-01-13T20:57:17.302Z,1578949037.302 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread. 2020-01-13T20:57:17.347Z,1578949037.347 [Micromodem] Loaded 2020-01-13T20:57:17.347Z,1578949037.347 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread. 2020-01-13T20:57:17.439Z,1578949037.439 [NAL9602] Loaded 2020-01-13T20:57:17.439Z,1578949037.439 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2020-01-13T20:57:17.475Z,1578949037.475 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/voltage_now 2020-01-13T20:57:17.475Z,1578949037.475 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/current_now 2020-01-13T20:57:17.476Z,1578949037.476 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/charge_now 2020-01-13T20:57:17.476Z,1578949037.476 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/charge_full 2020-01-13T20:57:17.477Z,1578949037.477 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/voltage_now 2020-01-13T20:57:17.478Z,1578949037.478 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/current_now 2020-01-13T20:57:17.478Z,1578949037.478 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/charge_now 2020-01-13T20:57:17.478Z,1578949037.478 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/charge_full 2020-01-13T20:57:17.479Z,1578949037.479 [Onboard] Loaded 2020-01-13T20:57:17.479Z,1578949037.479 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2020-01-13T20:57:17.484Z,1578949037.484 [PowerOnly] Loaded 2020-01-13T20:57:17.485Z,1578949037.485 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread. 2020-01-13T20:57:17.491Z,1578949037.491 [Radio_Surface] Loaded 2020-01-13T20:57:17.491Z,1578949037.491 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2020-01-13T20:57:17.492Z,1578949037.492 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4079F4E0 2020-01-13T20:57:17.492Z,1578949037.492 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2315 2020-01-13T20:57:17.534Z,1578949037.534 [RDI_Pathfinder] Loaded 2020-01-13T20:57:17.534Z,1578949037.534 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread. 2020-01-13T20:57:18.945Z,1578949038.945 [BPC1] Loaded 2020-01-13T20:57:18.945Z,1578949038.945 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2020-01-13T20:57:18.946Z,1578949038.946 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2020-01-13T20:57:18.946Z,1578949038.946 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2020-01-13T20:57:18.959Z,1578949038.959 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2020-01-13T20:57:18.960Z,1578949038.960 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2020-01-13T20:57:19.060Z,1578949039.060 [DeadReckonUsingMultipleVelocitySources] Loaded 2020-01-13T20:57:19.060Z,1578949039.060 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2020-01-13T20:57:19.079Z,1578949039.079 [NavChart] Loaded 2020-01-13T20:57:19.080Z,1578949039.080 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2020-01-13T20:57:19.083Z,1578949039.083 [UniversalFixResidualReporter] Loaded 2020-01-13T20:57:19.084Z,1578949039.084 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2020-01-13T20:57:19.084Z,1578949039.084 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2020-01-13T20:57:19.085Z,1578949039.085 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2020-01-13T20:57:19.291Z,1578949039.291 [BuoyancyServo] Loaded 2020-01-13T20:57:19.291Z,1578949039.291 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2020-01-13T20:57:19.318Z,1578949039.318 [ElevatorServo] Loaded 2020-01-13T20:57:19.319Z,1578949039.319 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2020-01-13T20:57:19.345Z,1578949039.345 [MassServo] Loaded 2020-01-13T20:57:19.345Z,1578949039.345 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2020-01-13T20:57:19.372Z,1578949039.372 [RudderServo] Loaded 2020-01-13T20:57:19.372Z,1578949039.372 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2020-01-13T20:57:19.404Z,1578949039.404 [ThrusterServo] Loaded 2020-01-13T20:57:19.405Z,1578949039.405 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2020-01-13T20:57:19.405Z,1578949039.405 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2020-01-13T20:57:19.406Z,1578949039.406 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2020-01-13T20:57:19.857Z,1578949039.857 [CTD_NeilBrown] Loaded 2020-01-13T20:57:19.857Z,1578949039.857 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2020-01-13T20:57:19.858Z,1578949039.858 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408F34E0 2020-01-13T20:57:19.858Z,1578949039.858 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 2319 2020-01-13T20:57:19.872Z,1578949039.872 [PAR_Licor] Loaded 2020-01-13T20:57:19.872Z,1578949039.872 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2020-01-13T20:57:19.947Z,1578949039.947 [WetLabsSeaOWL_UV_A] Loaded 2020-01-13T20:57:19.948Z,1578949039.948 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread. 2020-01-13T20:57:19.949Z,1578949039.949 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 409234E0 2020-01-13T20:57:19.949Z,1578949039.949 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 2320 2020-01-13T20:57:19.950Z,1578949039.950 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2020-01-13T20:57:19.950Z,1578949039.950 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2020-01-13T20:57:20.405Z,1578949040.405 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2020-01-13T20:57:20.405Z,1578949040.405 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2020-01-13T20:57:20.461Z,1578949040.461 [DepthRateCalculator] Loaded 2020-01-13T20:57:20.461Z,1578949040.461 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2020-01-13T20:57:20.467Z,1578949040.467 [PitchRateCalculator] Loaded 2020-01-13T20:57:20.467Z,1578949040.467 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2020-01-13T20:57:20.487Z,1578949040.487 [SpeedCalculator] Loaded 2020-01-13T20:57:20.487Z,1578949040.487 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2020-01-13T20:57:20.516Z,1578949040.516 [TempGradientCalculator] Loaded 2020-01-13T20:57:20.516Z,1578949040.516 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2020-01-13T20:57:20.529Z,1578949040.529 [YawRateCalculator] Loaded 2020-01-13T20:57:20.530Z,1578949040.530 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2020-01-13T20:57:20.585Z,1578949040.585 [ElevatorOffsetCalculator] Loaded 2020-01-13T20:57:20.585Z,1578949040.585 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2020-01-13T20:57:20.586Z,1578949040.586 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2020-01-13T20:57:20.586Z,1578949040.586 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2020-01-13T20:57:20.792Z,1578949040.792 [SBIT](DEBUG): Construct Startup Built In Test. 2020-01-13T20:57:20.822Z,1578949040.822 [SBIT] Loaded 2020-01-13T20:57:20.822Z,1578949040.822 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2020-01-13T20:57:20.823Z,1578949040.823 [IBIT](DEBUG): Construct Initiated Built In Test. 2020-01-13T20:57:20.843Z,1578949040.843 [IBIT] Loaded 2020-01-13T20:57:20.843Z,1578949040.843 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2020-01-13T20:57:20.846Z,1578949040.846 [CBIT](DEBUG): Construct Continuous Built In Test. 2020-01-13T20:57:21.118Z,1578949041.118 [CBIT] Loaded 2020-01-13T20:57:21.118Z,1578949041.118 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2020-01-13T20:57:21.118Z,1578949041.118 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2020-01-13T20:57:21.119Z,1578949041.119 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2020-01-13T20:57:21.309Z,1578949041.309 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2020-01-13T20:57:21.310Z,1578949041.310 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2020-01-13T20:57:21.502Z,1578949041.502 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2020-01-13T20:57:21.502Z,1578949041.502 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2020-01-13T20:57:21.597Z,1578949041.597 [VerticalControl](DEBUG): Construct VerticalControl. 2020-01-13T20:57:21.775Z,1578949041.775 [VerticalControl] Loaded 2020-01-13T20:57:21.775Z,1578949041.775 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2020-01-13T20:57:21.776Z,1578949041.776 [HorizontalControl](DEBUG): Construct HorizontalControl. 2020-01-13T20:57:21.936Z,1578949041.936 [HorizontalControl] Loaded 2020-01-13T20:57:21.937Z,1578949041.937 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2020-01-13T20:57:21.938Z,1578949041.938 [SpeedControl](DEBUG): Construct SpeedControl. 2020-01-13T20:57:21.939Z,1578949041.939 [SpeedControl] Loaded 2020-01-13T20:57:21.940Z,1578949041.940 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2020-01-13T20:57:21.940Z,1578949041.940 [LoopControl](DEBUG): Construct LoopControl. 2020-01-13T20:57:21.953Z,1578949041.953 [LoopControl] Loaded 2020-01-13T20:57:21.953Z,1578949041.953 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2020-01-13T20:57:21.953Z,1578949041.953 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2020-01-13T20:57:21.954Z,1578949041.954 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2020-01-13T20:57:22.010Z,1578949042.010 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2020-01-13T20:57:22.018Z,1578949042.018 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2020-01-13T20:57:22.019Z,1578949042.019 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2020-01-13T20:57:22.026Z,1578949042.026 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2020-01-13T20:57:22.027Z,1578949042.027 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B024E0 2020-01-13T20:57:22.027Z,1578949042.027 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2323 2020-01-13T20:57:22.032Z,1578949042.032 [Supervisor](INFO): Main Thread ID is 2231 2020-01-13T20:57:22.032Z,1578949042.032 [Supervisor](DEBUG): Running supervisor. 2020-01-13T20:57:22.032Z,1578949042.032 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2324 2020-01-13T20:57:22.035Z,1578949042.035 [controlThread ThreadHandler](INFO): Handler Thread ID is 2325 2020-01-13T20:57:22.035Z,1578949042.035 [controlThread](DEBUG): Initializing ControlThread 2020-01-13T20:57:22.044Z,1578949042.044 [NavChart](DEBUG): Initialize NavChart Navigation. 2020-01-13T20:57:22.044Z,1578949042.044 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2020-01-13T20:57:22.049Z,1578949042.049 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2020-01-13T20:57:22.049Z,1578949042.049 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2020-01-13T20:57:22.050Z,1578949042.050 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2020-01-13T20:57:22.050Z,1578949042.050 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2020-01-13T20:57:22.051Z,1578949042.051 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2020-01-13T20:57:22.051Z,1578949042.051 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2020-01-13T20:57:22.051Z,1578949042.051 [SBIT](INFO): Initialize SBIT Component. 2020-01-13T20:57:22.052Z,1578949042.052 [SBIT](IMPORTANT): git: 2019-12-03-34-g1420f60 2020-01-13T20:57:22.052Z,1578949042.052 [SBIT](INFO): git hash: 1420f6075bfd9e2317cf67bc08ebc33a04e592a5 2020-01-13T20:57:22.052Z,1578949042.052 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2020-01-13T20:57:22.054Z,1578949042.054 [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-13T20:57:22.055Z,1578949042.055 [SBIT](INFO): Beginning SBIT in 39.000000 seconds. 2020-01-13T20:57:22.055Z,1578949042.055 [IBIT](INFO): Initialize IBIT Component. 2020-01-13T20:57:22.056Z,1578949042.056 [CBIT](DEBUG): Initialize CBIT Component. 2020-01-13T20:57:22.070Z,1578949042.070 [CBIT](DEBUG): Initialized mux pins. 2020-01-13T20:57:22.070Z,1578949042.070 [CBIT](DEBUG): Initializing the watchdog timer. 2020-01-13T20:57:22.077Z,1578949042.077 [logger ThreadHandler](INFO): Handler Thread ID is 2326 2020-01-13T20:57:22.101Z,1578949042.101 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2020-01-13T20:57:22.101Z,1578949042.101 [CBIT](DEBUG): Initializing heartbeat. 2020-01-13T20:57:22.113Z,1578949042.113 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 2327 2020-01-13T20:57:22.114Z,1578949042.114 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2020-01-13T20:57:22.129Z,1578949042.129 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2328 2020-01-13T20:57:22.145Z,1578949042.145 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 2329 2020-01-13T20:57:22.146Z,1578949042.146 [CTD_NeilBrown](INFO): Powering down 2020-01-13T20:57:22.173Z,1578949042.173 [CBIT](DEBUG): Deactivating GF circuits. 2020-01-13T20:57:22.173Z,1578949042.173 [CBIT](DEBUG): Deactivating emergency mode. 2020-01-13T20:57:22.185Z,1578949042.185 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 2330 2020-01-13T20:57:22.186Z,1578949042.186 [WetLabsSeaOWL_UV_A](INFO): Powering down 2020-01-13T20:57:22.209Z,1578949042.209 [CBIT](DEBUG): Backplane powered. 2020-01-13T20:57:22.209Z,1578949042.209 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2020-01-13T20:57:22.211Z,1578949042.211 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2020-01-13T20:57:22.211Z,1578949042.211 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2020-01-13T20:57:22.212Z,1578949042.212 [LoopControl](DEBUG): Initialize LoopControlComponent. 2020-01-13T20:57:22.213Z,1578949042.213 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2020-01-13T20:57:22.222Z,1578949042.222 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2020-01-13T20:57:22.242Z,1578949042.242 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2331 2020-01-13T20:57:22.245Z,1578949042.245 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2020-01-13T20:57:22.245Z,1578949042.245 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2020-01-13T20:57:22.245Z,1578949042.245 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2020-01-13T20:57:22.245Z,1578949042.245 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2020-01-13T20:57:22.245Z,1578949042.245 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2020-01-13T20:57:22.246Z,1578949042.246 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2020-01-13T20:57:22.246Z,1578949042.246 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2020-01-13T20:57:22.246Z,1578949042.246 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2020-01-13T20:57:22.246Z,1578949042.246 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2020-01-13T20:57:22.246Z,1578949042.246 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2020-01-13T20:57:22.247Z,1578949042.247 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2020-01-13T20:57:22.247Z,1578949042.247 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2020-01-13T20:57:22.247Z,1578949042.247 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2020-01-13T20:57:22.247Z,1578949042.247 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2020-01-13T20:57:22.247Z,1578949042.247 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2020-01-13T20:57:22.248Z,1578949042.248 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2020-01-13T20:57:22.261Z,1578949042.261 [MissionManager](DEBUG): 2020-01-13T20:57:22.262Z,1578949042.262 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2020-01-13T20:57:22.361Z,1578949042.361 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2020-01-13T20:57:22.362Z,1578949042.362 [Default:A.Wait](DEBUG): Construct Wait. 2020-01-13T20:57:22.364Z,1578949042.364 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2020-01-13T20:57:22.426Z,1578949042.426 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2020-01-13T20:57:22.428Z,1578949042.428 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2020-01-13T20:57:22.469Z,1578949042.469 [Default:E.Execute](DEBUG): Construct Execute. 2020-01-13T20:57:22.472Z,1578949042.472 [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-13T20:57:22.485Z,1578949042.485 [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-13T20:57:22.510Z,1578949042.510 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2020-01-13T20:57:22.533Z,1578949042.533 [Radio_Surface](INFO): Powering up 2020-01-13T20:57:22.551Z,1578949042.551 [DDM](INFO): Powering up 2020-01-13T20:57:22.551Z,1578949042.551 [DDM](DEBUG): Initializing DDM. 2020-01-13T20:57:22.575Z,1578949042.575 [DUSBL_Hydroid](INFO): Powering up 2020-01-13T20:57:22.575Z,1578949042.575 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid. 2020-01-13T20:57:22.843Z,1578949042.843 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2020-01-13T20:57:22.849Z,1578949042.849 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2020-01-13T20:57:22.850Z,1578949042.850 [ElevatorServo](DEBUG): Initializing EZServoServo. 2020-01-13T20:57:22.861Z,1578949042.861 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2020-01-13T20:57:22.862Z,1578949042.862 [MassServo](DEBUG): Initializing EZServoServo. 2020-01-13T20:57:22.873Z,1578949042.873 [MassServo](DEBUG): Initializing MassServo. 2020-01-13T20:57:22.874Z,1578949042.874 [RudderServo](DEBUG): Initializing EZServoServo. 2020-01-13T20:57:22.885Z,1578949042.885 [RudderServo](DEBUG): Initializing RudderServo. 2020-01-13T20:57:22.886Z,1578949042.886 [ThrusterServo](DEBUG): Initializing EZServoServo. 2020-01-13T20:57:22.901Z,1578949042.901 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2020-01-13T20:57:23.070Z,1578949043.070 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2020-01-13T20:57:23.070Z,1578949043.070 [DropWeight] Hardware Fault, FailCount= 1 2020-01-13T20:57:23.070Z,1578949043.070 [DropWeight](ERROR): Hardware Fault 2020-01-13T20:57:23.072Z,1578949043.072 [Micromodem](INFO): Powering up 2020-01-13T20:57:23.072Z,1578949043.072 [Micromodem](DEBUG): Initializing Micromodem. 2020-01-13T20:57:23.175Z,1578949043.175 [CommandLine](FAULT): Scheduling is paused 2020-01-13T20:57:23.175Z,1578949043.175 [CBIT](INFO): Critical error at 20200113T205723 2020-01-13T20:57:23.175Z,1578949043.175 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2020-01-13T20:57:23.178Z,1578949043.178 [CBIT](ERROR): Hardware Fault in component: DropWeight 2020-01-13T20:57:23.178Z,1578949043.178 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2020-01-13T20:57:23.372Z,1578949043.372 [CBIT](INFO): Critical error at 20200113T205723 2020-01-13T20:57:27.857Z,1578949047.857 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33 2020-01-13T20:57:28.260Z,1578949048.260 [Micromodem](INFO): Nmea in: $CATMG,2020-01-13T20:57:27.837211Z,RTC,RTC*58 2020-01-13T20:57:28.260Z,1578949048.260 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2020-01-13T20:57:27.837211Z,RTC,RTC*58 2020-01-13T20:57:28.711Z,1578949048.711 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31 2020-01-13T20:57:28.711Z,1578949048.711 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31 2020-01-13T20:57:29.111Z,1578949049.111 [Micromodem](INFO): Nmea in: $CACFG,SRC,1*33 2020-01-13T20:57:29.111Z,1578949049.111 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64 2020-01-13T20:57:29.519Z,1578949049.519 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66 2020-01-13T20:57:29.519Z,1578949049.519 [Micromodem](INFO): Nmea out: $CCCFG,pwramp.txlevel,3*2C 2020-01-13T20:57:29.923Z,1578949049.923 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,3*2E 2020-01-13T20:57:29.923Z,1578949049.923 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E 2020-01-13T20:57:30.331Z,1578949050.331 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C 2020-01-13T20:57:30.331Z,1578949050.331 [Micromodem](INFO): Nmea out: $CCCFG,FC0,10000*46 2020-01-13T20:57:30.727Z,1578949050.727 [Micromodem](INFO): Nmea in: $CACFG,FC0,10000*44 2020-01-13T20:57:30.728Z,1578949050.728 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63 2020-01-13T20:57:31.136Z,1578949051.136 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61 2020-01-13T20:57:31.136Z,1578949051.136 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A 2020-01-13T20:57:31.513Z,1578949051.513 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38 2020-01-13T20:57:31.514Z,1578949051.514 [Micromodem](INFO): Nmea out: $CCCLK,2020,01,13,20,57,32*46 2020-01-13T20:57:31.935Z,1578949051.935 [Micromodem](INFO): Nmea in: $CACLK,2020,1,13,20,57,32*74 2020-01-13T20:57:32.315Z,1578949052.315 [Micromodem](INFO): Nmea in: $CATMS,0,2020-01-13T20:57:33Z*75 2020-01-13T20:57:32.317Z,1578949052.317 [Micromodem](INFO): Nmea in: $CATMG,2020-01-13T20:57:33.027892Z,USER_CMD,RTC*14 2020-01-13T20:57:33.124Z,1578949053.124 [DDM](INFO): Dynamic Docking Module: 2020-01-13T20:57:35.985Z,1578949055.985 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder 2020-01-13T20:57:40.402Z,1578949060.402 [DUSBL_Hydroid](INFO): DUSBL Version:O 2020-01-13T20:57:40.854Z,1578949060.854 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004486 2020-01-13T20:57:47.671Z,1578949067.671 [NAL9602](INFO): Powering up NAL9602 2020-01-13T20:57:58.583Z,1578949078.583 [NAL9602](INFO): NAL9602 initialized 2020-01-13T20:58:01.483Z,1578949081.483 [SBIT](IMPORTANT): Beginning Startup BIT 2020-01-13T20:58:01.495Z,1578949081.495 [CBIT](IMPORTANT): Beginning ground fault scan 2020-01-13T20:58:12.553Z,1578949092.553 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.012729 CHAN A1 (24V): -0.028637 CHAN A2 (12V): -0.007391 CHAN A3 (5V): -0.002151 CHAN B0 (3.3V): 0.000293 CHAN B1 (3.15aV): -0.000036 CHAN B2 (3.15bV): 0.000211 CHAN B3 (GND): 0.002191 OPEN: 0.005438 Full Scale Calc: 4.765 mA, -1.589 mA 2020-01-13T20:58:33.251Z,1578949113.251 [RDI_Pathfinder](ERROR): Failed to parse: :BI,-32768,-32768,-32768,-32768,V 2020-01-13T20:58:41.023Z,1578949121.023 [SBIT](FAULT): Rudder: EXPECTED:-15.000000 ACTUAL:-14.975829 2020-01-13T20:58:41.023Z,1578949121.023 [SBIT](FAULT): Control surface position failure. 2020-01-13T20:58:46.786Z,1578949126.786 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2020-01-13T20:58:46.786Z,1578949126.786 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2020-01-13T20:58:54.883Z,1578949134.883 [SBIT](CRITICAL): SBIT FAILED 2020-01-13T20:58:54.922Z,1578949134.922 [CommandLine](IMPORTANT): got command configSet list 2020-01-13T20:58:54.922Z,1578949134.922 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2020-01-13T20:58:54.923Z,1578949134.923 [CommandLine](IMPORTANT): DDM.loadAtStartup=1 bool; 2020-01-13T20:58:54.923Z,1578949134.923 [CommandLine](IMPORTANT): DDM.verbosity=3 count; 2020-01-13T20:58:54.924Z,1578949134.924 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold=25 count; 2020-01-13T20:58:54.924Z,1578949134.924 [CommandLine](IMPORTANT): DUSBL_Hydroid.transmitLockout=40 millisecond; 2020-01-13T20:58:54.924Z,1578949134.924 [CommandLine](IMPORTANT): Express linearApproximation DDM.DDMMode 1.000000 count; 2020-01-13T20:58:54.924Z,1578949134.924 [CommandLine](IMPORTANT): Express all DDM.cablePresent; 2020-01-13T20:58:54.924Z,1578949134.924 [CommandLine](IMPORTANT): Express linearApproximation DDM.latchState 1.000000 count; 2020-01-13T20:58:54.924Z,1578949134.924 [CommandLine](IMPORTANT): Express linearApproximation DDM.whiskerState 1.000000 count; 2020-01-13T20:58:54.924Z,1578949134.924 [CommandLine](IMPORTANT): Express linearApproximation DUSBL_Hydroid.acoustic_contact_range 1.000000 meter; 2020-01-13T20:58:54.924Z,1578949134.924 [CommandLine](IMPORTANT): Express linearApproximation DUSBL_Hydroid.xAngle 2.000000 degree; 2020-01-13T20:58:54.924Z,1578949134.924 [CommandLine](IMPORTANT): Express linearApproximation RDI_Pathfinder.height_above_sea_floor 2.000000 meter; 2020-01-13T20:58:54.925Z,1578949134.925 [CommandLine](IMPORTANT): Express linearApproximation platform_orientation 5.000000 degree; 2020-01-13T20:58:54.925Z,1578949134.925 [CommandLine](IMPORTANT): Express linearApproximation platform_x_velocity_wrt_ground 0.100000 meter_per_second; 2020-01-13T20:58:54.925Z,1578949134.925 [CommandLine](IMPORTANT): Express linearApproximation platform_y_velocity_wrt_ground 0.100000 meter_per_second; 2020-01-13T20:58:54.925Z,1578949134.925 [CommandLine](IMPORTANT): HorizontalControl.kiHeading=0.002 reciprocal_second; 2020-01-13T20:58:54.925Z,1578949134.925 [CommandLine](IMPORTANT): HorizontalControl.kpHeading=0.8 none; 2020-01-13T20:58:54.925Z,1578949134.925 [CommandLine](IMPORTANT): HorizontalControl.rudDeadband=0.05 degree; 2020-01-13T20:58:54.925Z,1578949134.925 [CommandLine](IMPORTANT): Micromodem.destinationAddress=12 enum; 2020-01-13T20:58:54.926Z,1578949134.926 [CommandLine](IMPORTANT): Micromodem.pwrampTXLevel=3 enum; 2020-01-13T20:58:54.926Z,1578949134.926 [CommandLine](IMPORTANT): Micromodem.surfaceThreshold=-1 meter; 2020-01-13T20:58:54.926Z,1578949134.926 [CommandLine](IMPORTANT): PowerOnly.sampleTime=90 second; 2020-01-13T20:58:54.926Z,1578949134.926 [CommandLine](IMPORTANT): RudderServo.deviationAngle=0.0001 degree; 2020-01-13T20:58:54.926Z,1578949134.926 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=105 cubic_centimeter; 2020-01-13T20:58:54.926Z,1578949134.926 [CommandLine](IMPORTANT): VerticalControl.massDefault=-5 millimeter; 2020-01-13T20:58:54.931Z,1578949134.931 [CBIT](INFO): Critical error at 20200113T205854 2020-01-13T20:58:55.278Z,1578949135.278 [MissionManager](IMPORTANT): Started mission Startup 2020-01-13T20:58:55.279Z,1578949135.279 [Startup] Running Loop=1 2020-01-13T20:58:55.279Z,1578949135.279 [Startup](DEBUG): Aggregate::initialize Startup 2020-01-13T20:58:55.279Z,1578949135.279 [Startup:A.GoToSurface] Running Loop=1 2020-01-13T20:58:55.279Z,1578949135.279 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2020-01-13T20:58:55.280Z,1578949135.280 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2020-01-13T20:58:55.280Z,1578949135.280 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2020-01-13T20:58:55.280Z,1578949135.280 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2020-01-13T20:58:55.281Z,1578949135.281 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2020-01-13T20:58:55.281Z,1578949135.281 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2020-01-13T20:58:55.283Z,1578949135.283 [Startup:StartupSatComms] Running Loop=1 2020-01-13T20:58:55.283Z,1578949135.283 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2020-01-13T20:58:55.283Z,1578949135.283 [Startup:StartupSatComms:A] Running Loop=1 2020-01-13T20:58:55.674Z,1578949135.674 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2020-01-13T20:59:55.459Z,1578949195.459 [Startup:StartupSatComms:A](INFO): Timed out from 2020-01-13T20:58:55.3Z 2020-01-13T20:59:55.459Z,1578949195.459 [Startup:StartupSatComms:A] Stopped 2020-01-13T20:59:55.459Z,1578949195.459 [Startup:StartupSatComms:B] Running Loop=1 2020-01-13T20:59:55.852Z,1578949195.852 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2020-01-13T20:59:57.267Z,1578949197.267 [Micromodem](INFO): Outgoing frame #1, 64 bytes: F9CE1C5E070000005D00000400320000000000000000151D80030C5669C010E4BA2E274249CC8C1C73BC51F29446773BB327936E238C667C1D152ACE1263781A 2020-01-13T20:59:57.267Z,1578949197.267 [Micromodem](INFO): Outgoing frame #2, 5 bytes: 73F6D413A0 2020-01-13T20:59:57.268Z,1578949197.268 [Micromodem](INFO): Nmea out: $CCCYC,0,1,12,1,0,2*68 2020-01-13T20:59:58.215Z,1578949198.215 [Micromodem](INFO): Nmea in: $CACYC,0,1,12,1,0,2*6A 2020-01-13T20:59:58.615Z,1578949198.615 [Micromodem](INFO): Nmea in: $CADRQ,205958,1,12,0,64,1*77 2020-01-13T20:59:58.616Z,1578949198.616 [Micromodem](INFO): Nmea out: $CCTXD,1,12,1,F9CE1C5E070000005D00000400320000000000000000151D80030C5669C010E4BA2E274249CC8C1C73BC51F29446773BB327936E238C667C1D152ACE1263781A*43 2020-01-13T20:59:59.043Z,1578949199.043 [Micromodem](INFO): Nmea in: $CATXD,1,12,1,64*4B 2020-01-13T20:59:59.419Z,1578949199.419 [Micromodem](INFO): Nmea in: $CADRQ,205959,1,12,0,64,2*75 2020-01-13T20:59:59.419Z,1578949199.419 [Micromodem](INFO): Nmea out: $CCTXD,1,12,1,73F6D413A0*3C 2020-01-13T20:59:59.823Z,1578949199.823 [Micromodem](INFO): Nmea in: $CATXD,1,12,1,5*7C 2020-01-13T21:00:00.235Z,1578949200.235 [Micromodem](INFO): Nmea in: $CATXP,69*7D 2020-01-13T21:00:02.651Z,1578949202.651 [Micromodem](INFO): Nmea in: $CATXF,69*6B 2020-01-13T21:00:03.056Z,1578949203.056 [Micromodem](INFO): Nmea in: $CAXST,6,20200113,210000.337125,3,0,200,4000,10000,1,1,12,1,2,2,3,69*4E 2020-01-13T21:00:04.008Z,1578949204.008 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20200113T201137/Courier0007.lzma 2020-01-13T21:00:06.014Z,1578949206.014 [DataOverHttps](INFO): Moved sent file to Logs/20200113T201137/Courier0007.lzma.bak 2020-01-13T21:00:06.015Z,1578949206.015 [DataOverHttps](INFO): SBD MOMSN=12191360 2020-01-13T21:00:22.098Z,1578949222.098 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2020-01-13T21:00:22.098Z,1578949222.098 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-01-13T21:00:22.112Z,1578949222.112 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-01-13T21:00:22.532Z,1578949222.532 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-01-13T21:00:22.533Z,1578949222.533 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2020-01-13T21:00:23.597Z,1578949223.597 [DataOverHttps](INFO): Sending 256 bytes from file Logs/20200113T205710/Courier0000.lzma 2020-01-13T21:00:25.602Z,1578949225.602 [DataOverHttps](INFO): Moved sent file to Logs/20200113T205710/Courier0000.lzma.bak 2020-01-13T21:00:25.602Z,1578949225.602 [DataOverHttps](INFO): SBD MOMSN=12191362 2020-01-13T21:00:44.352Z,1578949244.352 [DataOverHttps](INFO): Sending 1416 bytes from file Logs/20200110T020638/Express0001.lzma 2020-01-13T21:00:46.354Z,1578949246.354 [DataOverHttps](INFO): Moved sent file to Logs/20200110T020638/Express0001.lzma.bak 2020-01-13T21:00:46.354Z,1578949246.354 [DataOverHttps](INFO): SBD MOMSN=12191368 2020-01-13T21:00:55.635Z,1578949255.635 [Startup:StartupSatComms:B](INFO): Timed out from 2020-01-13T20:59:55.5Z 2020-01-13T21:00:55.635Z,1578949255.635 [Startup:StartupSatComms:B] Stopped 2020-01-13T21:00:55.635Z,1578949255.635 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2020-01-13T21:00:55.635Z,1578949255.635 [Startup:StartupSatComms] Stopped 2020-01-13T21:00:55.635Z,1578949255.635 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2020-01-13T21:00:55.636Z,1578949255.636 [Startup](INFO): Completed Startup 2020-01-13T21:00:55.636Z,1578949255.636 [MissionManager](INFO): Startup is completed. 2020-01-13T21:00:55.636Z,1578949255.636 [MissionManager](INFO): Uninitializing Mission Startup 2020-01-13T21:00:55.636Z,1578949255.636 [Startup] Stopped 2020-01-13T21:00:55.636Z,1578949255.636 [Startup](DEBUG): Aggregate::uninitialize Startup 2020-01-13T21:00:55.636Z,1578949255.636 [Startup:A.GoToSurface] Stopped 2020-01-13T21:00:55.636Z,1578949255.636 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2020-01-13T21:00:56.155Z,1578949256.155 [MissionManager](IMPORTANT): Started mission Default 2020-01-13T21:00:56.155Z,1578949256.155 [Default] Running Loop=1 2020-01-13T21:00:56.155Z,1578949256.155 [Default](DEBUG): Aggregate::initialize Default 2020-01-13T21:00:56.155Z,1578949256.155 [Default:B.GoToSurface] Running Loop=1 2020-01-13T21:00:56.155Z,1578949256.155 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2020-01-13T21:00:56.155Z,1578949256.155 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2020-01-13T21:00:56.156Z,1578949256.156 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2020-01-13T21:00:56.156Z,1578949256.156 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2020-01-13T21:00:56.156Z,1578949256.156 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2020-01-13T21:00:56.157Z,1578949256.157 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2020-01-13T21:00:56.157Z,1578949256.157 [Default:A.Wait] Running Loop=1 2020-01-13T21:00:56.157Z,1578949256.157 [Default:A.Wait](DEBUG): Initialize Wait Component. 2020-01-13T21:01:04.922Z,1578949264.922 [DataOverHttps](INFO): Sending 98 bytes from file Logs/20200110T020638/Express0005.lzma 2020-01-13T21:01:06.926Z,1578949266.926 [DataOverHttps](INFO): Moved sent file to Logs/20200110T020638/Express0005.lzma.bak 2020-01-13T21:01:06.926Z,1578949266.926 [DataOverHttps](INFO): SBD MOMSN=12191409 2020-01-13T21:01:09.405Z,1578949269.405 [Default:A.Wait](INFO): Done Waiting. 2020-01-13T21:01:09.405Z,1578949269.405 [Default:A.Wait] Stopped 2020-01-13T21:01:09.405Z,1578949269.405 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2020-01-13T21:01:09.888Z,1578949269.888 [Default:CheckIn] Running Loop=1 2020-01-13T21:01:09.888Z,1578949269.888 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-01-13T21:01:09.889Z,1578949269.889 [Default:CheckIn:Read_GPS] Running Loop=1 2020-01-13T21:01:10.183Z,1578949270.183 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2020-01-13T21:01:31.176Z,1578949291.176 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2020-01-13T21:01:31.176Z,1578949291.176 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2020-01-13T21:02:24.483Z,1578949344.483 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2020-01-13T21:02:24.483Z,1578949344.483 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2020-01-13T21:03:02.031Z,1578949382.031 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2020-01-13T21:03:23.082Z,1578949403.082 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2020-01-13T21:03:23.082Z,1578949403.082 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-01-13T21:03:23.092Z,1578949403.092 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-01-13T21:03:23.645Z,1578949403.645 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-01-13T21:03:23.645Z,1578949403.645 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2020-01-13T21:04:36.970Z,1578949476.970 [CommandLine](IMPORTANT): got command configSet list 2020-01-13T21:04:36.970Z,1578949476.970 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2020-01-13T21:04:36.971Z,1578949476.971 [CommandLine](IMPORTANT): DDM.loadAtStartup=1 bool; 2020-01-13T21:04:36.971Z,1578949476.971 [CommandLine](IMPORTANT): DDM.verbosity=3 count; 2020-01-13T21:04:36.971Z,1578949476.971 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold=25 count; 2020-01-13T21:04:36.971Z,1578949476.971 [CommandLine](IMPORTANT): DUSBL_Hydroid.transmitLockout=40 millisecond; 2020-01-13T21:04:36.971Z,1578949476.971 [CommandLine](IMPORTANT): Express linearApproximation DDM.DDMMode 1.000000 count; 2020-01-13T21:04:36.971Z,1578949476.971 [CommandLine](IMPORTANT): Express all DDM.cablePresent; 2020-01-13T21:04:36.971Z,1578949476.971 [CommandLine](IMPORTANT): Express linearApproximation DDM.latchState 1.000000 count; 2020-01-13T21:04:36.971Z,1578949476.971 [CommandLine](IMPORTANT): Express linearApproximation DDM.whiskerState 1.000000 count; 2020-01-13T21:04:36.972Z,1578949476.972 [CommandLine](IMPORTANT): Express linearApproximation DUSBL_Hydroid.acoustic_contact_range 1.000000 meter; 2020-01-13T21:04:36.972Z,1578949476.972 [CommandLine](IMPORTANT): Express linearApproximation DUSBL_Hydroid.xAngle 2.000000 degree; 2020-01-13T21:04:36.972Z,1578949476.972 [CommandLine](IMPORTANT): Express linearApproximation RDI_Pathfinder.height_above_sea_floor 2.000000 meter; 2020-01-13T21:04:36.972Z,1578949476.972 [CommandLine](IMPORTANT): Express linearApproximation platform_orientation 5.000000 degree; 2020-01-13T21:04:36.972Z,1578949476.972 [CommandLine](IMPORTANT): Express linearApproximation platform_x_velocity_wrt_ground 0.100000 meter_per_second; 2020-01-13T21:04:36.972Z,1578949476.972 [CommandLine](IMPORTANT): Express linearApproximation platform_y_velocity_wrt_ground 0.100000 meter_per_second; 2020-01-13T21:04:36.972Z,1578949476.972 [CommandLine](IMPORTANT): HorizontalControl.kiHeading=0.002 reciprocal_second; 2020-01-13T21:04:36.972Z,1578949476.972 [CommandLine](IMPORTANT): HorizontalControl.kpHeading=0.8 none; 2020-01-13T21:04:36.972Z,1578949476.972 [CommandLine](IMPORTANT): HorizontalControl.rudDeadband=0.05 degree; 2020-01-13T21:04:36.973Z,1578949476.973 [CommandLine](IMPORTANT): Micromodem.destinationAddress=12 enum; 2020-01-13T21:04:36.974Z,1578949476.974 [CommandLine](IMPORTANT): Micromodem.pwrampTXLevel=3 enum; 2020-01-13T21:04:36.974Z,1578949476.974 [CommandLine](IMPORTANT): Micromodem.surfaceThreshold=-1 meter; 2020-01-13T21:04:36.974Z,1578949476.974 [CommandLine](IMPORTANT): PowerOnly.sampleTime=90 second; 2020-01-13T21:04:36.974Z,1578949476.974 [CommandLine](IMPORTANT): RudderServo.deviationAngle=0.0001 degree; 2020-01-13T21:04:36.974Z,1578949476.974 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=105 cubic_centimeter; 2020-01-13T21:04:36.974Z,1578949476.974 [CommandLine](IMPORTANT): VerticalControl.massDefault=-5 millimeter; 2020-01-13T21:04:50.326Z,1578949490.326 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2020-01-13T21:04:50.364Z,1578949490.364 [BPC1](INFO): Received data from all battery sticks. 2020-01-13T21:04:55.634Z,1578949495.634 [CommandLine](IMPORTANT): got command configSet Micromodem.surfaceThreshold 0.000000 meter persist 2020-01-13T21:05:10.119Z,1578949510.119 [RDI_Pathfinder](ERROR): Failed to parse: :BI,-32768,-32768,-32768,-32768,V 2020-01-13T21:06:09.930Z,1578949569.930 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-01-13T21:01:09.9Z 2020-01-13T21:06:09.930Z,1578949569.930 [Default:CheckIn:Read_GPS] Stopped 2020-01-13T21:06:09.930Z,1578949569.930 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-01-13T21:06:10.330Z,1578949570.330 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2020-01-13T21:06:10.694Z,1578949570.694 [Micromodem](ERROR): Buffer fill timout failure. 2020-01-13T21:06:11.840Z,1578949571.840 [Micromodem](INFO): Outgoing frame #1, 64 bytes: A6D91C5E040001005D00000400600100000000000000151D80030C5669BF3148E2FA22188B6A3173E5573572661C0BCBDFFAB423BD32D9A51E8904B0A920CE9A 2020-01-13T21:06:11.841Z,1578949571.841 [Micromodem](INFO): Outgoing frame #2, 64 bytes: EF9F66414C9B9FD6761AD008C3E3DC4FCA2E4E25B6359B14B772C42BBF445E54CD5F36943A3BDD9E89309E9017DB79DD009A333A47CF42F3BE4E4AD4301D597F 2020-01-13T21:06:11.841Z,1578949571.841 [Micromodem](INFO): Outgoing frame #3, 64 bytes: FFA3EC7FA24353C087A3A1B3BD161F92F69707865251F3B93C9772C25CD67B52231335EF84B8E92D5FFA309E6A3CA3D472D19C2387F93B524F1C0C5E13B1324C 2020-01-13T21:06:11.842Z,1578949571.842 [Micromodem](INFO): Nmea out: $CCCYC,0,1,12,1,0,3*69 2020-01-13T21:06:12.019Z,1578949572.019 [Micromodem](INFO): Nmea in: $CACYC,0,1,12,1,0,3*6B 2020-01-13T21:06:12.383Z,1578949572.383 [Micromodem](INFO): Nmea in: $CADRQ,210612,1,12,0,64,1*72 2020-01-13T21:06:12.383Z,1578949572.383 [Micromodem](INFO): Nmea out: $CCTXD,1,12,1,A6D91C5E040001005D00000400600100000000000000151D80030C5669BF3148E2FA22188B6A3173E5573572661C0BCBDFFAB423BD32D9A51E8904B0A920CE9A*42 2020-01-13T21:06:12.783Z,1578949572.783 [Micromodem](INFO): Nmea in: $CATXD,1,12,1,64*4B 2020-01-13T21:06:13.199Z,1578949573.199 [Micromodem](INFO): Nmea in: $CADRQ,210613,1,12,0,64,2*70 2020-01-13T21:06:13.199Z,1578949573.199 [Micromodem](INFO): Nmea out: $CCTXD,1,12,1,EF9F66414C9B9FD6761AD008C3E3DC4FCA2E4E25B6359B14B772C42BBF445E54CD5F36943A3BDD9E89309E9017DB79DD009A333A47CF42F3BE4E4AD4301D597F*3D 2020-01-13T21:06:13.599Z,1578949573.599 [Micromodem](INFO): Nmea in: $CATXD,1,12,1,64*4B 2020-01-13T21:06:14.003Z,1578949574.003 [Micromodem](INFO): Nmea in: $CADRQ,210614,1,12,0,64,3*76 2020-01-13T21:06:14.003Z,1578949574.003 [Micromodem](INFO): Nmea out: $CCTXD,1,12,1,FFA3EC7FA24353C087A3A1B3BD161F92F69707865251F3B93C9772C25CD67B52231335EF84B8E92D5FFA309E6A3CA3D472D19C2387F93B524F1C0C5E13B1324C*35 2020-01-13T21:06:14.399Z,1578949574.399 [Micromodem](INFO): Nmea in: $CATXD,1,12,1,64*4B 2020-01-13T21:06:14.811Z,1578949574.811 [Micromodem](INFO): Nmea in: $CATXP,192*48 2020-01-13T21:06:17.637Z,1578949577.637 [DataOverHttps](INFO): Sending 200 bytes from file Logs/20200113T205710/Courier0004.lzma 2020-01-13T21:06:18.447Z,1578949578.447 [Micromodem](INFO): Nmea in: $CATXF,192*5E 2020-01-13T21:06:19.642Z,1578949579.642 [DataOverHttps](INFO): Moved sent file to Logs/20200113T205710/Courier0004.lzma.bak 2020-01-13T21:06:19.642Z,1578949579.642 [DataOverHttps](INFO): SBD MOMSN=12191412 2020-01-13T21:06:19.755Z,1578949579.755 [Micromodem](INFO): Nmea in: $CAXST,6,20200113,210614.993032,3,0,200,4000,10000,1,1,12,1,3,3,3,192*7B 2020-01-13T21:06:24.175Z,1578949584.175 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2020-01-13T21:06:24.175Z,1578949584.175 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-01-13T21:06:24.209Z,1578949584.209 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-01-13T21:06:24.554Z,1578949584.554 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-01-13T21:06:24.554Z,1578949584.554 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2020-01-13T21:06:38.966Z,1578949598.966 [DataOverHttps](INFO): Sending 1375 bytes from file Logs/20200110T020932/Express0001.lzma 2020-01-13T21:06:40.822Z,1578949600.822 [DataOverHttps](INFO): Moved sent file to Logs/20200110T020932/Express0001.lzma.bak 2020-01-13T21:06:40.822Z,1578949600.822 [DataOverHttps](INFO): SBD MOMSN=12191414 2020-01-13T21:06:59.342Z,1578949619.342 [DataOverHttps](INFO): Sending 99 bytes from file Logs/20200110T020932/Express0005.lzma 2020-01-13T21:07:01.346Z,1578949621.346 [DataOverHttps](INFO): Moved sent file to Logs/20200110T020932/Express0005.lzma.bak 2020-01-13T21:07:01.346Z,1578949621.346 [DataOverHttps](INFO): SBD MOMSN=12191454 2020-01-13T21:07:17.018Z,1578949637.018 [Micromodem](ERROR): Buffer fill timout failure. 2020-01-13T21:07:19.011Z,1578949639.011 [Default:CheckIn:Read_Iridium] Stopped 2020-01-13T21:07:19.011Z,1578949639.011 [Default:CheckIn:C.Wait] Running Loop=1 2020-01-13T21:07:19.011Z,1578949639.011 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-01-13T21:07:21.424Z,1578949641.424 [DataOverHttps](INFO): Sending 1365 bytes from file Logs/20200110T021238/Express0001.lzma 2020-01-13T21:07:23.426Z,1578949643.426 [DataOverHttps](INFO): Moved sent file to Logs/20200110T021238/Express0001.lzma.bak 2020-01-13T21:07:23.427Z,1578949643.427 [DataOverHttps](INFO): SBD MOMSN=12191457 2020-01-13T21:07:59.867Z,1578949679.867 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-01-13T21:07:59.867Z,1578949679.867 [NAL9602] Data Fault, FailCount= 1 2020-01-13T21:07:59.867Z,1578949679.867 [NAL9602](ERROR): Data Fault 2020-01-13T21:07:59.944Z,1578949679.944 [CBIT](ERROR): Data Fault in component: NAL9602 2020-01-13T21:08:00.263Z,1578949680.263 [NAL9602](INFO): Powering down 2020-01-13T21:08:01.143Z,1578949681.143 [CBIT](INFO): Clearing failed state for component NAL9602 2020-01-13T21:08:01.143Z,1578949681.143 [NAL9602] No Fault, FailCount= 1 2020-01-13T21:08:23.321Z,1578949703.321 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2020-01-13T21:08:23.321Z,1578949703.321 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2020-01-13T21:08:30.567Z,1578949710.567 [NAL9602](INFO): Powering up NAL9602 2020-01-13T21:08:31.834Z,1578949711.834 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2020-01-13T21:08:31.835Z,1578949711.835 [RDI_Pathfinder](ERROR): Failed to parse: :TS,20011314212602,35.0, -0.1, 0.0, 0 2020-01-13T21:08:41.471Z,1578949721.471 [NAL9602](INFO): NAL9602 initialized 2020-01-13T21:09:25.171Z,1578949765.171 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2020-01-13T21:09:25.171Z,1578949765.171 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-01-13T21:09:25.181Z,1578949765.181 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-01-13T21:09:25.546Z,1578949765.546 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-01-13T21:09:25.547Z,1578949765.547 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2020-01-13T21:11:32.811Z,1578949892.811 [CommandLine](IMPORTANT): got command run ./Missions/Maintenance/DUSBL.xml 2020-01-13T21:11:32.811Z,1578949892.811 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/DUSBL.xml 2020-01-13T21:11:32.865Z,1578949892.865 [MissionManager](INFO): DefineArg DUSBL.MissionTimeout = 90.000000 min 2020-01-13T21:11:32.873Z,1578949892.873 [MissionManager](INFO): DefineArg DUSBL.NumberOfRequests = 10.000000 count 2020-01-13T21:11:32.887Z,1578949892.887 [MissionManager](INFO): DefineArg DUSBL.TransponderCode = 2.000000 count 2020-01-13T21:11:32.920Z,1578949892.920 [MissionManager](INFO): DefineArg DUSBL.NumberOfPings = 1.000000 count 2020-01-13T21:11:32.939Z,1578949892.939 [MissionManager](INFO): DefineArg DUSBL.EnabledDUSBL = DUSBL_Hydroid.loadAtStartup 2020-01-13T21:11:32.940Z,1578949892.940 [DUSBL:A.Pitch](DEBUG): Construct. 2020-01-13T21:11:32.954Z,1578949892.954 [DUSBL:B.SetSpeed](DEBUG): Construct. 2020-01-13T21:11:32.975Z,1578949892.975 [DUSBL:RequestRepeater:C.Wait](DEBUG): Construct Wait. 2020-01-13T21:11:32.979Z,1578949892.979 [MissionManager](DEBUG): This mission is requests a DUSBL arming. How long to let the mission run. 90 Number of pings to requst. 10 Transponder Address. 2 Number of pings requested each time. 1 Automatically set to true if the DUSBL is enabled. Set to false to disable reading from the DUSBL. 0 90 2020-01-13T21:11:32.993Z,1578949892.993 [CommandLine](IMPORTANT): Running ./Missions/Maintenance/DUSBL.xml 2020-01-13T21:11:33.243Z,1578949893.243 [Default] Stopped 2020-01-13T21:11:33.243Z,1578949893.243 [Default](DEBUG): Aggregate::uninitialize Default 2020-01-13T21:11:33.243Z,1578949893.243 [Default:B.GoToSurface] Stopped 2020-01-13T21:11:33.243Z,1578949893.243 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2020-01-13T21:11:33.243Z,1578949893.243 [Default:CheckIn] Stopped 2020-01-13T21:11:33.243Z,1578949893.243 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-01-13T21:11:33.243Z,1578949893.243 [Default:CheckIn:C.Wait] Stopped 2020-01-13T21:11:33.243Z,1578949893.243 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-01-13T21:11:33.243Z,1578949893.243 [MissionManager](IMPORTANT): Started mission DUSBL 2020-01-13T21:11:33.244Z,1578949893.244 [DUSBL] Running Loop=1 2020-01-13T21:11:33.244Z,1578949893.244 [DUSBL](DEBUG): Aggregate::initialize DUSBL 2020-01-13T21:11:33.244Z,1578949893.244 [DUSBL:A.Pitch] Running Loop=1 2020-01-13T21:11:33.244Z,1578949893.244 [DUSBL:A.Pitch](DEBUG): Initialize. 2020-01-13T21:11:33.244Z,1578949893.244 [DUSBL:B.SetSpeed] Running Loop=1 2020-01-13T21:11:33.244Z,1578949893.244 [DUSBL:B.SetSpeed](DEBUG): Initialize. 2020-01-13T21:11:33.244Z,1578949893.244 [DUSBL:C] Running Loop=1 2020-01-13T21:11:33.244Z,1578949893.244 [DUSBL:RequestRepeater] Running Loop=1 2020-01-13T21:11:33.249Z,1578949893.249 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater 2020-01-13T21:11:33.249Z,1578949893.249 [DUSBL:RequestRepeater:A] Running Loop=1 2020-01-13T21:11:33.249Z,1578949893.249 [DUSBL:RequestRepeater:B] Running Loop=1 2020-01-13T21:11:33.249Z,1578949893.249 [DUSBL:RequestRepeater:C.Wait] Running Loop=1 2020-01-13T21:11:33.249Z,1578949893.249 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component. 2020-01-13T21:11:33.249Z,1578949893.249 [DUSBL:RequestRepeater:B] Running Loop=1 2020-01-13T21:11:33.250Z,1578949893.250 [DUSBL:RequestRepeater:A] Running Loop=1 2020-01-13T21:11:33.251Z,1578949893.251 [DUSBL:C](DEBUG): Initialize ReadDataComponent to sense acoustic_contact_range 2020-01-13T21:11:33.251Z,1578949893.251 [DUSBL:C](DEBUG): Initialize ReadDataComponent to sense acoustic_contact_direction_vehicle_frame 2020-01-13T21:11:33.251Z,1578949893.251 [DUSBL:B.SetSpeed] Running Loop=1 2020-01-13T21:11:33.251Z,1578949893.251 [DUSBL:A.Pitch] Running Loop=1 2020-01-13T21:11:35.205Z,1578949895.205 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77 2020-01-13T21:11:35.605Z,1578949895.605 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A 2020-01-13T21:11:36.415Z,1578949896.415 [Micromodem](INFO): Nmea in: $SNTTA,,,,,211136.15*5C 2020-01-13T21:11:37.643Z,1578949897.643 [CommandLine](IMPORTANT): got command stop 2020-01-13T21:11:37.644Z,1578949897.644 [CommandLine](IMPORTANT): Scheduling is paused 2020-01-13T21:11:37.644Z,1578949897.644 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop 2020-01-13T21:11:37.713Z,1578949897.713 [MissionManager](INFO): MissionManager is completed. 2020-01-13T21:11:37.713Z,1578949897.713 [MissionManager](INFO): Uninitializing Mission DUSBL 2020-01-13T21:11:37.714Z,1578949897.714 [DUSBL] Stopped 2020-01-13T21:11:37.714Z,1578949897.714 [DUSBL](DEBUG): Aggregate::uninitialize DUSBL 2020-01-13T21:11:37.714Z,1578949897.714 [DUSBL:A.Pitch] Stopped 2020-01-13T21:11:37.714Z,1578949897.714 [DUSBL:B.SetSpeed] Stopped 2020-01-13T21:11:37.714Z,1578949897.714 [DUSBL:B.SetSpeed](DEBUG): Uninitialize. 2020-01-13T21:11:37.714Z,1578949897.714 [DUSBL:C] Stopped 2020-01-13T21:11:37.714Z,1578949897.714 [DUSBL:RequestRepeater] Stopped 2020-01-13T21:11:37.714Z,1578949897.714 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater 2020-01-13T21:11:37.714Z,1578949897.714 [DUSBL:RequestRepeater:A] Stopped 2020-01-13T21:11:37.714Z,1578949897.714 [DUSBL:RequestRepeater:B] Stopped 2020-01-13T21:11:37.714Z,1578949897.714 [DUSBL:RequestRepeater:C.Wait] Stopped 2020-01-13T21:11:37.714Z,1578949897.714 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component. 2020-01-13T21:11:38.069Z,1578949898.069 [MissionManager](IMPORTANT): Started mission Default 2020-01-13T21:11:38.069Z,1578949898.069 [Default] Running Loop=1 2020-01-13T21:11:38.069Z,1578949898.069 [Default](DEBUG): Aggregate::initialize Default 2020-01-13T21:11:38.069Z,1578949898.069 [Default:B.GoToSurface] Running Loop=1 2020-01-13T21:11:38.069Z,1578949898.069 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2020-01-13T21:11:38.070Z,1578949898.070 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2020-01-13T21:11:38.070Z,1578949898.070 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2020-01-13T21:11:38.070Z,1578949898.070 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2020-01-13T21:11:38.070Z,1578949898.070 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2020-01-13T21:11:38.071Z,1578949898.071 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2020-01-13T21:11:38.071Z,1578949898.071 [Default:A.Wait] Running Loop=1 2020-01-13T21:11:38.071Z,1578949898.071 [Default:A.Wait](DEBUG): Initialize Wait Component. 2020-01-13T21:11:51.412Z,1578949911.412 [Default:A.Wait](INFO): Done Waiting. 2020-01-13T21:11:51.412Z,1578949911.412 [Default:A.Wait] Stopped 2020-01-13T21:11:51.412Z,1578949911.412 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2020-01-13T21:11:51.783Z,1578949911.783 [Default:CheckIn] Running Loop=1 2020-01-13T21:11:51.783Z,1578949911.783 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-01-13T21:11:51.783Z,1578949911.783 [Default:CheckIn:Read_GPS] Running Loop=1 2020-01-13T21:12:23.295Z,1578949943.295 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00, 0.00 2020-01-13T21:12:23.340Z,1578949943.340 [CBIT](INFO): Clearing failed state for component DropWeight 2020-01-13T21:12:23.340Z,1578949943.340 [DropWeight] No Fault, FailCount= 1 2020-01-13T21:12:26.166Z,1578949946.166 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2020-01-13T21:12:26.166Z,1578949946.166 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-01-13T21:12:26.204Z,1578949946.204 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-01-13T21:12:26.576Z,1578949946.576 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-01-13T21:12:26.576Z,1578949946.576 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2020-01-13T21:13:47.780Z,1578950027.780 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2020-01-13T21:13:47.780Z,1578950027.780 [RDI_Pathfinder](ERROR): Failed to parse: :BD, , +0.00, +0.00, 0.00,971.96 2020-01-13T21:15:27.131Z,1578950127.131 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2020-01-13T21:15:27.131Z,1578950127.131 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-01-13T21:15:27.157Z,1578950127.157 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-01-13T21:15:27.547Z,1578950127.547 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-01-13T21:15:27.547Z,1578950127.547 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2020-01-13T21:15:29.148Z,1578950129.148 [RDI_Pathfinder](ERROR): Failed to parse: :BE,-32768,-32768,-32768,V 2020-01-13T21:15:45.315Z,1578950145.315 [RDI_Pathfinder](ERROR): Failed to parse: :B +0.00, +0.00, +0.00, 0.00,1087.95 2020-01-13T21:16:11.157Z,1578950171.157 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2020-01-13T21:16:11.157Z,1578950171.157 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2020-01-13T21:16:27.764Z,1578950187.764 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2020-01-13T21:16:27.764Z,1578950187.764 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-3276,-32768,V 2020-01-13T21:16:49.955Z,1578950209.955 [RDI_Pathfinder](ERROR): Failed to parse: :B +0.00, +0.00, +0.00, 0.00,1152.94 2020-01-13T21:16:50.787Z,1578950210.787 [RDI_Pathfinder](ERROR): Failed to parse: :BI,-32768,-32768,-32768,-32768,V 2020-01-13T21:16:51.981Z,1578950211.981 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-01-13T21:11:51.8Z 2020-01-13T21:16:51.981Z,1578950211.981 [Default:CheckIn:Read_GPS] Stopped 2020-01-13T21:16:51.981Z,1578950211.981 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-01-13T21:16:53.769Z,1578950213.769 [Micromodem](INFO): Outgoing frame #1, 47 bytes: A6D91C5E070000005D00000400140000000000000000151D80030C5669C08C34EE575E5D943199163D1616748FCD00 2020-01-13T21:16:53.770Z,1578950213.770 [Micromodem](INFO): Nmea out: $CCCYC,0,1,12,1,0,1*6B 2020-01-13T21:16:53.907Z,1578950213.907 [Micromodem](INFO): Nmea in: $CACYC,0,1,12,1,0,1*69 2020-01-13T21:16:54.291Z,1578950214.291 [Micromodem](INFO): Nmea in: $CADRQ,211654,1,12,0,64,1*71 2020-01-13T21:16:54.291Z,1578950214.291 [Micromodem](INFO): Nmea out: $CCTXD,1,12,1,A6D91C5E070000005D00000400140000000000000000151D80030C5669C08C34EE575E5D943199163D1616748FCD00*38 2020-01-13T21:16:54.679Z,1578950214.679 [Micromodem](INFO): Nmea in: $CATXD,1,12,1,47*4A 2020-01-13T21:16:55.115Z,1578950215.115 [Micromodem](INFO): Nmea in: $CATXP,47*71 2020-01-13T21:16:56.303Z,1578950216.303 [Micromodem](INFO): Nmea in: $CATXF,47*67 2020-01-13T21:16:56.704Z,1578950216.704 [Micromodem](INFO): Nmea in: $CAXST,6,20200113,211655.242447,3,0,200,4000,10000,1,1,12,1,1,1,3,47*47 2020-01-13T21:17:00.444Z,1578950220.444 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200113T205710/Courier0007.lzma 2020-01-13T21:17:02.450Z,1578950222.450 [DataOverHttps](INFO): Moved sent file to Logs/20200113T205710/Courier0007.lzma.bak 2020-01-13T21:17:02.450Z,1578950222.450 [DataOverHttps](INFO): SBD MOMSN=12191497 2020-01-13T21:17:25.786Z,1578950245.786 [DataOverHttps](INFO): Sending 127 bytes from file Logs/20200110T021238/Express0005.lzma 2020-01-13T21:17:27.790Z,1578950247.790 [DataOverHttps](INFO): Moved sent file to Logs/20200110T021238/Express0005.lzma.bak 2020-01-13T21:17:27.790Z,1578950247.790 [DataOverHttps](INFO): SBD MOMSN=12191499 2020-01-13T21:17:47.743Z,1578950267.743 [DataOverHttps](INFO): Sending 1378 bytes from file Logs/20200110T021610/Express0001.lzma 2020-01-13T21:17:49.737Z,1578950269.737 [DataOverHttps](INFO): Moved sent file to Logs/20200110T021610/Express0001.lzma.bak 2020-01-13T21:17:49.737Z,1578950269.737 [DataOverHttps](INFO): SBD MOMSN=12191503 2020-01-13T21:17:58.963Z,1578950278.963 [Micromodem](ERROR): Buffer fill timout failure. 2020-01-13T21:17:59.968Z,1578950279.968 [Default:CheckIn:Read_Iridium] Stopped 2020-01-13T21:17:59.969Z,1578950279.969 [Default:CheckIn:C.Wait] Running Loop=1 2020-01-13T21:17:59.969Z,1578950279.969 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-01-13T21:18:08.362Z,1578950288.362 [DataOverHttps](INFO): Sending 195 bytes from file Logs/20200110T021610/Express0005.lzma 2020-01-13T21:18:10.366Z,1578950290.366 [DataOverHttps](INFO): Moved sent file to Logs/20200110T021610/Express0005.lzma.bak 2020-01-13T21:18:10.367Z,1578950290.367 [DataOverHttps](INFO): SBD MOMSN=12191543 2020-01-13T21:18:28.019Z,1578950308.019 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7 2020-01-13T21:18:28.019Z,1578950308.019 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-01-13T21:18:28.097Z,1578950308.097 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-01-13T21:18:28.365Z,1578950308.365 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-01-13T21:18:28.365Z,1578950308.365 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7 2020-01-13T21:18:42.823Z,1578950322.823 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-01-13T21:18:42.823Z,1578950322.823 [NAL9602] Data Fault, FailCount= 2 2020-01-13T21:18:42.823Z,1578950322.823 [NAL9602](ERROR): Data Fault 2020-01-13T21:18:42.919Z,1578950322.919 [CBIT](ERROR): Data Fault in component: NAL9602 2020-01-13T21:18:43.227Z,1578950323.227 [NAL9602](INFO): Powering down 2020-01-13T21:18:44.071Z,1578950324.071 [CBIT](INFO): Clearing failed state for component NAL9602 2020-01-13T21:18:44.071Z,1578950324.071 [NAL9602] No Fault, FailCount= 2 2020-01-13T21:19:13.526Z,1578950353.526 [NAL9602](INFO): Powering up NAL9602 2020-01-13T21:19:24.431Z,1578950364.431 [NAL9602](INFO): NAL9602 initialized 2020-01-13T21:21:01.834Z,1578950461.834 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2020-01-13T21:21:01.835Z,1578950461.835 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-3276,-32768,V 2020-01-13T21:21:28.900Z,1578950488.900 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8 2020-01-13T21:21:28.900Z,1578950488.900 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-01-13T21:21:28.930Z,1578950488.930 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-01-13T21:21:29.310Z,1578950489.310 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-01-13T21:21:29.310Z,1578950489.310 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8 2020-01-13T21:22:05.058Z,1578950525.058 [CommandLine](IMPORTANT): got command get Micromodem.sendExpress 2020-01-13T21:22:05.059Z,1578950525.059 [CommandLine](IMPORTANT): Micromodem.sendExpress 0 bool 2020-01-13T21:22:11.355Z,1578950531.355 [CommandLine](IMPORTANT): got command configSet Micromodem.sendExpress 1.000000 bool persist 2020-01-13T21:22:19.426Z,1578950539.426 [CommandLine](IMPORTANT): got command failComponent hardware Micromodem 2020-01-13T21:22:19.426Z,1578950539.426 [Micromodem] Hardware Fault, FailCount= 1 2020-01-13T21:22:19.426Z,1578950539.426 [Micromodem](ERROR): Hardware Fault 2020-01-13T21:22:19.426Z,1578950539.426 [CommandLine](IMPORTANT): Micromodem failureMode is Hardware Fault 2020-01-13T21:22:19.768Z,1578950539.768 [Micromodem](INFO): Powering down 2020-01-13T21:22:19.955Z,1578950539.955 [CBIT](ERROR): Hardware Fault in component: Micromodem 2020-01-13T21:22:20.166Z,1578950540.166 [Micromodem](FAULT): LCB 2 fault: Software Overcurrent. 2020-01-13T21:22:20.658Z,1578950540.658 [CBIT](INFO): Clearing failed state for component Micromodem 2020-01-13T21:22:20.658Z,1578950540.658 [Micromodem] No Fault, FailCount= 1 2020-01-13T21:22:23.398Z,1578950543.398 [Micromodem](INFO): Powering up 2020-01-13T21:22:23.399Z,1578950543.399 [Micromodem](DEBUG): Initializing Micromodem. 2020-01-13T21:22:28.243Z,1578950548.243 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33 2020-01-13T21:22:30.275Z,1578950550.275 [Micromodem](INFO): Nmea in: $CATMG,2020-01-13T21:22:29.219212Z,RTC,RTC*50 2020-01-13T21:22:30.276Z,1578950550.276 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2020-01-13T21:22:29.219212Z,RTC,RTC*50 2020-01-13T21:22:39.555Z,1578950559.555 [Micromodem](ERROR): Nmea resend: $CCCFG,ALL,0*33 2020-01-13T21:22:39.967Z,1578950559.967 [Micromodem](INFO): Nmea in: $CAERR,212240,NI ,12,Unknown command*4B 2020-01-13T21:22:39.968Z,1578950559.968 [Micromodem](ERROR): Got error from modem: $CAERR,212240,NI ,12,Unknown command*4B 2020-01-13T21:22:50.878Z,1578950570.878 [Micromodem](ERROR): Nmea resend: $CCCFG,ALL,0*33 2020-01-13T21:22:51.275Z,1578950571.275 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31 2020-01-13T21:22:51.275Z,1578950571.275 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31 2020-01-13T21:22:51.683Z,1578950571.683 [Micromodem](INFO): Nmea in: $CACFG,SRC,1*33 2020-01-13T21:22:51.683Z,1578950571.683 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64 2020-01-13T21:22:52.083Z,1578950572.083 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66 2020-01-13T21:22:52.083Z,1578950572.083 [Micromodem](INFO): Nmea out: $CCCFG,pwramp.txlevel,3*2C 2020-01-13T21:22:52.487Z,1578950572.487 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,3*2E 2020-01-13T21:22:52.487Z,1578950572.487 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E 2020-01-13T21:22:52.915Z,1578950572.915 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C 2020-01-13T21:22:52.916Z,1578950572.916 [Micromodem](INFO): Nmea out: $CCCFG,FC0,10000*46 2020-01-13T21:22:53.303Z,1578950573.303 [Micromodem](INFO): Nmea in: $CACFG,FC0,10000*44 2020-01-13T21:22:53.303Z,1578950573.303 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63 2020-01-13T21:22:53.712Z,1578950573.712 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61 2020-01-13T21:22:53.712Z,1578950573.712 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A 2020-01-13T21:22:54.116Z,1578950574.116 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38 2020-01-13T21:22:54.116Z,1578950574.116 [Micromodem](INFO): Nmea out: $CCCLK,2020,01,13,21,22,55*44 2020-01-13T21:22:54.511Z,1578950574.511 [Micromodem](INFO): Nmea in: $CACLK,2020,1,13,21,22,55*76 2020-01-13T21:22:54.512Z,1578950574.512 [Micromodem](INFO): Nmea in: $CATMS,0,2020-01-13T21:22:56Z*75 2020-01-13T21:22:54.514Z,1578950574.514 [Micromodem](INFO): Nmea in: $CATMG,2020-01-13T21:22:56.026054Z,USER_CMD,RTC*17 2020-01-13T21:22:55.783Z,1578950575.783 [RDI_Pathfinder](ERROR): Failed to parse: :BE,-32768,-32768,-32768,V 2020-01-13T21:23:00.187Z,1578950580.187 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-01-13T21:23:00.187Z,1578950580.187 [Default:CheckIn:C.Wait] Stopped 2020-01-13T21:23:00.187Z,1578950580.187 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-01-13T21:23:00.187Z,1578950580.187 [Default:CheckIn:D] Running Loop=1 2020-01-13T21:23:00.596Z,1578950580.596 [Default:CheckIn:D] Stopped 2020-01-13T21:23:00.596Z,1578950580.596 [Default:CheckIn:E] Running Loop=1 2020-01-13T21:23:01.016Z,1578950581.016 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.375443 min 2020-01-13T21:23:01.017Z,1578950581.017 [Default:CheckIn:E] Stopped 2020-01-13T21:23:01.017Z,1578950581.017 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-01-13T21:23:01.017Z,1578950581.017 [Default:CheckIn] Stopped 2020-01-13T21:23:01.017Z,1578950581.017 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-01-13T21:23:01.017Z,1578950581.017 [Default:CheckIn](INFO): Running loop #2 2020-01-13T21:23:01.017Z,1578950581.017 [Default:CheckIn] Running Loop=2 2020-01-13T21:23:01.017Z,1578950581.017 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-01-13T21:23:01.018Z,1578950581.018 [Default:CheckIn:Read_GPS] Running Loop=1 2020-01-13T21:23:02.180Z,1578950582.180 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2020-01-13T21:23:02.184Z,1578950582.184 [Micromodem](INFO): Nmea in: $CACST,6,1,20200113212303.164406,06,164,16,0092,0150,179,02,02,01,03,-1,-01,-01,1,3,1,0,150,19.6,-5.00,00,8.00,-01,-0.25,38,10000,4000*51 2020-01-13T21:23:08.652Z,1578950588.652 [Micromodem](INFO): Nmea in: $CACYC,1,12,1,1,0,1*68 2020-01-13T21:23:08.652Z,1578950588.652 [Micromodem](INFO): Have incoming data 2020-01-13T21:23:08.655Z,1578950588.655 [Micromodem](INFO): Nmea in: $CARXD,12,1,0,1,EA49DA6859B6D6FDD7866B1D923D9D8A099CA094*52 2020-01-13T21:23:08.655Z,1578950588.655 [Micromodem](ERROR): Could not determine end of data in CARXD:$CARXD,12,1,0,1,EA49DA6859B6D6FDD7866B1D923D9D8A099CA094*52 2020-01-13T21:23:09.065Z,1578950589.065 [Micromodem](INFO): Nmea in: $CACST,6,0,20200113212308.324524,06,159,15,0090,0150,179,02,02,01,03,1,012,001,0,3,1,0,150,-32.0,5.00,00,-2.00,-01,-0.03,51,10000,4000*5E 2020-01-13T21:23:30.059Z,1578950610.059 [Micromodem](INFO): Nmea in: $CACYC,1,12,1,1,0,1*68 2020-01-13T21:23:30.060Z,1578950610.060 [Micromodem](INFO): Have incoming data 2020-01-13T21:23:30.062Z,1578950610.062 [Micromodem](INFO): Nmea in: $CARXD,12,1,0,1,3D90B8D172D0E11A94BB9A0D6EC0434A2AB488F6*51 2020-01-13T21:23:30.064Z,1578950610.064 [Micromodem](INFO): Received command:stop 2020-01-13T21:23:30.129Z,1578950610.129 [CommandLine](IMPORTANT): got command stop 2020-01-13T21:23:30.466Z,1578950610.466 [Micromodem](INFO): Nmea in: $CACST,6,0,20200113212329.744520,06,163,16,0091,0150,179,02,02,01,03,1,012,001,0,3,1,0,150,12.4,5.00,00,-2.00,-01,-0.02,39,10000,4000*74 2020-01-13T21:23:34.913Z,1578950614.913 [Micromodem](INFO): Nmea in: $CACYC,1,12,1,1,0,1*68 2020-01-13T21:23:34.913Z,1578950614.913 [Micromodem](INFO): Have incoming data 2020-01-13T21:23:34.925Z,1578950614.925 [Micromodem](INFO): Nmea in: $CARXD,12,1,0,1,EA49DA6859B6D6FDD7866B1D923D9D8A099CA094*52 2020-01-13T21:23:34.926Z,1578950614.926 [Micromodem](INFO): Received command:failc 2020-01-13T21:23:34.932Z,1578950614.932 [CommandLine](IMPORTANT): got command failComponent 2020-01-13T21:23:34.932Z,1578950614.932 [CommandLine](IMPORTANT): Failed components: 2020-01-13T21:23:34.932Z,1578950614.932 [CommandLine](IMPORTANT): No failed Components. 2020-01-13T21:23:35.322Z,1578950615.322 [Micromodem](INFO): Nmea in: $CACST,6,0,20200113212334.820714,06,162,16,0090,0150,179,02,02,01,03,1,012,001,0,3,1,0,150,13.3,5.00,00,-2.00,-01,-0.02,38,10000,4000*77 2020-01-13T21:23:40.164Z,1578950620.164 [CommandLine](IMPORTANT): got command show variable surfaceThresh 2020-01-13T21:23:40.257Z,1578950620.257 [CommandLine](IMPORTANT): VerticalControl.surfaceThreshold (meter) 2020-01-13T21:23:40.365Z,1578950620.365 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.surfaceThreshold (meter) 2020-01-13T21:23:40.368Z,1578950620.368 [CommandLine](IMPORTANT): DAT.surfaceThreshold (meter) 2020-01-13T21:23:40.372Z,1578950620.372 [CommandLine](IMPORTANT): Micromodem.surfaceThreshold (meter) 2020-01-13T21:23:46.334Z,1578950626.334 [CommandLine](IMPORTANT): got command get Micromodem.surfaceThreshold 2020-01-13T21:23:46.334Z,1578950626.334 [CommandLine](IMPORTANT): Micromodem.surfaceThreshold 0.000000 m 2020-01-13T21:23:48.404Z,1578950628.404 [CommandLine](IMPORTANT): got command get depth 2020-01-13T21:23:48.405Z,1578950628.405 [CommandLine](IMPORTANT): depth 0.157049 m 2020-01-13T21:23:55.259Z,1578950635.259 [CommandLine](IMPORTANT): got command maintain sensor Depth_Keller.depth 0.000000 meter 2020-01-13T21:23:55.260Z,1578950635.260 [ComponentRegistry](DEBUG): SyncComponent "Maintain_Depth_Keller.depth" handled in the control thread. 2020-01-13T21:23:55.559Z,1578950635.559 [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,Maintain_Depth_Keller.depth,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-13T21:24:01.083Z,1578950641.083 [CommandLine](IMPORTANT): got command maintain sensor Depth_Keller.depth 5.000000 meter 2020-01-13T21:24:01.602Z,1578950641.602 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch 30.00 deg, mass-position -22.00 mm (1 active estimators). 2020-01-13T21:24:05.769Z,1578950645.769 [CommandLine](IMPORTANT): got command maintain sensor Depth_Keller.depth 0.000000 meter 2020-01-13T21:24:20.083Z,1578950660.083 [CommandLine](IMPORTANT): got command set NAL9602.time_fix 1578950656.000000 second 2020-01-13T21:24:20.330Z,1578950660.330 [Default:CheckIn:Read_GPS] Stopped 2020-01-13T21:24:20.330Z,1578950660.330 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-01-13T21:24:22.099Z,1578950662.099 [Micromodem](INFO): Outgoing frame #1, 64 bytes: A6D91C5E0A0000005D00000400AE0000000000000000151D80030C5669BF3148E2FA22188B6A3173E6960F887FF8A99E669AC91D474B0DB47F940EC581E0D567 2020-01-13T21:24:22.099Z,1578950662.099 [Micromodem](INFO): Outgoing frame #2, 64 bytes: 266CC0E6F1A517638CB0C0B8BE372A0B00F6D61E05F93094AA77DEFC753FE61F094712E1114D8E0AD7B6106F0F7B016211E5CA62E332602D1D41ACBF7CDB6A31 2020-01-13T21:24:22.100Z,1578950662.100 [Micromodem](INFO): Outgoing frame #3, 35 bytes: 6612EA34F6AB88140473EC40462B9DBD27C021FAFE608C940FAD29C990B0CC68134500 2020-01-13T21:24:22.100Z,1578950662.100 [Micromodem](INFO): Nmea out: $CCCYC,0,1,12,1,0,3*69 2020-01-13T21:24:22.283Z,1578950662.283 [Micromodem](INFO): Nmea in: $CACYC,0,1,12,1,0,3*6B 2020-01-13T21:24:22.627Z,1578950662.627 [Micromodem](INFO): Nmea in: $CADRQ,212423,1,12,0,64,1*70 2020-01-13T21:24:22.627Z,1578950662.627 [Micromodem](INFO): Nmea out: $CCTXD,1,12,1,A6D91C5E0A0000005D00000400AE0000000000000000151D80030C5669BF3148E2FA22188B6A3173E6960F887FF8A99E669AC91D474B0DB47F940EC581E0D567*4C 2020-01-13T21:24:23.031Z,1578950663.031 [Micromodem](INFO): Nmea in: $CATXD,1,12,1,64*4B 2020-01-13T21:24:23.427Z,1578950663.427 [Micromodem](INFO): Nmea in: $CADRQ,212424,1,12,0,64,2*74 2020-01-13T21:24:23.428Z,1578950663.428 [Micromodem](INFO): Nmea out: $CCTXD,1,12,1,266CC0E6F1A517638CB0C0B8BE372A0B00F6D61E05F93094AA77DEFC753FE61F094712E1114D8E0AD7B6106F0F7B016211E5CA62E332602D1D41ACBF7CDB6A31*3C 2020-01-13T21:24:23.835Z,1578950663.835 [Micromodem](INFO): Nmea in: $CATXD,1,12,1,64*4B 2020-01-13T21:24:24.243Z,1578950664.243 [Micromodem](INFO): Nmea in: $CADRQ,212425,1,12,0,64,3*74 2020-01-13T21:24:24.243Z,1578950664.243 [Micromodem](INFO): Nmea out: $CCTXD,1,12,1,6612EA34F6AB88140473EC40462B9DBD27C021FAFE608C940FAD29C990B0CC68134500*43 2020-01-13T21:24:24.639Z,1578950664.639 [Micromodem](INFO): Nmea in: $CATXD,1,12,1,35*4F 2020-01-13T21:24:25.057Z,1578950665.057 [Micromodem](INFO): Nmea in: $CATXP,163*46 2020-01-13T21:24:27.792Z,1578950667.792 [DataOverHttps](INFO): Sending 155 bytes from file Logs/20200113T205710/Courier0010.lzma 2020-01-13T21:24:28.687Z,1578950668.687 [Micromodem](INFO): Nmea in: $CATXF,163*50 2020-01-13T21:24:29.088Z,1578950669.088 [Micromodem](INFO): Nmea in: $CAXST,6,20200113,212426.205550,3,0,200,4000,10000,1,1,12,1,3,3,3,163*71 2020-01-13T21:24:29.798Z,1578950669.798 [DataOverHttps](INFO): Moved sent file to Logs/20200113T205710/Courier0010.lzma.bak 2020-01-13T21:24:29.798Z,1578950669.798 [DataOverHttps](INFO): SBD MOMSN=12191547 2020-01-13T21:24:29.928Z,1578950669.928 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9 2020-01-13T21:24:29.928Z,1578950669.928 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-01-13T21:24:29.962Z,1578950669.962 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-01-13T21:24:30.342Z,1578950670.342 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-01-13T21:24:30.342Z,1578950670.342 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9 2020-01-13T21:24:47.307Z,1578950687.307 [DataOverHttps](INFO): Sending 291 bytes from file Logs/20200110T021610/Express0008.lzma 2020-01-13T21:24:49.310Z,1578950689.310 [DataOverHttps](INFO): Moved sent file to Logs/20200110T021610/Express0008.lzma.bak 2020-01-13T21:24:49.311Z,1578950689.311 [DataOverHttps](INFO): SBD MOMSN=12191549 2020-01-13T21:25:07.749Z,1578950707.749 [DataOverHttps](INFO): Sending 153 bytes from file Logs/20200110T021610/Express0011.lzma 2020-01-13T21:25:09.638Z,1578950709.638 [DataOverHttps](INFO): Moved sent file to Logs/20200110T021610/Express0011.lzma.bak 2020-01-13T21:25:09.638Z,1578950709.638 [DataOverHttps](INFO): SBD MOMSN=12191552 2020-01-13T21:25:27.267Z,1578950727.267 [Micromodem](ERROR): Buffer fill timout failure. 2020-01-13T21:25:28.220Z,1578950728.220 [DataOverHttps](INFO): Sending 1403 bytes from file Logs/20200110T023252/Express0001.lzma 2020-01-13T21:25:28.786Z,1578950728.786 [Micromodem](INFO): Outgoing frame #1, 64 bytes: 54E2175E010007005D00000400AF0E00000000000000151D80030C5669BF31555EAE1409A708D50837CD96632A3B471986A383D0F4DFCC64A6879B643ABEF93C 2020-01-13T21:25:28.786Z,1578950728.786 [Micromodem](INFO): Outgoing frame #2, 64 bytes: 0BCE170D2657F20F775F92A070B2B5290DEC5614CFCA61E9C859ECCA14B64B8B274042E826FE2E218CEE63CB5DB0A997D59F4208459FF3BD2A005AEC32380AE6 2020-01-13T21:25:28.787Z,1578950728.787 [Micromodem](INFO): Outgoing frame #3, 64 bytes: 918687CD86810A1DDD904F20288329F88E0FD0B29CA01D028F436EAD14A66C27E643E7C1CD9E37F6A66C6330C2E8748FF6AABBA2BD6D5E460299E0B69B5C6CE9 2020-01-13T21:25:28.787Z,1578950728.787 [Micromodem](INFO): Nmea out: $CCCYC,0,1,12,1,0,3*69 2020-01-13T21:25:29.746Z,1578950729.746 [Micromodem](INFO): Nmea in: $CACYC,0,1,12,1,0,3*6B 2020-01-13T21:25:30.135Z,1578950730.135 [Micromodem](INFO): Nmea in: $CADRQ,212530,1,12,0,64,1*73 2020-01-13T21:25:30.136Z,1578950730.136 [Micromodem](INFO): Nmea out: $CCTXD,1,12,1,54E2175E010007005D00000400AF0E00000000000000151D80030C5669BF31555EAE1409A708D50837CD96632A3B471986A383D0F4DFCC64A6879B643ABEF93C*3C 2020-01-13T21:25:30.223Z,1578950730.223 [DataOverHttps](INFO): Moved sent file to Logs/20200110T023252/Express0001.lzma.bak 2020-01-13T21:25:30.224Z,1578950730.224 [DataOverHttps](INFO): SBD MOMSN=12191556 2020-01-13T21:25:30.535Z,1578950730.535 [Micromodem](INFO): Nmea in: $CATXD,1,12,1,64*4B 2020-01-13T21:25:30.947Z,1578950730.947 [Micromodem](INFO): Nmea in: $CADRQ,212532,1,12,0,64,2*72 2020-01-13T21:25:30.947Z,1578950730.947 [Micromodem](INFO): Nmea out: $CCTXD,1,12,1,0BCE170D2657F20F775F92A070B2B5290DEC5614CFCA61E9C859ECCA14B64B8B274042E826FE2E218CEE63CB5DB0A997D59F4208459FF3BD2A005AEC32380AE6*4A 2020-01-13T21:25:31.359Z,1578950731.359 [Micromodem](INFO): Nmea in: $CATXD,1,12,1,64*4B 2020-01-13T21:25:31.747Z,1578950731.747 [Micromodem](INFO): Nmea in: $CADRQ,212532,1,12,0,64,3*73 2020-01-13T21:25:31.748Z,1578950731.748 [Micromodem](INFO): Nmea out: $CCTXD,1,12,1,918687CD86810A1DDD904F20288329F88E0FD0B29CA01D028F436EAD14A66C27E643E7C1CD9E37F6A66C6330C2E8748FF6AABBA2BD6D5E460299E0B69B5C6CE9*39 2020-01-13T21:25:32.155Z,1578950732.155 [Micromodem](INFO): Nmea in: $CATXD,1,12,1,64*4B 2020-01-13T21:25:32.208Z,1578950732.208 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2020-01-13T21:25:32.208Z,1578950732.208 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2020-01-13T21:25:32.571Z,1578950732.571 [Micromodem](INFO): Nmea in: $CATXP,192*48 2020-01-13T21:25:36.207Z,1578950736.207 [Micromodem](INFO): Nmea in: $CATXF,192*5E 2020-01-13T21:25:36.596Z,1578950736.596 [Micromodem](INFO): Nmea in: $CAXST,6,20200113,212533.741014,3,0,200,4000,10000,1,1,12,1,3,3,3,192*7A 2020-01-13T21:25:37.859Z,1578950737.859 [CommandLine](IMPORTANT): got command restart application 2020-01-13T21:25:38.865Z,1578950738.865 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2020-01-13T21:25:38.865Z,1578950738.865 [CommandLine ThreadHandler](INFO): Thread cancelled. 2020-01-13T21:25:39.005Z,1578950739.005 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2020-01-13T21:25:39.005Z,1578950739.005 [CommandLine ThreadHandler](INFO): Thread cancelled. 2020-01-13T21:25:39.006Z,1578950739.006 [CommandLine](INFO): Join timeout helper Thread ID is 2386 2020-01-13T21:25:39.029Z,1578950739.029 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2020-01-13T21:25:39.031Z,1578950739.031 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2020-01-13T21:25:39.033Z,1578950739.033 [NavChartDb](INFO): Join timeout helper Thread ID is 2387 2020-01-13T21:25:39.301Z,1578950739.301 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2020-01-13T21:25:39.301Z,1578950739.301 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2020-01-13T21:25:39.313Z,1578950739.313 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler 2020-01-13T21:25:39.313Z,1578950739.313 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled. 2020-01-13T21:25:39.313Z,1578950739.313 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 2388 2020-01-13T21:25:39.329Z,1578950739.329 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread. 2020-01-13T21:25:39.329Z,1578950739.329 [WetLabsSeaOWL_UV_A](INFO): Powering down 2020-01-13T21:25:39.330Z,1578950739.330 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled. 2020-01-13T21:25:39.330Z,1578950739.330 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler 2020-01-13T21:25:39.331Z,1578950739.331 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2020-01-13T21:25:39.331Z,1578950739.331 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 2389 2020-01-13T21:25:39.525Z,1578950739.525 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread. 2020-01-13T21:25:39.525Z,1578950739.525 [CTD_NeilBrown](INFO): Powering down 2020-01-13T21:25:39.537Z,1578950739.537 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2020-01-13T21:25:39.538Z,1578950739.538 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2020-01-13T21:25:39.538Z,1578950739.538 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2020-01-13T21:25:39.538Z,1578950739.538 [Radio_Surface](INFO): Join timeout helper Thread ID is 2390 2020-01-13T21:25:39.913Z,1578950739.913 [Radio_Surface](INFO): Powering down 2020-01-13T21:25:39.914Z,1578950739.914 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2020-01-13T21:25:39.914Z,1578950739.914 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2020-01-13T21:25:39.918Z,1578950739.918 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2020-01-13T21:25:39.918Z,1578950739.918 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2020-01-13T21:25:39.918Z,1578950739.918 [DataOverHttps](INFO): Join timeout helper Thread ID is 2391 2020-01-13T21:25:39.970Z,1578950739.970 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2020-01-13T21:25:39.974Z,1578950739.974 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2020-01-13T21:25:39.993Z,1578950739.993 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2020-01-13T21:25:39.994Z,1578950739.994 [logger ThreadHandler](INFO): Thread cancelled. 2020-01-13T21:25:39.994Z,1578950739.994 [logger](INFO): Join timeout helper Thread ID is 2392 2020-01-13T21:25:39.994Z,1578950739.994 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2020-01-13T21:25:39.995Z,1578950739.995 [logger ThreadHandler](INFO): Thread cancelled. 2020-01-13T21:25:39.996Z,1578950739.996 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2020-01-13T21:25:39.996Z,1578950739.996 [CommandLine ThreadHandler](INFO): Thread cancelled. 2020-01-13T21:25:39.996Z,1578950739.996 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2020-01-13T21:25:39.996Z,1578950739.996 [controlThread ThreadHandler](INFO): Thread cancelled. 2020-01-13T21:25:39.997Z,1578950739.997 [controlThread](INFO): Join timeout helper Thread ID is 2393 2020-01-13T21:25:40.221Z,1578950740.221 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2020-01-13T21:25:40.221Z,1578950740.221 [controlThread](DEBUG): Uninitializing ControlThread 2020-01-13T21:25:40.222Z,1578950740.222 [AHRS_M2](INFO): Powering down 2020-01-13T21:25:40.293Z,1578950740.293 [DDM](INFO): Powering down 2020-01-13T21:25:40.382Z,1578950740.382 [DUSBL_Hydroid](INFO): Powering down 2020-01-13T21:25:40.469Z,1578950740.469 [Micromodem](INFO): Powering down 2020-01-13T21:25:40.565Z,1578950740.565 [NAL9602](INFO): Powering down 2020-01-13T21:25:40.637Z,1578950740.637 [RDI_Pathfinder](INFO): Powering down 2020-01-13T21:25:40.639Z,1578950740.639 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2020-01-13T21:25:40.639Z,1578950740.639 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2020-01-13T21:25:40.640Z,1578950740.640 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2020-01-13T21:25:40.640Z,1578950740.640 [MissionManager](INFO): Uninitializing Mission Default 2020-01-13T21:25:40.640Z,1578950740.640 [Default] Stopped 2020-01-13T21:25:40.641Z,1578950740.641 [Default](DEBUG): Aggregate::uninitialize Default 2020-01-13T21:25:40.641Z,1578950740.641 [Default:B.GoToSurface] Stopped 2020-01-13T21:25:40.641Z,1578950740.641 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2020-01-13T21:25:40.641Z,1578950740.641 [Default:CheckIn] Stopped 2020-01-13T21:25:40.641Z,1578950740.641 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-01-13T21:25:40.641Z,1578950740.641 [Default:CheckIn:Read_Iridium] Stopped 2020-01-13T21:25:40.643Z,1578950740.643 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2020-01-13T21:25:40.644Z,1578950740.644 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2020-01-13T21:25:40.644Z,1578950740.644 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2020-01-13T21:25:40.644Z,1578950740.644 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2020-01-13T21:25:40.644Z,1578950740.644 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2020-01-13T21:25:40.645Z,1578950740.645 [BuoyancyServo](INFO): Powering down 2020-01-13T21:25:40.657Z,1578950740.657 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2020-01-13T21:25:40.657Z,1578950740.657 [ElevatorServo](INFO): Powering down 2020-01-13T21:25:40.658Z,1578950740.658 [MassServo](DEBUG): Uninitialize Mass Servo. 2020-01-13T21:25:40.658Z,1578950740.658 [MassServo](INFO): Powering down 2020-01-13T21:25:40.659Z,1578950740.659 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2020-01-13T21:25:40.659Z,1578950740.659 [RudderServo](INFO): Powering down 2020-01-13T21:25:40.660Z,1578950740.660 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2020-01-13T21:25:40.660Z,1578950740.660 [ThrusterServo](INFO): Powering down 2020-01-13T21:25:40.660Z,1578950740.660 [SBIT](DEBUG): Uninitialize SBIT Component. 2020-01-13T21:25:40.661Z,1578950740.661 [IBIT](DEBUG): Uninitialize IBIT Component. 2020-01-13T21:25:40.661Z,1578950740.661 [CBIT](DEBUG): Uninitialize CBIT Component. 2020-01-13T21:25:40.661Z,1578950740.661 [CBIT](DEBUG): Powering off loads. 2020-01-13T21:25:40.673Z,1578950740.673 [CBIT](DEBUG): Disabling WDT. 2020-01-13T21:25:40.685Z,1578950740.685 [CBIT](DEBUG): Opening all GF detection circuits. 2020-01-13T21:25:40.686Z,1578950740.686 [controlThread ThreadHandler](INFO): Thread cancelled. 2020-01-13T21:25:40.737Z,1578950740.737 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2020-01-13T21:25:40.747Z,1578950740.747 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2020-01-13T21:25:40.788Z,1578950740.788 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled. 2020-01-13T21:25:40.790Z,1578950740.790 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2020-01-13T21:25:40.846Z,1578950740.846 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2020-01-13T21:25:40.905Z,1578950740.905 [logger ThreadHandler](INFO): Thread cancelled.