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