2016-05-19T22:46:37.164Z,1463697997.164 [Supervisor](DEBUG): Initializing supervisor. 2016-05-19T22:46:37.168Z,1463697997.168 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0 2016-05-19T22:46:37.168Z,1463697997.168 [SyncHandler](INFO): Protected caller Thread ID is 766 2016-05-19T22:46:37.169Z,1463697997.169 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2016-05-19T22:46:37.172Z,1463697997.172 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0 2016-05-19T22:46:37.172Z,1463697997.172 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 767 2016-05-19T22:46:37.175Z,1463697997.175 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2016-05-19T22:46:37.187Z,1463697997.187 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2016-05-19T22:46:37.192Z,1463697997.192 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0 2016-05-19T22:46:37.192Z,1463697997.192 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 768 2016-05-19T22:46:37.193Z,1463697997.193 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2016-05-19T22:46:37.196Z,1463697997.196 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0 2016-05-19T22:46:37.196Z,1463697997.196 [logger ThreadHandler](INFO): Protected caller Thread ID is 769 2016-05-19T22:46:37.198Z,1463697997.198 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2016-05-19T22:46:37.199Z,1463697997.199 [Supervisor](INFO): Looking for Config files in directory: Config/ 2016-05-19T22:46:37.203Z,1463697997.203 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2016-05-19T22:46:37.586Z,1463697997.586 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2016-05-19T22:46:37.588Z,1463697997.588 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2016-05-19T22:46:37.769Z,1463697997.769 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2016-05-19T22:46:37.770Z,1463697997.770 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2016-05-19T22:46:37.909Z,1463697997.909 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2016-05-19T22:46:37.910Z,1463697997.910 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2016-05-19T22:46:38.056Z,1463697998.056 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2016-05-19T22:46:38.058Z,1463697998.058 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2016-05-19T22:46:38.153Z,1463697998.153 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2016-05-19T22:46:38.366Z,1463697998.366 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2016-05-19T22:46:38.367Z,1463697998.367 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2016-05-19T22:46:38.465Z,1463697998.465 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2016-05-19T22:46:38.467Z,1463697998.467 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2016-05-19T22:46:38.771Z,1463697998.771 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2016-05-19T22:46:38.772Z,1463697998.772 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2016-05-19T22:46:39.152Z,1463697999.152 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2016-05-19T22:46:39.152Z,1463697999.152 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2016-05-19T22:46:39.486Z,1463697999.486 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2016-05-19T22:46:39.487Z,1463697999.487 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2016-05-19T22:46:40.045Z,1463698000.045 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2016-05-19T22:46:40.046Z,1463698000.046 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2016-05-19T22:46:40.274Z,1463698000.274 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2016-05-19T22:46:40.274Z,1463698000.274 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2016-05-19T22:46:40.389Z,1463698000.389 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2016-05-19T22:46:40.390Z,1463698000.390 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2016-05-19T22:46:40.878Z,1463698000.878 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2016-05-19T22:46:40.878Z,1463698000.878 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2016-05-19T22:46:41.051Z,1463698001.051 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2016-05-19T22:46:41.053Z,1463698001.053 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/ 2016-05-19T22:46:41.056Z,1463698001.056 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg 2016-05-19T22:46:41.323Z,1463698001.323 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2016-05-19T22:46:41.324Z,1463698001.324 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg 2016-05-19T22:46:41.456Z,1463698001.456 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg 2016-05-19T22:46:41.564Z,1463698001.564 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg 2016-05-19T22:46:41.672Z,1463698001.672 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg 2016-05-19T22:46:41.772Z,1463698001.772 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg 2016-05-19T22:46:41.928Z,1463698001.928 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg 2016-05-19T22:46:42.107Z,1463698002.107 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg 2016-05-19T22:46:42.221Z,1463698002.221 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg 2016-05-19T22:46:42.315Z,1463698002.315 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg 2016-05-19T22:46:42.417Z,1463698002.417 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg 2016-05-19T22:46:42.613Z,1463698002.613 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2016-05-19T22:46:42.616Z,1463698002.616 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2016-05-19T22:46:42.764Z,1463698002.764 [SBIT](DEBUG): Construct Startup Built In Test. 2016-05-19T22:46:42.804Z,1463698002.804 [SBIT] Loaded 2016-05-19T22:46:42.804Z,1463698002.804 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2016-05-19T22:46:42.805Z,1463698002.805 [IBIT](DEBUG): Construct Initiated Built In Test. 2016-05-19T22:46:42.833Z,1463698002.833 [IBIT] Loaded 2016-05-19T22:46:42.833Z,1463698002.833 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2016-05-19T22:46:42.835Z,1463698002.835 [CBIT](DEBUG): Construct Continuous Built In Test. 2016-05-19T22:46:42.989Z,1463698002.989 [CBIT] Loaded 2016-05-19T22:46:42.989Z,1463698002.989 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2016-05-19T22:46:42.990Z,1463698002.990 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2016-05-19T22:46:42.991Z,1463698002.991 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2016-05-19T22:46:43.059Z,1463698003.059 [VerticalControl](DEBUG): Construct VerticalControl. 2016-05-19T22:46:43.172Z,1463698003.172 [VerticalControl] Loaded 2016-05-19T22:46:43.173Z,1463698003.173 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2016-05-19T22:46:43.174Z,1463698003.174 [HorizontalControl](DEBUG): Construct HorizontalControl. 2016-05-19T22:46:43.239Z,1463698003.239 [HorizontalControl] Loaded 2016-05-19T22:46:43.239Z,1463698003.239 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2016-05-19T22:46:43.240Z,1463698003.240 [SpeedControl](DEBUG): Construct SpeedControl. 2016-05-19T22:46:43.246Z,1463698003.246 [SpeedControl] Loaded 2016-05-19T22:46:43.246Z,1463698003.246 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2016-05-19T22:46:43.247Z,1463698003.247 [LoopControl](DEBUG): Construct LoopControl. 2016-05-19T22:46:43.247Z,1463698003.247 [LoopControl] Loaded 2016-05-19T22:46:43.247Z,1463698003.247 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2016-05-19T22:46:43.248Z,1463698003.248 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2016-05-19T22:46:43.248Z,1463698003.248 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2016-05-19T22:46:43.293Z,1463698003.293 [DepthRateCalculator] Loaded 2016-05-19T22:46:43.293Z,1463698003.293 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2016-05-19T22:46:43.298Z,1463698003.298 [PitchRateCalculator] Loaded 2016-05-19T22:46:43.299Z,1463698003.299 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2016-05-19T22:46:43.310Z,1463698003.310 [SpeedCalculator] Loaded 2016-05-19T22:46:43.310Z,1463698003.310 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2016-05-19T22:46:43.330Z,1463698003.330 [TempGradientCalculator] Loaded 2016-05-19T22:46:43.330Z,1463698003.330 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2016-05-19T22:46:43.347Z,1463698003.347 [VerticalTemperatureHomogeneityIndexCalculator] Loaded 2016-05-19T22:46:43.347Z,1463698003.347 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread. 2016-05-19T22:46:43.352Z,1463698003.352 [YawRateCalculator] Loaded 2016-05-19T22:46:43.352Z,1463698003.352 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2016-05-19T22:46:43.353Z,1463698003.353 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2016-05-19T22:46:43.354Z,1463698003.354 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2016-05-19T22:46:43.475Z,1463698003.475 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC 2016-05-19T22:46:43.475Z,1463698003.475 [StratificationFrontDetector](DEBUG): (re)initializing 2016-05-19T22:46:43.476Z,1463698003.476 [StratificationFrontDetector] Loaded 2016-05-19T22:46:43.476Z,1463698003.476 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread. 2016-05-19T22:46:43.476Z,1463698003.476 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2016-05-19T22:46:43.477Z,1463698003.477 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2016-05-19T22:46:43.751Z,1463698003.751 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2016-05-19T22:46:43.752Z,1463698003.752 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2016-05-19T22:46:43.878Z,1463698003.878 [DeadReckonUsingMultipleVelocitySources] Loaded 2016-05-19T22:46:43.879Z,1463698003.879 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2016-05-19T22:46:43.937Z,1463698003.937 [DeadReckonUsingSpeedCalculator] Loaded 2016-05-19T22:46:43.937Z,1463698003.937 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2016-05-19T22:46:43.958Z,1463698003.958 [NavChart] Loaded 2016-05-19T22:46:43.958Z,1463698003.958 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2016-05-19T22:46:43.963Z,1463698003.963 [UniversalFixResidualReporter] Loaded 2016-05-19T22:46:43.963Z,1463698003.963 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2016-05-19T22:46:43.963Z,1463698003.963 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2016-05-19T22:46:43.964Z,1463698003.964 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2016-05-19T22:46:43.972Z,1463698003.972 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2016-05-19T22:46:43.973Z,1463698003.973 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2016-05-19T22:46:44.197Z,1463698004.197 [Aanderaa_O2] Loaded 2016-05-19T22:46:44.198Z,1463698004.198 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread. 2016-05-19T22:46:44.282Z,1463698004.282 [CTD_NeilBrown] Loaded 2016-05-19T22:46:44.282Z,1463698004.282 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2016-05-19T22:46:44.287Z,1463698004.287 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4059E4E0 2016-05-19T22:46:44.287Z,1463698004.287 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 848 2016-05-19T22:46:44.302Z,1463698004.302 [PAR_Licor] Loaded 2016-05-19T22:46:44.302Z,1463698004.302 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2016-05-19T22:46:44.359Z,1463698004.359 [WetLabsBB2FL] Loaded 2016-05-19T22:46:44.359Z,1463698004.359 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2016-05-19T22:46:44.363Z,1463698004.363 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 405CE4E0 2016-05-19T22:46:44.363Z,1463698004.363 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 849 2016-05-19T22:46:44.364Z,1463698004.364 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2016-05-19T22:46:44.364Z,1463698004.364 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2016-05-19T22:46:46.201Z,1463698006.201 [AcousticModem_Benthos_ATM900] Loaded 2016-05-19T22:46:46.201Z,1463698006.201 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread. 2016-05-19T22:46:46.377Z,1463698006.377 [DataOverHttps] Loaded 2016-05-19T22:46:46.382Z,1463698006.382 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2016-05-19T22:46:46.395Z,1463698006.395 [Depth_Keller] Loaded 2016-05-19T22:46:46.396Z,1463698006.396 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2016-05-19T22:46:46.400Z,1463698006.400 [DropWeight] Loaded 2016-05-19T22:46:46.401Z,1463698006.401 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2016-05-19T22:46:46.499Z,1463698006.499 [NAL9602] Loaded 2016-05-19T22:46:46.500Z,1463698006.500 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2016-05-19T22:46:46.545Z,1463698006.545 [Onboard] Loaded 2016-05-19T22:46:46.546Z,1463698006.546 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2016-05-19T22:46:46.553Z,1463698006.553 [Radio_Surface] Loaded 2016-05-19T22:46:46.553Z,1463698006.553 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2016-05-19T22:46:46.554Z,1463698006.554 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409E44E0 2016-05-19T22:46:46.554Z,1463698006.554 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 850 2016-05-19T22:46:46.763Z,1463698006.763 [PNI_TCM] Loaded 2016-05-19T22:46:46.763Z,1463698006.763 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread. 2016-05-19T22:46:48.751Z,1463698008.751 [BPC1] Loaded 2016-05-19T22:46:48.751Z,1463698008.751 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2016-05-19T22:46:48.752Z,1463698008.752 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2016-05-19T22:46:48.753Z,1463698008.753 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2016-05-19T22:46:48.883Z,1463698008.883 [BuoyancyServo] Loaded 2016-05-19T22:46:48.884Z,1463698008.884 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2016-05-19T22:46:48.896Z,1463698008.896 [ElevatorServo] Loaded 2016-05-19T22:46:48.896Z,1463698008.896 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2016-05-19T22:46:48.908Z,1463698008.908 [MassServo] Loaded 2016-05-19T22:46:48.908Z,1463698008.908 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2016-05-19T22:46:48.925Z,1463698008.925 [RudderServo] Loaded 2016-05-19T22:46:48.925Z,1463698008.925 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2016-05-19T22:46:48.936Z,1463698008.936 [ThrusterServo] Loaded 2016-05-19T22:46:48.937Z,1463698008.937 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2016-05-19T22:46:48.937Z,1463698008.937 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2016-05-19T22:46:48.938Z,1463698008.938 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2016-05-19T22:46:49.073Z,1463698009.073 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2016-05-19T22:46:49.073Z,1463698009.073 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2016-05-19T22:46:49.116Z,1463698009.116 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2016-05-19T22:46:49.120Z,1463698009.120 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2016-05-19T22:46:49.121Z,1463698009.121 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2016-05-19T22:46:49.128Z,1463698009.128 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2016-05-19T22:46:49.134Z,1463698009.134 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A924E0 2016-05-19T22:46:49.134Z,1463698009.134 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 851 2016-05-19T22:46:49.139Z,1463698009.139 [Supervisor](INFO): Main Thread ID is 765 2016-05-19T22:46:49.139Z,1463698009.139 [Supervisor](DEBUG): Running supervisor. 2016-05-19T22:46:49.140Z,1463698009.140 [CommandLine ThreadHandler](INFO): Handler Thread ID is 852 2016-05-19T22:46:49.147Z,1463698009.147 [controlThread ThreadHandler](INFO): Handler Thread ID is 853 2016-05-19T22:46:49.147Z,1463698009.147 [controlThread](DEBUG): Initializing ControlThread 2016-05-19T22:46:49.148Z,1463698009.148 [SBIT](INFO): Initialize SBIT Component. 2016-05-19T22:46:49.148Z,1463698009.148 [SBIT](IMPORTANT): git: 2015-11-13-11-g036008f 2016-05-19T22:46:49.149Z,1463698009.149 [SBIT](INFO): git hash: 036008fb27dd1443c9c6898c567944386f491f02 2016-05-19T22:46:49.149Z,1463698009.149 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2016-05-19T22:46:49.149Z,1463698009.149 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014 2016-05-19T22:46:49.150Z,1463698009.150 [SBIT](INFO): Beginning SBIT in 63.000000 seconds. 2016-05-19T22:46:49.151Z,1463698009.151 [IBIT](INFO): Initialize IBIT Component. 2016-05-19T22:46:49.151Z,1463698009.151 [CBIT](DEBUG): Initialize CBIT Component. 2016-05-19T22:46:49.152Z,1463698009.152 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL. 2016-05-19T22:46:49.152Z,1463698009.152 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET. 2016-05-19T22:46:49.155Z,1463698009.155 [logger ThreadHandler](INFO): Handler Thread ID is 854 2016-05-19T22:46:49.178Z,1463698009.178 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2016-05-19T22:46:49.180Z,1463698009.180 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2016-05-19T22:46:49.181Z,1463698009.181 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2016-05-19T22:46:49.181Z,1463698009.181 [LoopControl](DEBUG): Initialize LoopControlComponent. 2016-05-19T22:46:49.182Z,1463698009.182 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2016-05-19T22:46:49.182Z,1463698009.182 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2016-05-19T22:46:49.182Z,1463698009.182 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2016-05-19T22:46:49.183Z,1463698009.183 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2016-05-19T22:46:49.183Z,1463698009.183 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing 2016-05-19T22:46:49.184Z,1463698009.184 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2016-05-19T22:46:49.185Z,1463698009.185 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2016-05-19T22:46:49.185Z,1463698009.185 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s. 2016-05-19T22:46:49.186Z,1463698009.186 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s. 2016-05-19T22:46:49.186Z,1463698009.186 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2016-05-19T22:46:49.187Z,1463698009.187 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2016-05-19T22:46:49.187Z,1463698009.187 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2016-05-19T22:46:49.187Z,1463698009.187 [NavChart](DEBUG): Initialize NavChart Navigation. 2016-05-19T22:46:49.188Z,1463698009.188 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2016-05-19T22:46:49.196Z,1463698009.196 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2016-05-19T22:46:49.211Z,1463698009.211 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 855 2016-05-19T22:46:49.212Z,1463698009.212 [CTD_NeilBrown](INFO): Powering down 2016-05-19T22:46:49.235Z,1463698009.235 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 856 2016-05-19T22:46:49.238Z,1463698009.238 [WetLabsBB2FL](INFO): Powering down 2016-05-19T22:46:49.248Z,1463698009.248 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2016-05-19T22:46:49.271Z,1463698009.271 [MissionManager](DEBUG): 2016-05-19T22:46:49.272Z,1463698009.272 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2016-05-19T22:46:49.283Z,1463698009.283 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 857 2016-05-19T22:46:49.292Z,1463698009.292 [Radio_Surface](INFO): Powering up 2016-05-19T22:46:49.303Z,1463698009.303 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 858 2016-05-19T22:46:49.309Z,1463698009.309 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources/ElectronicNavigationCharts 2016-05-19T22:46:49.312Z,1463698009.312 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2016-05-19T22:46:49.313Z,1463698009.313 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2016-05-19T22:46:49.313Z,1463698009.313 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2016-05-19T22:46:49.313Z,1463698009.313 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2016-05-19T22:46:49.313Z,1463698009.313 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2016-05-19T22:46:49.313Z,1463698009.313 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2016-05-19T22:46:49.314Z,1463698009.314 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2016-05-19T22:46:49.314Z,1463698009.314 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2016-05-19T22:46:49.366Z,1463698009.366 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2016-05-19T22:46:49.382Z,1463698009.382 [Default:A.Wait](DEBUG): Construct Wait. 2016-05-19T22:46:49.384Z,1463698009.384 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2016-05-19T22:46:49.407Z,1463698009.407 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2016-05-19T22:46:49.409Z,1463698009.409 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2016-05-19T22:46:49.431Z,1463698009.431 [Default:E.Execute](DEBUG): Construct Execute. 2016-05-19T22:46:49.451Z,1463698009.451 [MissionManager](DEBUG): 0 Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. 13 Burn 300 Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2016-05-19T22:46:49.456Z,1463698009.456 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,PAR_Licor,AcousticModem_Benthos_ATM900,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,StratificationFrontDetector,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2016-05-19T22:46:49.571Z,1463698009.571 [AcousticModem_Benthos_ATM900](INFO): Powering up 2016-05-19T22:46:49.571Z,1463698009.571 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900. 2016-05-19T22:46:50.124Z,1463698010.124 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2016-05-19T22:46:50.362Z,1463698010.362 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-19T22:46:50.471Z,1463698010.471 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2016-05-19T22:46:50.480Z,1463698010.480 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2016-05-19T22:46:50.499Z,1463698010.499 [ElevatorServo](DEBUG): Initializing EZServoServo. 2016-05-19T22:46:50.508Z,1463698010.508 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2016-05-19T22:46:50.528Z,1463698010.528 [MassServo](DEBUG): Initializing EZServoServo. 2016-05-19T22:46:50.537Z,1463698010.537 [MassServo](DEBUG): Initializing MassServo. 2016-05-19T22:46:50.562Z,1463698010.562 [RudderServo](DEBUG): Initializing EZServoServo. 2016-05-19T22:46:50.569Z,1463698010.569 [RudderServo](DEBUG): Initializing RudderServo. 2016-05-19T22:46:50.582Z,1463698010.582 [ThrusterServo](DEBUG): Initializing EZServoServo. 2016-05-19T22:46:50.589Z,1463698010.589 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2016-05-19T22:46:50.614Z,1463698010.614 [CommandLine](FAULT): Scheduling is paused 2016-05-19T22:46:50.796Z,1463698010.796 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2016-05-19T22:46:50.805Z,1463698010.805 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-19T22:46:51.205Z,1463698011.205 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2016-05-19T22:46:51.207Z,1463698011.207 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-19T22:46:51.620Z,1463698011.620 [NAL9602](INFO): Powering up NAL9602 2016-05-19T22:46:51.694Z,1463698011.694 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2016-05-19T22:46:51.695Z,1463698011.695 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-19T22:46:52.098Z,1463698012.098 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2016-05-19T22:46:52.104Z,1463698012.104 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-19T22:46:52.436Z,1463698012.436 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2016-05-19T22:46:52.437Z,1463698012.437 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-19T22:46:52.936Z,1463698012.936 [Aanderaa_O2](INFO): Powering down 2016-05-19T22:46:53.096Z,1463698013.096 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2016-05-19T22:46:53.098Z,1463698013.098 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-19T22:46:53.302Z,1463698013.302 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2016-05-19T22:46:53.304Z,1463698013.304 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-19T22:46:56.947Z,1463698016.947 [AcousticModem_Benthos_ATM900](DEBUG): 2016-05-19T22:46:58.543Z,1463698018.543 [AcousticModem_Benthos_ATM900](DEBUG): Teledyne Benthos ATM-900 Series OEM w/burn wire 2016-05-19T22:46:58.544Z,1463698018.544 [AcousticModem_Benthos_ATM900](DEBUG): MF Frequency Band 2016-05-19T22:46:58.544Z,1463698018.544 [AcousticModem_Benthos_ATM900](DEBUG): Standard version 8.6.3 2016-05-19T22:46:58.947Z,1463698018.947 [AcousticModem_Benthos_ATM900](DEBUG): May 19 2016 22:38:12 2016-05-19T22:46:59.768Z,1463698019.768 [AcousticModem_Benthos_ATM900](INFO): entering command mode 2016-05-19T22:47:00.144Z,1463698020.144 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgment 2016-05-19T22:47:00.145Z,1463698020.145 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 1: user:1> 2016-05-19T22:47:00.145Z,1463698020.145 [AcousticModem_Benthos_ATM900](INFO): command mode acknowledged 2016-05-19T22:47:00.549Z,1463698020.549 [AcousticModem_Benthos_ATM900](INFO): setting local address to 3 2016-05-19T22:47:00.945Z,1463698020.945 [AcousticModem_Benthos_ATM900](DEBUG): checking for local address setting acknowledgment 2016-05-19T22:47:00.946Z,1463698020.946 [AcousticModem_Benthos_ATM900](INFO): set local address to 3 2016-05-19T22:47:01.347Z,1463698021.347 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 2: user:2> 2016-05-19T22:47:02.553Z,1463698022.553 [NAL9602](INFO): NAL9602 initialized 2016-05-19T22:47:06.196Z,1463698026.196 [BPC1](ERROR): Failed to receive battery data 2016-05-19T22:47:06.208Z,1463698026.208 [BPC1] Communications Fault, FailCount= 1 2016-05-19T22:47:06.209Z,1463698026.209 [BPC1](ERROR): Communications Fault 2016-05-19T22:47:06.288Z,1463698026.288 [CBIT](ERROR): Communications Fault in component: BPC1 2016-05-19T22:47:07.582Z,1463698027.582 [CBIT](INFO): Clearing failed state for component BPC1 2016-05-19T22:47:07.582Z,1463698027.582 [BPC1] No Fault, FailCount= 1 2016-05-19T22:47:52.703Z,1463698072.703 [SBIT](IMPORTANT): Beginning Startup BIT 2016-05-19T22:47:52.710Z,1463698072.710 [CBIT](IMPORTANT): Beginning GF scan 2016-05-19T22:48:19.008Z,1463698099.008 [CBIT](IMPORTANT): No ground fault detected 2016-05-19T22:48:28.595Z,1463698108.595 [DataOverHttps](DEBUG): dataRead() @791 received: vehicle=makai&busy=false, 1 2016-05-19T22:48:28.595Z,1463698108.595 [DataOverHttps](DEBUG): ParseDataRead( data = busy=false, key = 6, value = makai 2016-05-19T22:48:28.596Z,1463698108.596 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 0, value = false 2016-05-19T22:48:28.599Z,1463698108.599 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004706 2016-05-19T22:48:46.781Z,1463698126.781 [SBIT](IMPORTANT): SBIT PASSED 2016-05-19T22:48:47.154Z,1463698127.154 [MissionManager](IMPORTANT): Started mission Startup 2016-05-19T22:48:47.154Z,1463698127.154 [Startup] Running Loop=1 2016-05-19T22:48:47.155Z,1463698127.155 [Startup](DEBUG): Aggregate::initialize Startup 2016-05-19T22:48:47.155Z,1463698127.155 [Startup:A.GoToSurface] Running Loop=1 2016-05-19T22:48:47.155Z,1463698127.155 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2016-05-19T22:48:47.155Z,1463698127.155 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2016-05-19T22:48:47.156Z,1463698127.156 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2016-05-19T22:48:47.156Z,1463698127.156 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2016-05-19T22:48:47.156Z,1463698127.156 [Startup:A.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds. 2016-05-19T22:48:47.157Z,1463698127.157 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2016-05-19T22:48:47.163Z,1463698127.163 [Startup:StartupSatComms] Running Loop=1 2016-05-19T22:48:47.163Z,1463698127.163 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2016-05-19T22:48:47.163Z,1463698127.163 [Startup:StartupSatComms:A] Running Loop=1 2016-05-19T22:48:47.610Z,1463698127.610 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2016-05-19T22:49:20.106Z,1463698160.106 [DataOverHttps](DEBUG): dataRead() @791 received: vehicle=makai&busy=false, 1 2016-05-19T22:49:20.107Z,1463698160.107 [DataOverHttps](DEBUG): ParseDataRead( data = busy=false, key = 6, value = makai 2016-05-19T22:49:20.108Z,1463698160.108 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 0, value = false 2016-05-19T22:49:36.125Z,1463698176.125 [BPC1](ERROR): Failed to receive battery data 2016-05-19T22:49:36.125Z,1463698176.125 [BPC1] Communications Fault, FailCount= 1 2016-05-19T22:49:36.125Z,1463698176.125 [BPC1](ERROR): Communications Fault 2016-05-19T22:49:36.145Z,1463698176.145 [CBIT](ERROR): Communications Fault in component: BPC1 2016-05-19T22:49:37.349Z,1463698177.349 [CBIT](INFO): Clearing failed state for component BPC1 2016-05-19T22:49:37.349Z,1463698177.349 [BPC1] No Fault, FailCount= 1 2016-05-19T22:49:47.341Z,1463698187.341 [Startup:StartupSatComms:A](INFO): Timed out from 2016-05-19T22:48:47.2Z 2016-05-19T22:49:47.341Z,1463698187.341 [Startup:StartupSatComms:A] Stopped 2016-05-19T22:49:47.341Z,1463698187.341 [Startup:StartupSatComms:B] Running Loop=1 2016-05-19T22:49:47.737Z,1463698187.737 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2016-05-19T22:49:51.880Z,1463698191.880 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2016-05-19T22:49:51.880Z,1463698191.880 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2016-05-19T22:49:51.880Z,1463698191.880 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2016-05-19T22:49:51.882Z,1463698191.882 [DeadReckonUsingSpeedCalculator](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2016-05-19T22:49:51.882Z,1463698191.882 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1 2016-05-19T22:49:51.883Z,1463698191.883 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2016-05-19T22:49:51.894Z,1463698191.894 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2016-05-19T22:49:51.894Z,1463698191.894 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2016-05-19T22:49:51.963Z,1463698191.963 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20160519T213031/Courier0032.lzma 2016-05-19T22:49:52.032Z,1463698192.032 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2016-05-19T22:49:52.032Z,1463698192.032 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2016-05-19T22:49:52.033Z,1463698192.033 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2016-05-19T22:49:52.033Z,1463698192.033 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1 2016-05-19T22:49:52.360Z,1463698192.360 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2016-05-19T22:49:52.361Z,1463698192.361 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s. 2016-05-19T22:49:52.361Z,1463698192.361 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s. 2016-05-19T22:49:52.361Z,1463698192.361 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2016-05-19T22:49:52.362Z,1463698192.362 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2016-05-19T22:49:52.362Z,1463698192.362 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2016-05-19T22:49:52.709Z,1463698192.709 [DataOverHttps](DEBUG): dataRead() @791 received: vehicle=makai&busy=true&momsn=4115104&filename=Logs%2F20160519T213031%2FCourier0032.lzma, 1 2016-05-19T22:49:52.710Z,1463698192.710 [DataOverHttps](DEBUG): ParseDataRead( data = busy=true&momsn=4115104&filename=Logs%2F20160519T213031%2FCourier0032.lzma, key = 6, value = makai 2016-05-19T22:49:52.710Z,1463698192.710 [DataOverHttps](DEBUG): ParseDataRead( data = momsn=4115104&filename=Logs%2F20160519T213031%2FCourier0032.lzma, key = 0, value = true 2016-05-19T22:49:52.711Z,1463698192.711 [DataOverHttps](DEBUG): ParseDataRead( data = filename=Logs%2F20160519T213031%2FCourier0032.lzma, key = 4, value = 4115104 2016-05-19T22:49:52.711Z,1463698192.711 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 2, value = Logs%2F20160519T213031%2FCourier0032.lzma 2016-05-19T22:49:52.712Z,1463698192.712 [DataOverHttps](INFO): Moved sent file to Logs/20160519T213031/Courier0032.lzma.bak 2016-05-19T22:49:52.712Z,1463698192.712 [DataOverHttps](INFO): SBD MOMSN=4115104 2016-05-19T22:49:52.801Z,1463698192.801 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 0.9 s old, using for 20.0 s. 2016-05-19T22:49:53.152Z,1463698193.152 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.3 s old, using for 20.0 s. 2016-05-19T22:49:53.581Z,1463698193.581 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.7 s old, using for 20.0 s. 2016-05-19T22:49:56.808Z,1463698196.808 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.9 s old, using for 20.0 s. 2016-05-19T22:49:56.944Z,1463698196.944 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.1 s old, using for 20.0 s. 2016-05-19T22:49:57.307Z,1463698197.307 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.4 s old, using for 20.0 s. 2016-05-19T22:49:57.635Z,1463698197.635 [DataOverHttps](DEBUG): dataRead() @791 received: vehicle=makai&busy=false, 1 2016-05-19T22:49:57.636Z,1463698197.636 [DataOverHttps](DEBUG): ParseDataRead( data = busy=false, key = 6, value = makai 2016-05-19T22:49:57.636Z,1463698197.636 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 0, value = false 2016-05-19T22:49:57.703Z,1463698197.703 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.8 s old, using for 20.0 s. 2016-05-19T22:49:58.056Z,1463698198.056 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.2 s old, using for 20.0 s. 2016-05-19T22:49:58.467Z,1463698198.467 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.6 s old, using for 20.0 s. 2016-05-19T22:50:01.698Z,1463698201.698 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.8 s old, using for 20.0 s. 2016-05-19T22:50:01.783Z,1463698201.783 [DataOverHttps](INFO): Sending 99 bytes from file Logs/20160519T224637/Courier0000.lzma 2016-05-19T22:50:01.847Z,1463698201.847 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.0 s old, using for 20.0 s. 2016-05-19T22:50:02.176Z,1463698202.176 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.3 s old, using for 20.0 s. 2016-05-19T22:50:02.528Z,1463698202.528 [DataOverHttps](DEBUG): dataRead() @791 received: vehicle=makai&busy=true&momsn=4115106&filename=Logs%2F20160519T224637%2FCourier0000.lzma, 1 2016-05-19T22:50:02.529Z,1463698202.529 [DataOverHttps](DEBUG): ParseDataRead( data = busy=true&momsn=4115106&filename=Logs%2F20160519T224637%2FCourier0000.lzma, key = 6, value = makai 2016-05-19T22:50:02.529Z,1463698202.529 [DataOverHttps](DEBUG): ParseDataRead( data = momsn=4115106&filename=Logs%2F20160519T224637%2FCourier0000.lzma, key = 0, value = true 2016-05-19T22:50:02.538Z,1463698202.538 [DataOverHttps](DEBUG): ParseDataRead( data = filename=Logs%2F20160519T224637%2FCourier0000.lzma, key = 4, value = 4115106 2016-05-19T22:50:02.538Z,1463698202.538 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 2, value = Logs%2F20160519T224637%2FCourier0000.lzma 2016-05-19T22:50:02.539Z,1463698202.539 [DataOverHttps](INFO): Moved sent file to Logs/20160519T224637/Courier0000.lzma.bak 2016-05-19T22:50:02.539Z,1463698202.539 [DataOverHttps](INFO): SBD MOMSN=4115106 2016-05-19T22:50:02.610Z,1463698202.610 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.7 s old, using for 20.0 s. 2016-05-19T22:50:03.054Z,1463698203.054 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.2 s old, using for 20.0 s. 2016-05-19T22:50:03.366Z,1463698203.366 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.5 s old, using for 20.0 s. 2016-05-19T22:50:06.627Z,1463698206.627 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.7 s old, using for 20.0 s. 2016-05-19T22:50:06.758Z,1463698206.758 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.9 s old, using for 20.0 s. 2016-05-19T22:50:07.154Z,1463698207.154 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.3 s old, using for 20.0 s. 2016-05-19T22:50:07.492Z,1463698207.492 [DataOverHttps](DEBUG): dataRead() @791 received: vehicle=makai&busy=false, 1 2016-05-19T22:50:07.492Z,1463698207.492 [DataOverHttps](DEBUG): ParseDataRead( data = busy=false, key = 6, value = makai 2016-05-19T22:50:07.493Z,1463698207.493 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 0, value = false 2016-05-19T22:50:07.561Z,1463698207.561 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.7 s old, using for 20.0 s. 2016-05-19T22:50:07.918Z,1463698207.918 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.0 s old, using for 20.0 s. 2016-05-19T22:50:08.327Z,1463698208.327 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.4 s old, using for 20.0 s. 2016-05-19T22:50:11.641Z,1463698211.641 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 19.8 s old, using for 20.0 s. 2016-05-19T22:50:11.729Z,1463698211.729 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20160519T213031/Express0033.lzma 2016-05-19T22:50:11.786Z,1463698211.786 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 19.9 s old, using for 20.0 s. 2016-05-19T22:50:12.468Z,1463698212.468 [DataOverHttps](DEBUG): dataRead() @791 received: vehicle=makai&busy=true&momsn=4115110&filename=Logs%2F20160519T213031%2FExpress0033.lzma, 1 2016-05-19T22:50:12.468Z,1463698212.468 [DataOverHttps](DEBUG): ParseDataRead( data = busy=true&momsn=4115110&filename=Logs%2F20160519T213031%2FExpress0033.lzma, key = 6, value = makai 2016-05-19T22:50:12.469Z,1463698212.469 [DataOverHttps](DEBUG): ParseDataRead( data = momsn=4115110&filename=Logs%2F20160519T213031%2FExpress0033.lzma, key = 0, value = true 2016-05-19T22:50:12.469Z,1463698212.469 [DataOverHttps](DEBUG): ParseDataRead( data = filename=Logs%2F20160519T213031%2FExpress0033.lzma, key = 4, value = 4115110 2016-05-19T22:50:12.470Z,1463698212.470 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 2, value = Logs%2F20160519T213031%2FExpress0033.lzma 2016-05-19T22:50:12.471Z,1463698212.471 [DataOverHttps](INFO): Moved sent file to Logs/20160519T213031/Express0033.lzma.bak 2016-05-19T22:50:12.471Z,1463698212.471 [DataOverHttps](INFO): SBD MOMSN=4115110 2016-05-19T22:50:17.379Z,1463698217.379 [DataOverHttps](DEBUG): dataRead() @791 received: vehicle=makai&busy=false, 1 2016-05-19T22:50:17.380Z,1463698217.380 [DataOverHttps](DEBUG): ParseDataRead( data = busy=false, key = 6, value = makai 2016-05-19T22:50:17.380Z,1463698217.380 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 0, value = false 2016-05-19T22:50:21.546Z,1463698221.546 [DataOverHttps](INFO): Sending 517 bytes from file Logs/20160519T224637/Express0001.lzma 2016-05-19T22:50:22.287Z,1463698222.287 [DataOverHttps](DEBUG): dataRead() @791 received: vehicle=makai&busy=true&momsn=4115112&filename=Logs%2F20160519T224637%2FExpress0001.lzma, 1 2016-05-19T22:50:22.288Z,1463698222.288 [DataOverHttps](DEBUG): ParseDataRead( data = busy=true&momsn=4115112&filename=Logs%2F20160519T224637%2FExpress0001.lzma, key = 6, value = makai 2016-05-19T22:50:22.288Z,1463698222.288 [DataOverHttps](DEBUG): ParseDataRead( data = momsn=4115112&filename=Logs%2F20160519T224637%2FExpress0001.lzma, key = 0, value = true 2016-05-19T22:50:22.289Z,1463698222.289 [DataOverHttps](DEBUG): ParseDataRead( data = filename=Logs%2F20160519T224637%2FExpress0001.lzma, key = 4, value = 4115112 2016-05-19T22:50:22.289Z,1463698222.289 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 2, value = Logs%2F20160519T224637%2FExpress0001.lzma 2016-05-19T22:50:22.290Z,1463698222.290 [DataOverHttps](INFO): Moved sent file to Logs/20160519T224637/Express0001.lzma.bak 2016-05-19T22:50:22.290Z,1463698222.290 [DataOverHttps](INFO): SBD MOMSN=4115112 2016-05-19T22:50:22.736Z,1463698222.736 [Startup:StartupSatComms:B] Stopped 2016-05-19T22:50:22.736Z,1463698222.736 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2016-05-19T22:50:22.736Z,1463698222.736 [Startup:StartupSatComms] Stopped 2016-05-19T22:50:22.736Z,1463698222.736 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2016-05-19T22:50:22.737Z,1463698222.737 [Startup](INFO): Completed Startup 2016-05-19T22:50:22.737Z,1463698222.737 [Startup] Stopped 2016-05-19T22:50:22.737Z,1463698222.737 [Startup](DEBUG): Aggregate::uninitialize Startup 2016-05-19T22:50:22.737Z,1463698222.737 [Startup:A.GoToSurface] Stopped 2016-05-19T22:50:22.738Z,1463698222.738 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2016-05-19T22:50:23.131Z,1463698223.131 [MissionManager](IMPORTANT): Started mission Default 2016-05-19T22:50:23.131Z,1463698223.131 [Default] Running Loop=1 2016-05-19T22:50:23.131Z,1463698223.131 [Default](DEBUG): Aggregate::initialize Default 2016-05-19T22:50:23.131Z,1463698223.131 [Default:B.GoToSurface] Running Loop=1 2016-05-19T22:50:23.131Z,1463698223.131 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2016-05-19T22:50:23.132Z,1463698223.132 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2016-05-19T22:50:23.132Z,1463698223.132 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2016-05-19T22:50:23.132Z,1463698223.132 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2016-05-19T22:50:23.133Z,1463698223.133 [Default:B.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds. 2016-05-19T22:50:23.133Z,1463698223.133 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2016-05-19T22:50:23.133Z,1463698223.133 [Default:A.Wait] Running Loop=1 2016-05-19T22:50:23.133Z,1463698223.133 [Default:A.Wait](DEBUG): Initialize Wait Component. 2016-05-19T22:50:27.283Z,1463698227.283 [DataOverHttps](DEBUG): dataRead() @791 received: vehicle=makai&busy=false, 1 2016-05-19T22:50:27.283Z,1463698227.283 [DataOverHttps](DEBUG): ParseDataRead( data = busy=false, key = 6, value = makai 2016-05-19T22:50:27.284Z,1463698227.284 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 0, value = false 2016-05-19T22:50:36.549Z,1463698236.549 [Default:A.Wait](INFO): Done Waiting. 2016-05-19T22:50:36.549Z,1463698236.549 [Default:A.Wait] Stopped 2016-05-19T22:50:36.549Z,1463698236.549 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2016-05-19T22:50:36.950Z,1463698236.950 [Default:CheckIn] Running Loop=1 2016-05-19T22:50:36.950Z,1463698236.950 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2016-05-19T22:50:36.950Z,1463698236.950 [Default:CheckIn:Read_GPS] Running Loop=1 2016-05-19T22:50:37.350Z,1463698237.350 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2016-05-19T22:51:27.412Z,1463698287.412 [DataOverHttps](DEBUG): dataRead() @791 received: vehicle=makai&busy=false, 1 2016-05-19T22:51:27.412Z,1463698287.412 [DataOverHttps](DEBUG): ParseDataRead( data = busy=false, key = 6, value = makai 2016-05-19T22:51:27.413Z,1463698287.413 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 0, value = false 2016-05-19T22:52:06.224Z,1463698326.224 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2016-05-19T22:52:27.576Z,1463698347.576 [DataOverHttps](DEBUG): dataRead() @791 received: vehicle=makai&busy=false, 1 2016-05-19T22:52:27.577Z,1463698347.577 [DataOverHttps](DEBUG): ParseDataRead( data = busy=false, key = 6, value = makai 2016-05-19T22:52:27.577Z,1463698347.577 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 0, value = false 2016-05-19T22:52:52.405Z,1463698372.405 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2016-05-19T22:52:52.405Z,1463698372.405 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2016-05-19T22:52:52.405Z,1463698372.405 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2016-05-19T22:52:52.407Z,1463698372.407 [DeadReckonUsingSpeedCalculator](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2016-05-19T22:52:52.407Z,1463698372.407 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2 2016-05-19T22:52:52.407Z,1463698372.407 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2016-05-19T22:52:52.419Z,1463698372.419 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2016-05-19T22:52:52.419Z,1463698372.419 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2016-05-19T22:52:52.821Z,1463698372.821 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2016-05-19T22:52:52.821Z,1463698372.821 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2016-05-19T22:52:52.822Z,1463698372.822 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2016-05-19T22:52:52.822Z,1463698372.822 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2 2016-05-19T22:52:53.209Z,1463698373.209 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2016-05-19T22:52:53.209Z,1463698373.209 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s. 2016-05-19T22:52:53.210Z,1463698373.210 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s. 2016-05-19T22:52:53.210Z,1463698373.210 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2016-05-19T22:52:53.211Z,1463698373.211 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2016-05-19T22:52:53.212Z,1463698373.212 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2016-05-19T22:52:53.613Z,1463698373.613 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.2 s old, using for 20.0 s. 2016-05-19T22:52:54.043Z,1463698374.043 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.6 s old, using for 20.0 s. 2016-05-19T22:52:54.427Z,1463698374.427 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.0 s old, using for 20.0 s. 2016-05-19T22:52:54.806Z,1463698374.806 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.4 s old, using for 20.0 s. 2016-05-19T22:52:55.210Z,1463698375.210 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.8 s old, using for 20.0 s. 2016-05-19T22:52:55.607Z,1463698375.607 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.2 s old, using for 20.0 s. 2016-05-19T22:52:56.065Z,1463698376.065 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.7 s old, using for 20.0 s. 2016-05-19T22:52:56.430Z,1463698376.430 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.0 s old, using for 20.0 s. 2016-05-19T22:52:56.855Z,1463698376.855 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.5 s old, using for 20.0 s. 2016-05-19T22:52:57.219Z,1463698377.219 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.8 s old, using for 20.0 s. 2016-05-19T22:52:57.649Z,1463698377.649 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.2 s old, using for 20.0 s. 2016-05-19T22:52:58.005Z,1463698378.005 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.6 s old, using for 20.0 s. 2016-05-19T22:52:58.448Z,1463698378.448 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.0 s old, using for 20.0 s. 2016-05-19T22:52:58.812Z,1463698378.812 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.4 s old, using for 20.0 s. 2016-05-19T22:52:59.212Z,1463698379.212 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.8 s old, using for 20.0 s. 2016-05-19T22:52:59.615Z,1463698379.615 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.2 s old, using for 20.0 s. 2016-05-19T22:53:00.016Z,1463698380.016 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.6 s old, using for 20.0 s. 2016-05-19T22:53:00.416Z,1463698380.416 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.0 s old, using for 20.0 s. 2016-05-19T22:53:00.809Z,1463698380.809 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.4 s old, using for 20.0 s. 2016-05-19T22:53:01.211Z,1463698381.211 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.8 s old, using for 20.0 s. 2016-05-19T22:53:01.610Z,1463698381.610 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.2 s old, using for 20.0 s. 2016-05-19T22:53:02.010Z,1463698382.010 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.6 s old, using for 20.0 s. 2016-05-19T22:53:02.410Z,1463698382.410 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.0 s old, using for 20.0 s. 2016-05-19T22:53:02.816Z,1463698382.816 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.4 s old, using for 20.0 s. 2016-05-19T22:53:03.220Z,1463698383.220 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.8 s old, using for 20.0 s. 2016-05-19T22:53:03.606Z,1463698383.606 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.2 s old, using for 20.0 s. 2016-05-19T22:53:04.010Z,1463698384.010 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.6 s old, using for 20.0 s. 2016-05-19T22:53:04.409Z,1463698384.409 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.0 s old, using for 20.0 s. 2016-05-19T22:53:04.807Z,1463698384.807 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.4 s old, using for 20.0 s. 2016-05-19T22:53:05.208Z,1463698385.208 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.8 s old, using for 20.0 s. 2016-05-19T22:53:05.620Z,1463698385.620 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 13.2 s old, using for 20.0 s. 2016-05-19T22:53:06.016Z,1463698386.016 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 13.6 s old, using for 20.0 s. 2016-05-19T22:53:06.422Z,1463698386.422 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.0 s old, using for 20.0 s. 2016-05-19T22:53:06.810Z,1463698386.810 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.4 s old, using for 20.0 s. 2016-05-19T22:53:07.211Z,1463698387.211 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.8 s old, using for 20.0 s. 2016-05-19T22:53:07.608Z,1463698387.608 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.2 s old, using for 20.0 s. 2016-05-19T22:53:08.007Z,1463698388.007 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.6 s old, using for 20.0 s. 2016-05-19T22:53:08.416Z,1463698388.416 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.0 s old, using for 20.0 s. 2016-05-19T22:53:08.821Z,1463698388.821 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.4 s old, using for 20.0 s. 2016-05-19T22:53:09.222Z,1463698389.222 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.8 s old, using for 20.0 s. 2016-05-19T22:53:09.607Z,1463698389.607 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 17.2 s old, using for 20.0 s. 2016-05-19T22:53:10.008Z,1463698390.008 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 17.6 s old, using for 20.0 s. 2016-05-19T22:53:10.459Z,1463698390.459 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.1 s old, using for 20.0 s. 2016-05-19T22:53:10.812Z,1463698390.812 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.4 s old, using for 20.0 s. 2016-05-19T22:53:11.213Z,1463698391.213 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.8 s old, using for 20.0 s. 2016-05-19T22:53:11.661Z,1463698391.661 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 19.3 s old, using for 20.0 s. 2016-05-19T22:53:12.015Z,1463698392.015 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 19.6 s old, using for 20.0 s. 2016-05-19T22:53:27.774Z,1463698407.774 [DataOverHttps](DEBUG): dataRead() @791 received: vehicle=makai&busy=false, 1 2016-05-19T22:53:27.775Z,1463698407.775 [DataOverHttps](DEBUG): ParseDataRead( data = busy=false, key = 6, value = makai 2016-05-19T22:53:27.775Z,1463698407.775 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 0, value = false 2016-05-19T22:54:27.024Z,1463698467.024 [BPC1](ERROR): Failed to receive battery data 2016-05-19T22:54:27.024Z,1463698467.024 [BPC1] Communications Fault, FailCount= 1 2016-05-19T22:54:27.024Z,1463698467.024 [BPC1](ERROR): Communications Fault 2016-05-19T22:54:27.043Z,1463698467.043 [CBIT](ERROR): Communications Fault in component: BPC1 2016-05-19T22:54:27.902Z,1463698467.902 [DataOverHttps](DEBUG): dataRead() @791 received: vehicle=makai&busy=false, 1 2016-05-19T22:54:27.903Z,1463698467.903 [DataOverHttps](DEBUG): ParseDataRead( data = busy=false, key = 6, value = makai 2016-05-19T22:54:27.903Z,1463698467.903 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 0, value = false 2016-05-19T22:54:27.988Z,1463698467.988 [CBIT](INFO): Clearing failed state for component BPC1 2016-05-19T22:54:27.988Z,1463698467.988 [BPC1] No Fault, FailCount= 1 2016-05-19T22:55:28.037Z,1463698528.037 [DataOverHttps](DEBUG): dataRead() @791 received: vehicle=makai&busy=false, 1 2016-05-19T22:55:28.037Z,1463698528.037 [DataOverHttps](DEBUG): ParseDataRead( data = busy=false, key = 6, value = makai 2016-05-19T22:55:28.038Z,1463698528.038 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 0, value = false 2016-05-19T22:55:37.296Z,1463698537.296 [Default:CheckIn:Read_GPS](INFO): Timed out from 2016-05-19T22:50:36.9Z 2016-05-19T22:55:37.296Z,1463698537.296 [Default:CheckIn:Read_GPS] Stopped 2016-05-19T22:55:37.296Z,1463698537.296 [Default:CheckIn:Read_Iridium] Running Loop=1 2016-05-19T22:55:37.688Z,1463698537.688 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2016-05-19T22:55:41.894Z,1463698541.894 [DataOverHttps](INFO): Sending 197 bytes from file Logs/20160519T224637/Courier0004.lzma 2016-05-19T22:55:42.648Z,1463698542.648 [DataOverHttps](DEBUG): dataRead() @791 received: vehicle=makai&busy=true&momsn=4115125&filename=Logs%2F20160519T224637%2FCourier0004.lzma, 1 2016-05-19T22:55:42.648Z,1463698542.648 [DataOverHttps](DEBUG): ParseDataRead( data = busy=true&momsn=4115125&filename=Logs%2F20160519T224637%2FCourier0004.lzma, key = 6, value = makai 2016-05-19T22:55:42.649Z,1463698542.649 [DataOverHttps](DEBUG): ParseDataRead( data = momsn=4115125&filename=Logs%2F20160519T224637%2FCourier0004.lzma, key = 0, value = true 2016-05-19T22:55:42.649Z,1463698542.649 [DataOverHttps](DEBUG): ParseDataRead( data = filename=Logs%2F20160519T224637%2FCourier0004.lzma, key = 4, value = 4115125 2016-05-19T22:55:42.650Z,1463698542.650 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 2, value = Logs%2F20160519T224637%2FCourier0004.lzma 2016-05-19T22:55:42.650Z,1463698542.650 [DataOverHttps](INFO): Moved sent file to Logs/20160519T224637/Courier0004.lzma.bak 2016-05-19T22:55:42.651Z,1463698542.651 [DataOverHttps](INFO): SBD MOMSN=4115125 2016-05-19T22:55:47.567Z,1463698547.567 [DataOverHttps](DEBUG): dataRead() @791 received: vehicle=makai&busy=false, 1 2016-05-19T22:55:47.568Z,1463698547.568 [DataOverHttps](DEBUG): ParseDataRead( data = busy=false, key = 6, value = makai 2016-05-19T22:55:47.568Z,1463698547.568 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 0, value = false 2016-05-19T22:55:51.713Z,1463698551.713 [DataOverHttps](INFO): Sending 425 bytes from file Logs/20160519T224637/Express0005.lzma 2016-05-19T22:55:52.467Z,1463698552.467 [DataOverHttps](DEBUG): dataRead() @791 received: vehicle=makai&busy=true&momsn=4115127&filename=Logs%2F20160519T224637%2FExpress0005.lzma, 1 2016-05-19T22:55:52.468Z,1463698552.468 [DataOverHttps](DEBUG): ParseDataRead( data = busy=true&momsn=4115127&filename=Logs%2F20160519T224637%2FExpress0005.lzma, key = 6, value = makai 2016-05-19T22:55:52.468Z,1463698552.468 [DataOverHttps](DEBUG): ParseDataRead( data = momsn=4115127&filename=Logs%2F20160519T224637%2FExpress0005.lzma, key = 0, value = true 2016-05-19T22:55:52.469Z,1463698552.469 [DataOverHttps](DEBUG): ParseDataRead( data = filename=Logs%2F20160519T224637%2FExpress0005.lzma, key = 4, value = 4115127 2016-05-19T22:55:52.469Z,1463698552.469 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 2, value = Logs%2F20160519T224637%2FExpress0005.lzma 2016-05-19T22:55:52.470Z,1463698552.470 [DataOverHttps](INFO): Moved sent file to Logs/20160519T224637/Express0005.lzma.bak 2016-05-19T22:55:52.470Z,1463698552.470 [DataOverHttps](INFO): SBD MOMSN=4115127 2016-05-19T22:55:52.917Z,1463698552.917 [Default:CheckIn:Read_Iridium] Stopped 2016-05-19T22:55:52.917Z,1463698552.917 [Default:CheckIn:C.Wait] Running Loop=1 2016-05-19T22:55:52.917Z,1463698552.917 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2016-05-19T22:55:53.308Z,1463698553.308 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2016-05-19T22:55:53.309Z,1463698553.309 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2016-05-19T22:55:53.309Z,1463698553.309 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2016-05-19T22:55:53.311Z,1463698553.311 [DeadReckonUsingSpeedCalculator](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2016-05-19T22:55:53.311Z,1463698553.311 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 3 2016-05-19T22:55:53.311Z,1463698553.311 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2016-05-19T22:55:53.347Z,1463698553.347 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2016-05-19T22:55:53.348Z,1463698553.348 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2016-05-19T22:55:56.611Z,1463698556.611 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2016-05-19T22:55:56.611Z,1463698556.611 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2016-05-19T22:55:56.611Z,1463698556.611 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2016-05-19T22:55:56.611Z,1463698556.611 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 3 2016-05-19T22:55:56.701Z,1463698556.701 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2016-05-19T22:55:56.702Z,1463698556.702 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s. 2016-05-19T22:55:56.702Z,1463698556.702 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s. 2016-05-19T22:55:56.703Z,1463698556.703 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2016-05-19T22:55:56.703Z,1463698556.703 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2016-05-19T22:55:56.704Z,1463698556.704 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2016-05-19T22:55:57.070Z,1463698557.070 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.8 s old, using for 20.0 s. 2016-05-19T22:55:57.427Z,1463698557.427 [DataOverHttps](DEBUG): dataRead() @791 received: vehicle=makai&busy=false, 1 2016-05-19T22:55:57.427Z,1463698557.427 [DataOverHttps](DEBUG): ParseDataRead( data = busy=false, key = 6, value = makai 2016-05-19T22:55:57.427Z,1463698557.427 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 0, value = false 2016-05-19T22:55:57.519Z,1463698557.519 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.2 s old, using for 20.0 s. 2016-05-19T22:55:57.862Z,1463698557.862 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.6 s old, using for 20.0 s. 2016-05-19T22:55:58.265Z,1463698558.265 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.0 s old, using for 20.0 s. 2016-05-19T22:55:58.681Z,1463698558.681 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.4 s old, using for 20.0 s. 2016-05-19T22:55:59.064Z,1463698559.064 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.8 s old, using for 20.0 s. 2016-05-19T22:55:59.513Z,1463698559.513 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.2 s old, using for 20.0 s. 2016-05-19T22:55:59.868Z,1463698559.868 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.6 s old, using for 20.0 s. 2016-05-19T22:56:00.315Z,1463698560.315 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.0 s old, using for 20.0 s. 2016-05-19T22:56:00.706Z,1463698560.706 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.4 s old, using for 20.0 s. 2016-05-19T22:56:01.067Z,1463698561.067 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.8 s old, using for 20.0 s. 2016-05-19T22:56:01.465Z,1463698561.465 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.2 s old, using for 20.0 s. 2016-05-19T22:56:01.870Z,1463698561.870 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.6 s old, using for 20.0 s. 2016-05-19T22:56:02.263Z,1463698562.263 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.0 s old, using for 20.0 s. 2016-05-19T22:56:02.674Z,1463698562.674 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.4 s old, using for 20.0 s. 2016-05-19T22:56:03.079Z,1463698563.079 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.8 s old, using for 20.0 s. 2016-05-19T22:56:03.470Z,1463698563.470 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.2 s old, using for 20.0 s. 2016-05-19T22:56:03.852Z,1463698563.852 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.5 s old, using for 20.0 s. 2016-05-19T22:56:04.265Z,1463698564.265 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.0 s old, using for 20.0 s. 2016-05-19T22:56:04.651Z,1463698564.651 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.3 s old, using for 20.0 s. 2016-05-19T22:56:05.046Z,1463698565.046 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.7 s old, using for 20.0 s. 2016-05-19T22:56:05.479Z,1463698565.479 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.2 s old, using for 20.0 s. 2016-05-19T22:56:05.876Z,1463698565.876 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.6 s old, using for 20.0 s. 2016-05-19T22:56:06.277Z,1463698566.277 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 13.0 s old, using for 20.0 s. 2016-05-19T22:56:06.649Z,1463698566.649 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 13.3 s old, using for 20.0 s. 2016-05-19T22:56:07.050Z,1463698567.050 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 13.7 s old, using for 20.0 s. 2016-05-19T22:56:07.474Z,1463698567.474 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.2 s old, using for 20.0 s. 2016-05-19T22:56:07.851Z,1463698567.851 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.5 s old, using for 20.0 s. 2016-05-19T22:56:08.251Z,1463698568.251 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.9 s old, using for 20.0 s. 2016-05-19T22:56:08.684Z,1463698568.684 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.4 s old, using for 20.0 s. 2016-05-19T22:56:09.081Z,1463698569.081 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.8 s old, using for 20.0 s. 2016-05-19T22:56:09.481Z,1463698569.481 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.2 s old, using for 20.0 s. 2016-05-19T22:56:09.854Z,1463698569.854 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.5 s old, using for 20.0 s. 2016-05-19T22:56:10.255Z,1463698570.255 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.9 s old, using for 20.0 s. 2016-05-19T22:56:10.656Z,1463698570.656 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 17.3 s old, using for 20.0 s. 2016-05-19T22:56:11.051Z,1463698571.051 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 17.7 s old, using for 20.0 s. 2016-05-19T22:56:11.508Z,1463698571.508 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.2 s old, using for 20.0 s. 2016-05-19T22:56:11.883Z,1463698571.883 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.6 s old, using for 20.0 s. 2016-05-19T22:56:12.282Z,1463698572.282 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 19.0 s old, using for 20.0 s. 2016-05-19T22:56:12.705Z,1463698572.705 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 19.4 s old, using for 20.0 s. 2016-05-19T22:56:13.053Z,1463698573.053 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 19.7 s old, using for 20.0 s. 2016-05-19T22:56:49.469Z,1463698609.469 [CBIT](DEBUG): EFC running - data check-sum false 2016-05-19T22:56:57.572Z,1463698617.572 [DataOverHttps](DEBUG): dataRead() @791 received: vehicle=makai&busy=false, 1 2016-05-19T22:56:57.572Z,1463698617.572 [DataOverHttps](DEBUG): ParseDataRead( data = busy=false, key = 6, value = makai 2016-05-19T22:56:57.573Z,1463698617.573 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 0, value = false 2016-05-19T22:56:58.410Z,1463698618.410 [BPC1](ERROR): Failed to receive battery data 2016-05-19T22:56:58.410Z,1463698618.410 [BPC1] Communications Fault, FailCount= 1 2016-05-19T22:56:58.410Z,1463698618.410 [BPC1](ERROR): Communications Fault 2016-05-19T22:56:58.460Z,1463698618.460 [CBIT](ERROR): Communications Fault in component: BPC1 2016-05-19T22:56:59.620Z,1463698619.620 [CBIT](INFO): Clearing failed state for component BPC1 2016-05-19T22:56:59.620Z,1463698619.620 [BPC1] No Fault, FailCount= 1 2016-05-19T22:57:04.374Z,1463698624.374 [NAL9602](FAULT): GPS failed to acquire within timeout. 2016-05-19T22:57:04.374Z,1463698624.374 [NAL9602] Data Fault, FailCount= 1 2016-05-19T22:57:04.375Z,1463698624.375 [NAL9602](ERROR): Data Fault 2016-05-19T22:57:04.453Z,1463698624.453 [CBIT](ERROR): Data Fault in component: NAL9602 2016-05-19T22:57:04.775Z,1463698624.775 [NAL9602](INFO): Powering down 2016-05-19T22:57:05.620Z,1463698625.620 [CBIT](INFO): Clearing failed state for component NAL9602 2016-05-19T22:57:05.621Z,1463698625.621 [NAL9602] No Fault, FailCount= 1 2016-05-19T22:57:09.988Z,1463698629.988 [NAL9602](INFO): Powering up NAL9602 2016-05-19T22:57:21.180Z,1463698641.180 [NAL9602](INFO): NAL9602 initialized 2016-05-19T22:57:57.733Z,1463698677.733 [DataOverHttps](DEBUG): dataRead() @791 received: vehicle=makai&busy=false, 1 2016-05-19T22:57:57.733Z,1463698677.733 [DataOverHttps](DEBUG): ParseDataRead( data = busy=false, key = 6, value = makai 2016-05-19T22:57:57.734Z,1463698677.734 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 0, value = false 2016-05-19T22:58:40.462Z,1463698720.462 [CommandLine](IMPORTANT): got command quit 2016-05-19T22:58:41.470Z,1463698721.470 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2016-05-19T22:58:41.470Z,1463698721.470 [CommandLine ThreadHandler](INFO): Thread cancelled. 2016-05-19T22:58:41.643Z,1463698721.643 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2016-05-19T22:58:41.643Z,1463698721.643 [CommandLine ThreadHandler](INFO): Thread cancelled. 2016-05-19T22:58:41.644Z,1463698721.644 [CommandLine](INFO): Join timeout helper Thread ID is 884 2016-05-19T22:58:41.644Z,1463698721.644 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2016-05-19T22:58:41.644Z,1463698721.644 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2016-05-19T22:58:41.645Z,1463698721.645 [NavChartDb](INFO): Join timeout helper Thread ID is 885 2016-05-19T22:58:41.947Z,1463698721.947 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2016-05-19T22:58:41.948Z,1463698721.948 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2016-05-19T22:58:41.963Z,1463698721.963 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2016-05-19T22:58:41.963Z,1463698721.963 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2016-05-19T22:58:41.964Z,1463698721.964 [Radio_Surface](INFO): Join timeout helper Thread ID is 886 2016-05-19T22:58:42.324Z,1463698722.324 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2016-05-19T22:58:42.324Z,1463698722.324 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2016-05-19T22:58:42.332Z,1463698722.332 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2016-05-19T22:58:42.332Z,1463698722.332 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2016-05-19T22:58:42.332Z,1463698722.332 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 887 2016-05-19T22:58:42.597Z,1463698722.597 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2016-05-19T22:58:42.597Z,1463698722.597 [WetLabsBB2FL](INFO): Powering down 2016-05-19T22:58:42.598Z,1463698722.598 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2016-05-19T22:58:42.600Z,1463698722.600 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler 2016-05-19T22:58:42.600Z,1463698722.600 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2016-05-19T22:58:42.601Z,1463698722.601 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 888 2016-05-19T22:58:42.681Z,1463698722.681 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread. 2016-05-19T22:58:42.681Z,1463698722.681 [CTD_NeilBrown](INFO): Powering down 2016-05-19T22:58:42.682Z,1463698722.682 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2016-05-19T22:58:42.689Z,1463698722.689 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2016-05-19T22:58:42.689Z,1463698722.689 [logger ThreadHandler](INFO): Thread cancelled. 2016-05-19T22:58:42.690Z,1463698722.690 [logger](INFO): Join timeout helper Thread ID is 889 2016-05-19T22:58:42.704Z,1463698722.704 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2016-05-19T22:58:42.705Z,1463698722.705 [logger ThreadHandler](INFO): Thread cancelled. 2016-05-19T22:58:42.709Z,1463698722.709 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2016-05-19T22:58:42.709Z,1463698722.709 [CommandLine ThreadHandler](INFO): Thread cancelled. 2016-05-19T22:58:42.709Z,1463698722.709 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2016-05-19T22:58:42.710Z,1463698722.710 [controlThread ThreadHandler](INFO): Thread cancelled. 2016-05-19T22:58:42.710Z,1463698722.710 [controlThread](INFO): Join timeout helper Thread ID is 890 2016-05-19T22:58:42.929Z,1463698722.929 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2016-05-19T22:58:42.929Z,1463698722.929 [controlThread](DEBUG): Uninitializing ControlThread 2016-05-19T22:58:42.930Z,1463698722.930 [Aanderaa_O2](INFO): Powering down 2016-05-19T22:58:42.931Z,1463698722.931 [AcousticModem_Benthos_ATM900](INFO): Powering down 2016-05-19T22:58:43.050Z,1463698723.050 [NAL9602](INFO): Powering down 2016-05-19T22:58:43.051Z,1463698723.051 [PNI_TCM](INFO): Powering down 2016-05-19T22:58:43.138Z,1463698723.138 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2016-05-19T22:58:43.140Z,1463698723.140 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2016-05-19T22:58:43.140Z,1463698723.140 [Default] Stopped 2016-05-19T22:58:43.140Z,1463698723.140 [Default](DEBUG): Aggregate::uninitialize Default 2016-05-19T22:58:43.140Z,1463698723.140 [Default:B.GoToSurface] Stopped 2016-05-19T22:58:43.141Z,1463698723.141 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2016-05-19T22:58:43.141Z,1463698723.141 [Default:CheckIn] Stopped 2016-05-19T22:58:43.141Z,1463698723.141 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2016-05-19T22:58:43.141Z,1463698723.141 [Default:CheckIn:C.Wait] Stopped 2016-05-19T22:58:43.141Z,1463698723.141 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2016-05-19T22:58:43.143Z,1463698723.143 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2016-05-19T22:58:43.144Z,1463698723.144 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2016-05-19T22:58:43.144Z,1463698723.144 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2016-05-19T22:58:43.144Z,1463698723.144 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2016-05-19T22:58:43.145Z,1463698723.145 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2016-05-19T22:58:43.145Z,1463698723.145 [BuoyancyServo](INFO): Powering down 2016-05-19T22:58:43.157Z,1463698723.157 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2016-05-19T22:58:43.157Z,1463698723.157 [ElevatorServo](INFO): Powering down 2016-05-19T22:58:43.158Z,1463698723.158 [MassServo](DEBUG): Uninitialize Mass Servo. 2016-05-19T22:58:43.158Z,1463698723.158 [MassServo](INFO): Powering down 2016-05-19T22:58:43.159Z,1463698723.159 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2016-05-19T22:58:43.159Z,1463698723.159 [RudderServo](INFO): Powering down 2016-05-19T22:58:43.160Z,1463698723.160 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2016-05-19T22:58:43.160Z,1463698723.160 [ThrusterServo](INFO): Powering down 2016-05-19T22:58:43.161Z,1463698723.161 [SBIT](DEBUG): Uninitialize SBIT Component. 2016-05-19T22:58:43.161Z,1463698723.161 [IBIT](DEBUG): Uninitialize IBIT Component. 2016-05-19T22:58:43.162Z,1463698723.162 [CBIT](DEBUG): Uninitialize CBIT Component. 2016-05-19T22:58:43.194Z,1463698723.194 [controlThread ThreadHandler](INFO): Thread cancelled. 2016-05-19T22:58:43.252Z,1463698723.252 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2016-05-19T22:58:43.256Z,1463698723.256 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2016-05-19T22:58:43.322Z,1463698723.322 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2016-05-19T22:58:43.369Z,1463698723.369 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2016-05-19T22:58:43.426Z,1463698723.426 [logger ThreadHandler](INFO): Thread cancelled.