2016-05-10T21:21:11.304Z,1462915271.304 [Supervisor](DEBUG): Initializing supervisor. 2016-05-10T21:21:11.307Z,1462915271.307 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0 2016-05-10T21:21:11.308Z,1462915271.308 [SyncHandler](INFO): Protected caller Thread ID is 6857 2016-05-10T21:21:11.308Z,1462915271.308 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2016-05-10T21:21:11.309Z,1462915271.309 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0 2016-05-10T21:21:11.309Z,1462915271.309 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 6858 2016-05-10T21:21:11.312Z,1462915271.312 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2016-05-10T21:21:11.325Z,1462915271.325 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2016-05-10T21:21:11.327Z,1462915271.327 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0 2016-05-10T21:21:11.327Z,1462915271.327 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 6859 2016-05-10T21:21:11.328Z,1462915271.328 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2016-05-10T21:21:11.329Z,1462915271.329 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0 2016-05-10T21:21:11.329Z,1462915271.329 [logger ThreadHandler](INFO): Protected caller Thread ID is 6860 2016-05-10T21:21:11.331Z,1462915271.331 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2016-05-10T21:21:11.332Z,1462915271.332 [Supervisor](INFO): Looking for Config files in directory: Config/ 2016-05-10T21:21:11.333Z,1462915271.333 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2016-05-10T21:21:11.684Z,1462915271.684 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2016-05-10T21:21:11.685Z,1462915271.685 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2016-05-10T21:21:11.852Z,1462915271.852 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2016-05-10T21:21:11.852Z,1462915271.852 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2016-05-10T21:21:11.979Z,1462915271.979 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2016-05-10T21:21:11.979Z,1462915271.979 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2016-05-10T21:21:12.111Z,1462915272.111 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2016-05-10T21:21:12.111Z,1462915272.111 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2016-05-10T21:21:12.197Z,1462915272.197 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2016-05-10T21:21:12.388Z,1462915272.388 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2016-05-10T21:21:12.388Z,1462915272.388 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2016-05-10T21:21:12.474Z,1462915272.474 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2016-05-10T21:21:12.475Z,1462915272.475 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2016-05-10T21:21:12.750Z,1462915272.750 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2016-05-10T21:21:12.750Z,1462915272.750 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2016-05-10T21:21:13.094Z,1462915273.094 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2016-05-10T21:21:13.094Z,1462915273.094 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2016-05-10T21:21:13.432Z,1462915273.432 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2016-05-10T21:21:13.433Z,1462915273.433 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2016-05-10T21:21:13.936Z,1462915273.936 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2016-05-10T21:21:13.937Z,1462915273.937 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2016-05-10T21:21:14.142Z,1462915274.142 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2016-05-10T21:21:14.142Z,1462915274.142 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2016-05-10T21:21:14.246Z,1462915274.246 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2016-05-10T21:21:14.247Z,1462915274.247 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2016-05-10T21:21:14.683Z,1462915274.683 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2016-05-10T21:21:14.684Z,1462915274.684 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2016-05-10T21:21:14.795Z,1462915274.795 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2016-05-10T21:21:14.797Z,1462915274.797 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/ 2016-05-10T21:21:14.798Z,1462915274.798 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg 2016-05-10T21:21:15.036Z,1462915275.036 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2016-05-10T21:21:15.037Z,1462915275.037 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg 2016-05-10T21:21:15.154Z,1462915275.154 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg 2016-05-10T21:21:15.252Z,1462915275.252 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg 2016-05-10T21:21:15.349Z,1462915275.349 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg 2016-05-10T21:21:15.439Z,1462915275.439 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg 2016-05-10T21:21:15.587Z,1462915275.587 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg 2016-05-10T21:21:15.743Z,1462915275.743 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg 2016-05-10T21:21:15.846Z,1462915275.846 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg 2016-05-10T21:21:15.928Z,1462915275.928 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg 2016-05-10T21:21:16.018Z,1462915276.018 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg 2016-05-10T21:21:16.198Z,1462915276.198 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/ 2016-05-10T21:21:16.199Z,1462915276.199 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2016-05-10T21:21:16.206Z,1462915276.206 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2016-05-10T21:21:16.319Z,1462915276.319 [SBIT](DEBUG): Construct Startup Built In Test. 2016-05-10T21:21:16.350Z,1462915276.350 [SBIT] Loaded 2016-05-10T21:21:16.350Z,1462915276.350 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2016-05-10T21:21:16.351Z,1462915276.351 [IBIT](DEBUG): Construct Initiated Built In Test. 2016-05-10T21:21:16.380Z,1462915276.380 [IBIT] Loaded 2016-05-10T21:21:16.380Z,1462915276.380 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2016-05-10T21:21:16.383Z,1462915276.383 [CBIT](DEBUG): Construct Continuous Built In Test. 2016-05-10T21:21:16.525Z,1462915276.525 [CBIT] Loaded 2016-05-10T21:21:16.525Z,1462915276.525 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2016-05-10T21:21:16.526Z,1462915276.526 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2016-05-10T21:21:16.527Z,1462915276.527 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2016-05-10T21:21:16.572Z,1462915276.572 [VerticalControl](DEBUG): Construct VerticalControl. 2016-05-10T21:21:16.676Z,1462915276.676 [VerticalControl] Loaded 2016-05-10T21:21:16.677Z,1462915276.677 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2016-05-10T21:21:16.677Z,1462915276.677 [HorizontalControl](DEBUG): Construct HorizontalControl. 2016-05-10T21:21:16.741Z,1462915276.741 [HorizontalControl] Loaded 2016-05-10T21:21:16.742Z,1462915276.742 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2016-05-10T21:21:16.742Z,1462915276.742 [SpeedControl](DEBUG): Construct SpeedControl. 2016-05-10T21:21:16.748Z,1462915276.748 [SpeedControl] Loaded 2016-05-10T21:21:16.748Z,1462915276.748 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2016-05-10T21:21:16.749Z,1462915276.749 [LoopControl](DEBUG): Construct LoopControl. 2016-05-10T21:21:16.750Z,1462915276.750 [LoopControl] Loaded 2016-05-10T21:21:16.750Z,1462915276.750 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2016-05-10T21:21:16.750Z,1462915276.750 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2016-05-10T21:21:16.751Z,1462915276.751 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2016-05-10T21:21:16.773Z,1462915276.773 [DepthRateCalculator] Loaded 2016-05-10T21:21:16.773Z,1462915276.773 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2016-05-10T21:21:16.779Z,1462915276.779 [PitchRateCalculator] Loaded 2016-05-10T21:21:16.779Z,1462915276.779 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2016-05-10T21:21:16.791Z,1462915276.791 [SpeedCalculator] Loaded 2016-05-10T21:21:16.791Z,1462915276.791 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2016-05-10T21:21:16.807Z,1462915276.807 [TempGradientCalculator] Loaded 2016-05-10T21:21:16.807Z,1462915276.807 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2016-05-10T21:21:16.825Z,1462915276.825 [VerticalTemperatureHomogeneityIndexCalculator] Loaded 2016-05-10T21:21:16.825Z,1462915276.825 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread. 2016-05-10T21:21:16.830Z,1462915276.830 [YawRateCalculator] Loaded 2016-05-10T21:21:16.831Z,1462915276.831 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2016-05-10T21:21:16.831Z,1462915276.831 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2016-05-10T21:21:16.832Z,1462915276.832 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2016-05-10T21:21:16.903Z,1462915276.903 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC 2016-05-10T21:21:16.903Z,1462915276.903 [StratificationFrontDetector](DEBUG): (re)initializing 2016-05-10T21:21:16.904Z,1462915276.904 [StratificationFrontDetector] Loaded 2016-05-10T21:21:16.904Z,1462915276.904 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread. 2016-05-10T21:21:16.905Z,1462915276.905 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2016-05-10T21:21:16.905Z,1462915276.905 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2016-05-10T21:21:17.115Z,1462915277.115 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2016-05-10T21:21:17.116Z,1462915277.116 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2016-05-10T21:21:17.206Z,1462915277.206 [DeadReckonUsingSpeedCalculator] Loaded 2016-05-10T21:21:17.207Z,1462915277.207 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2016-05-10T21:21:17.224Z,1462915277.224 [NavChart] Loaded 2016-05-10T21:21:17.225Z,1462915277.225 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2016-05-10T21:21:17.229Z,1462915277.229 [UniversalFixResidualReporter] Loaded 2016-05-10T21:21:17.229Z,1462915277.229 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2016-05-10T21:21:17.230Z,1462915277.230 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2016-05-10T21:21:17.230Z,1462915277.230 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2016-05-10T21:21:17.236Z,1462915277.236 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2016-05-10T21:21:17.237Z,1462915277.237 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2016-05-10T21:21:17.417Z,1462915277.417 [Aanderaa_O2] Loaded 2016-05-10T21:21:17.417Z,1462915277.417 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread. 2016-05-10T21:21:17.493Z,1462915277.493 [CTD_NeilBrown] Loaded 2016-05-10T21:21:17.494Z,1462915277.494 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2016-05-10T21:21:17.495Z,1462915277.495 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4059E4E0 2016-05-10T21:21:17.495Z,1462915277.495 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 6939 2016-05-10T21:21:17.498Z,1462915277.498 [ESPComponent](CRITICAL): No configuration setting for: ESPComponent.espSimulator 2016-05-10T21:21:17.504Z,1462915277.504 [ESPComponent](CRITICAL): No configuration setting for: ESPComponent.stopCompleteTimeout 2016-05-10T21:21:17.516Z,1462915277.516 [ESPComponent] Loaded 2016-05-10T21:21:17.516Z,1462915277.516 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2016-05-10T21:21:17.531Z,1462915277.531 [PAR_Licor] Loaded 2016-05-10T21:21:17.532Z,1462915277.532 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2016-05-10T21:21:17.584Z,1462915277.584 [WetLabsBB2FL] Loaded 2016-05-10T21:21:17.584Z,1462915277.584 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2016-05-10T21:21:17.585Z,1462915277.585 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 405CE4E0 2016-05-10T21:21:17.585Z,1462915277.585 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 6940 2016-05-10T21:21:17.586Z,1462915277.586 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2016-05-10T21:21:17.587Z,1462915277.587 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2016-05-10T21:21:17.838Z,1462915277.838 [AcousticModem_Benthos_ATM900] Loaded 2016-05-10T21:21:17.838Z,1462915277.838 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread. 2016-05-10T21:21:17.913Z,1462915277.913 [DataOverHttps] Loaded 2016-05-10T21:21:17.914Z,1462915277.914 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2016-05-10T21:21:17.927Z,1462915277.927 [Depth_Keller] Loaded 2016-05-10T21:21:17.928Z,1462915277.928 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2016-05-10T21:21:17.933Z,1462915277.933 [DropWeight] Loaded 2016-05-10T21:21:17.933Z,1462915277.933 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2016-05-10T21:21:18.025Z,1462915278.025 [NAL9602] Loaded 2016-05-10T21:21:18.025Z,1462915278.025 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2016-05-10T21:21:18.067Z,1462915278.067 [Onboard] Loaded 2016-05-10T21:21:18.067Z,1462915278.067 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2016-05-10T21:21:18.075Z,1462915278.075 [Radio_Surface] Loaded 2016-05-10T21:21:18.075Z,1462915278.075 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2016-05-10T21:21:18.076Z,1462915278.076 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409E54E0 2016-05-10T21:21:18.076Z,1462915278.076 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 6941 2016-05-10T21:21:18.126Z,1462915278.126 [PNI_TCM] Loaded 2016-05-10T21:21:18.126Z,1462915278.126 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread. 2016-05-10T21:21:18.309Z,1462915278.309 [Rowe_600] Loaded 2016-05-10T21:21:18.309Z,1462915278.309 [ComponentRegistry](DEBUG): Component "Rowe_600" handled in its own thread. 2016-05-10T21:21:18.311Z,1462915278.311 [Rowe_600 ThreadHandler](DEBUG): Created PCaller Thread at 40A154E0 2016-05-10T21:21:18.311Z,1462915278.311 [Rowe_600 ThreadHandler](INFO): Protected caller Thread ID is 6942 2016-05-10T21:21:18.326Z,1462915278.326 [Rowe_600LCM] Loaded 2016-05-10T21:21:18.326Z,1462915278.326 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread. 2016-05-10T21:21:18.327Z,1462915278.327 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 40A454E0 2016-05-10T21:21:18.328Z,1462915278.328 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 6943 2016-05-10T21:21:20.159Z,1462915280.159 [BPC1] Loaded 2016-05-10T21:21:20.159Z,1462915280.159 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2016-05-10T21:21:20.159Z,1462915280.159 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2016-05-10T21:21:20.160Z,1462915280.160 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2016-05-10T21:21:20.280Z,1462915280.280 [BuoyancyServo] Loaded 2016-05-10T21:21:20.280Z,1462915280.280 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2016-05-10T21:21:20.292Z,1462915280.292 [ElevatorServo] Loaded 2016-05-10T21:21:20.293Z,1462915280.293 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2016-05-10T21:21:20.304Z,1462915280.304 [MassServo] Loaded 2016-05-10T21:21:20.305Z,1462915280.305 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2016-05-10T21:21:20.317Z,1462915280.317 [RudderServo] Loaded 2016-05-10T21:21:20.317Z,1462915280.317 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2016-05-10T21:21:20.329Z,1462915280.329 [ThrusterServo] Loaded 2016-05-10T21:21:20.329Z,1462915280.329 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2016-05-10T21:21:20.330Z,1462915280.330 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2016-05-10T21:21:20.330Z,1462915280.330 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2016-05-10T21:21:20.424Z,1462915280.424 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2016-05-10T21:21:20.425Z,1462915280.425 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2016-05-10T21:21:20.449Z,1462915280.449 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2016-05-10T21:21:20.453Z,1462915280.453 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2016-05-10T21:21:20.454Z,1462915280.454 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2016-05-10T21:21:20.460Z,1462915280.460 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2016-05-10T21:21:20.462Z,1462915280.462 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AF34E0 2016-05-10T21:21:20.462Z,1462915280.462 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 6944 2016-05-10T21:21:20.467Z,1462915280.467 [Supervisor](INFO): Main Thread ID is 6856 2016-05-10T21:21:20.467Z,1462915280.467 [Supervisor](DEBUG): Running supervisor. 2016-05-10T21:21:20.468Z,1462915280.468 [CommandLine ThreadHandler](INFO): Handler Thread ID is 6945 2016-05-10T21:21:20.471Z,1462915280.471 [controlThread ThreadHandler](INFO): Handler Thread ID is 6946 2016-05-10T21:21:20.471Z,1462915280.471 [controlThread](DEBUG): Initializing ControlThread 2016-05-10T21:21:20.472Z,1462915280.472 [SBIT](INFO): Initialize SBIT Component. 2016-05-10T21:21:20.473Z,1462915280.473 [SBIT](IMPORTANT): git: 2015-11-13-11-g036008f 2016-05-10T21:21:20.473Z,1462915280.473 [SBIT](INFO): git hash: 036008fb27dd1443c9c6898c567944386f491f02 2016-05-10T21:21:20.473Z,1462915280.473 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2016-05-10T21:21:20.473Z,1462915280.473 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014 2016-05-10T21:21:20.474Z,1462915280.474 [SBIT](INFO): Beginning SBIT in 35.000000 seconds. 2016-05-10T21:21:20.475Z,1462915280.475 [IBIT](INFO): Initialize IBIT Component. 2016-05-10T21:21:20.476Z,1462915280.476 [CBIT](DEBUG): Initialize CBIT Component. 2016-05-10T21:21:20.476Z,1462915280.476 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2016-05-10T21:21:20.477Z,1462915280.477 [logger ThreadHandler](INFO): Handler Thread ID is 6947 2016-05-10T21:21:20.502Z,1462915280.502 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2016-05-10T21:21:20.504Z,1462915280.504 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2016-05-10T21:21:20.505Z,1462915280.505 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2016-05-10T21:21:20.506Z,1462915280.506 [LoopControl](DEBUG): Initialize LoopControlComponent. 2016-05-10T21:21:20.506Z,1462915280.506 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2016-05-10T21:21:20.506Z,1462915280.506 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2016-05-10T21:21:20.507Z,1462915280.507 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2016-05-10T21:21:20.507Z,1462915280.507 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2016-05-10T21:21:20.508Z,1462915280.508 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing 2016-05-10T21:21:20.508Z,1462915280.508 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2016-05-10T21:21:20.509Z,1462915280.509 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2016-05-10T21:21:20.510Z,1462915280.510 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2016-05-10T21:21:20.510Z,1462915280.510 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2016-05-10T21:21:20.511Z,1462915280.511 [NavChart](DEBUG): Initialize NavChart Navigation. 2016-05-10T21:21:20.511Z,1462915280.511 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2016-05-10T21:21:20.520Z,1462915280.520 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2016-05-10T21:21:20.523Z,1462915280.523 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 6948 2016-05-10T21:21:20.524Z,1462915280.524 [CTD_NeilBrown](INFO): Powering down 2016-05-10T21:21:20.559Z,1462915280.559 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 6949 2016-05-10T21:21:20.560Z,1462915280.560 [WetLabsBB2FL](INFO): Powering down 2016-05-10T21:21:20.588Z,1462915280.588 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2016-05-10T21:21:20.592Z,1462915280.592 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 6950 2016-05-10T21:21:20.603Z,1462915280.603 [Radio_Surface](INFO): Powering up 2016-05-10T21:21:20.611Z,1462915280.611 [Rowe_600 ThreadHandler](INFO): Handler Thread ID is 6951 2016-05-10T21:21:20.617Z,1462915280.617 [MissionManager](DEBUG): 2016-05-10T21:21:20.618Z,1462915280.618 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2016-05-10T21:21:20.627Z,1462915280.627 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 6952 2016-05-10T21:21:20.628Z,1462915280.628 [Rowe_600LCM](INFO): Powering down 2016-05-10T21:21:20.672Z,1462915280.672 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 6954 2016-05-10T21:21:20.675Z,1462915280.675 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources/ElectronicNavigationCharts 2016-05-10T21:21:20.675Z,1462915280.675 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2016-05-10T21:21:20.676Z,1462915280.676 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2016-05-10T21:21:20.676Z,1462915280.676 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2016-05-10T21:21:20.676Z,1462915280.676 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2016-05-10T21:21:20.676Z,1462915280.676 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2016-05-10T21:21:20.676Z,1462915280.676 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2016-05-10T21:21:20.677Z,1462915280.677 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2016-05-10T21:21:20.677Z,1462915280.677 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2016-05-10T21:21:20.744Z,1462915280.744 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2016-05-10T21:21:20.745Z,1462915280.745 [Default:A.Wait](DEBUG): Construct Wait. 2016-05-10T21:21:20.747Z,1462915280.747 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2016-05-10T21:21:20.785Z,1462915280.785 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2016-05-10T21:21:20.816Z,1462915280.816 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2016-05-10T21:21:20.822Z,1462915280.822 [Default:E.Execute](DEBUG): Construct Execute. 2016-05-10T21:21:20.850Z,1462915280.850 [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-10T21:21:20.856Z,1462915280.856 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,ESPComponent,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,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2016-05-10T21:21:20.888Z,1462915280.888 [Rowe_600](INFO): Powering down 2016-05-10T21:21:20.920Z,1462915280.920 [ESPComponent](INFO): powering down ESP 2016-05-10T21:21:21.310Z,1462915281.310 [AcousticModem_Benthos_ATM900](INFO): Powering up 2016-05-10T21:21:21.310Z,1462915281.310 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900. 2016-05-10T21:21:21.829Z,1462915281.829 [Rowe_600LCM](INFO): Initializing 2016-05-10T21:21:21.829Z,1462915281.829 [Rowe_600LCM](IMPORTANT): Checking LCM 2016-05-10T21:21:21.829Z,1462915281.829 [Rowe_600LCM](IMPORTANT): LCM OK 2016-05-10T21:21:21.830Z,1462915281.830 [Rowe_600LCM](INFO): Powering up 2016-05-10T21:21:21.934Z,1462915281.934 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-10T21:21:22.082Z,1462915282.082 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2016-05-10T21:21:22.089Z,1462915282.089 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2016-05-10T21:21:22.113Z,1462915282.113 [ElevatorServo](DEBUG): Initializing EZServoServo. 2016-05-10T21:21:22.121Z,1462915282.121 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2016-05-10T21:21:22.137Z,1462915282.137 [MassServo](DEBUG): Initializing EZServoServo. 2016-05-10T21:21:22.145Z,1462915282.145 [MassServo](DEBUG): Initializing MassServo. 2016-05-10T21:21:22.177Z,1462915282.177 [RudderServo](DEBUG): Initializing EZServoServo. 2016-05-10T21:21:22.186Z,1462915282.186 [RudderServo](DEBUG): Initializing RudderServo. 2016-05-10T21:21:22.206Z,1462915282.206 [ThrusterServo](DEBUG): Initializing EZServoServo. 2016-05-10T21:21:22.213Z,1462915282.213 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2016-05-10T21:21:22.255Z,1462915282.255 [CommandLine](FAULT): Scheduling is paused 2016-05-10T21:21:22.485Z,1462915282.485 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-10T21:21:22.737Z,1462915282.737 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-10T21:21:23.208Z,1462915283.208 [NAL9602](INFO): Powering up NAL9602 2016-05-10T21:21:23.251Z,1462915283.251 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-10T21:21:23.703Z,1462915283.703 [Aanderaa_O2](INFO): Powering down 2016-05-10T21:21:24.056Z,1462915284.056 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-10T21:21:24.175Z,1462915284.175 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-10T21:21:24.532Z,1462915284.532 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-10T21:21:24.969Z,1462915284.969 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-10T21:21:25.355Z,1462915285.355 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-10T21:21:25.788Z,1462915285.788 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-10T21:21:26.198Z,1462915286.198 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-10T21:21:26.308Z,1462915286.308 [Rowe_600LCM](INFO): Stopping previous instance(s) of Rowe LCM interface 2016-05-10T21:21:26.391Z,1462915286.391 [Rowe_600LCM](INFO): Starting Rowe LCM interface 2016-05-10T21:21:26.443Z,1462915286.443 [Rowe_600LCM](IMPORTANT): LCM subscribed 2016-05-10T21:21:26.608Z,1462915286.608 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-10T21:21:27.002Z,1462915287.002 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-10T21:21:27.409Z,1462915287.409 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-10T21:21:27.797Z,1462915287.797 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-10T21:21:28.294Z,1462915288.294 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-10T21:21:28.596Z,1462915288.596 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-10T21:21:28.944Z,1462915288.944 [AcousticModem_Benthos_ATM900](DEBUG): 2016-05-10T21:21:29.036Z,1462915289.036 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-10T21:21:29.396Z,1462915289.396 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-10T21:21:29.970Z,1462915289.970 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-10T21:21:30.157Z,1462915290.157 [AcousticModem_Benthos_ATM900](DEBUG): Teledyne Benthos ATM-900 Series OEM w/burn wire 2016-05-10T21:21:30.158Z,1462915290.158 [AcousticModem_Benthos_ATM900](DEBUG): MF Frequency Band 2016-05-10T21:21:30.159Z,1462915290.159 [AcousticModem_Benthos_ATM900](DEBUG): Standard version 8.6.3 2016-05-10T21:21:30.203Z,1462915290.203 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-10T21:21:30.548Z,1462915290.548 [AcousticModem_Benthos_ATM900](DEBUG): May 10 2016 21:14:03 2016-05-10T21:21:30.599Z,1462915290.599 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-10T21:21:30.992Z,1462915290.992 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-10T21:21:31.348Z,1462915291.348 [AcousticModem_Benthos_ATM900](INFO): entering command mode 2016-05-10T21:21:31.388Z,1462915291.388 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-10T21:21:31.779Z,1462915291.779 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgment 2016-05-10T21:21:32.079Z,1462915292.079 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-10T21:21:32.480Z,1462915292.480 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgment 2016-05-10T21:21:32.491Z,1462915292.491 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 1: user:1> 2016-05-10T21:21:32.492Z,1462915292.492 [AcousticModem_Benthos_ATM900](INFO): command mode acknowledged 2016-05-10T21:21:32.707Z,1462915292.707 [PNI_TCM](ERROR): No parameter response UART error: serial timeout 2016-05-10T21:21:32.708Z,1462915292.708 [PNI_TCM](ERROR): Received 0xF61F 2016-05-10T21:21:32.850Z,1462915292.850 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-10T21:21:33.240Z,1462915293.240 [Rowe_600LCM](IMPORTANT): valid:0 2016-05-10T21:21:33.241Z,1462915293.241 [Rowe_600LCM](IMPORTANT): range0:nan 2016-05-10T21:21:33.243Z,1462915293.243 [Rowe_600LCM](IMPORTANT): range1:nan 2016-05-10T21:21:33.245Z,1462915293.245 [Rowe_600LCM](IMPORTANT): range2:nan 2016-05-10T21:21:33.248Z,1462915293.248 [Rowe_600LCM](IMPORTANT): range3:nan 2016-05-10T21:21:33.261Z,1462915293.261 [AcousticModem_Benthos_ATM900](INFO): setting local address to 3 2016-05-10T21:21:33.597Z,1462915293.597 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-10T21:21:33.831Z,1462915293.831 [AcousticModem_Benthos_ATM900](DEBUG): checking for local address setting acknowledgment 2016-05-10T21:21:33.864Z,1462915293.864 [AcousticModem_Benthos_ATM900](INFO): set local address to 3 2016-05-10T21:21:34.289Z,1462915294.289 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-10T21:21:34.531Z,1462915294.531 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 2: user:2> 2016-05-10T21:21:34.772Z,1462915294.772 [Rowe_600LCM](IMPORTANT): valid:0 2016-05-10T21:21:34.774Z,1462915294.774 [Rowe_600LCM](IMPORTANT): range0:nan 2016-05-10T21:21:34.776Z,1462915294.776 [Rowe_600LCM](IMPORTANT): range1:nan 2016-05-10T21:21:34.778Z,1462915294.778 [Rowe_600LCM](IMPORTANT): range2:nan 2016-05-10T21:21:34.780Z,1462915294.780 [Rowe_600LCM](IMPORTANT): range3:nan 2016-05-10T21:21:34.901Z,1462915294.901 [NAL9602](INFO): NAL9602 initialized 2016-05-10T21:21:35.435Z,1462915295.435 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-10T21:21:36.786Z,1462915296.786 [Rowe_600LCM](IMPORTANT): valid:0 2016-05-10T21:21:36.788Z,1462915296.788 [Rowe_600LCM](IMPORTANT): range0:nan 2016-05-10T21:21:36.789Z,1462915296.789 [Rowe_600LCM](IMPORTANT): range1:nan 2016-05-10T21:21:36.791Z,1462915296.791 [Rowe_600LCM](IMPORTANT): range2:nan 2016-05-10T21:21:36.792Z,1462915296.792 [Rowe_600LCM](IMPORTANT): range3:nan 2016-05-10T21:21:37.042Z,1462915297.042 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-10T21:21:37.996Z,1462915297.996 [Rowe_600LCM](IMPORTANT): valid:1 2016-05-10T21:21:37.998Z,1462915297.998 [Rowe_600LCM](IMPORTANT): range0:9.485023 2016-05-10T21:21:37.000Z,1462915298.000 [Rowe_600LCM](IMPORTANT): range1:0.000000 2016-05-10T21:21:38.002Z,1462915298.002 [Rowe_600LCM](IMPORTANT): range2:10.204474 2016-05-10T21:21:38.004Z,1462915298.004 [Rowe_600LCM](IMPORTANT): range3:8.589377 2016-05-10T21:21:38.175Z,1462915298.175 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-10T21:21:39.205Z,1462915299.205 [Rowe_600LCM](IMPORTANT): valid:1 2016-05-10T21:21:39.207Z,1462915299.207 [Rowe_600LCM](IMPORTANT): range0:9.485023 2016-05-10T21:21:39.209Z,1462915299.209 [Rowe_600LCM](IMPORTANT): range1:0.000000 2016-05-10T21:21:39.211Z,1462915299.211 [Rowe_600LCM](IMPORTANT): range2:10.204474 2016-05-10T21:21:39.213Z,1462915299.213 [Rowe_600LCM](IMPORTANT): range3:8.574696 2016-05-10T21:21:39.250Z,1462915299.250 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-10T21:21:40.128Z,1462915300.128 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-10T21:21:40.553Z,1462915300.553 [Rowe_600LCM](IMPORTANT): valid:1 2016-05-10T21:21:40.555Z,1462915300.555 [Rowe_600LCM](IMPORTANT): range0:9.485023 2016-05-10T21:21:40.557Z,1462915300.557 [Rowe_600LCM](IMPORTANT): range1:0.000000 2016-05-10T21:21:40.559Z,1462915300.559 [Rowe_600LCM](IMPORTANT): range2:10.204474 2016-05-10T21:21:40.561Z,1462915300.561 [Rowe_600LCM](IMPORTANT): range3:8.574696 2016-05-10T21:21:41.101Z,1462915301.101 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-10T21:21:41.943Z,1462915301.943 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-10T21:21:42.041Z,1462915302.041 [Rowe_600LCM](IMPORTANT): valid:1 2016-05-10T21:21:42.044Z,1462915302.044 [Rowe_600LCM](IMPORTANT): range0:9.485023 2016-05-10T21:21:42.046Z,1462915302.046 [Rowe_600LCM](IMPORTANT): range1:0.000000 2016-05-10T21:21:42.048Z,1462915302.048 [Rowe_600LCM](IMPORTANT): range2:10.204474 2016-05-10T21:21:42.050Z,1462915302.050 [Rowe_600LCM](IMPORTANT): range3:8.574696 2016-05-10T21:21:42.000Z,1462915303.000 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-10T21:21:43.504Z,1462915303.504 [Rowe_600L