2016-05-10T17:03:07.832Z,1462899787.832 [Supervisor](DEBUG): Initializing supervisor.
2016-05-10T17:03:07.835Z,1462899787.835 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0
2016-05-10T17:03:07.836Z,1462899787.836 [SyncHandler](INFO): Protected caller Thread ID is 7461
2016-05-10T17:03:07.836Z,1462899787.836 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2016-05-10T17:03:07.837Z,1462899787.837 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0
2016-05-10T17:03:07.838Z,1462899787.838 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 7462
2016-05-10T17:03:07.841Z,1462899787.841 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2016-05-10T17:03:07.854Z,1462899787.854 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2016-05-10T17:03:07.855Z,1462899787.855 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0
2016-05-10T17:03:07.855Z,1462899787.855 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 7463
2016-05-10T17:03:07.856Z,1462899787.856 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2016-05-10T17:03:07.857Z,1462899787.857 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0
2016-05-10T17:03:07.858Z,1462899787.858 [logger ThreadHandler](INFO): Protected caller Thread ID is 7464
2016-05-10T17:03:07.860Z,1462899787.860 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2016-05-10T17:03:07.860Z,1462899787.860 [Supervisor](INFO): Looking for Config files in directory: Config/
2016-05-10T17:03:07.862Z,1462899787.862 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2016-05-10T17:03:08.210Z,1462899788.210 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2016-05-10T17:03:08.211Z,1462899788.211 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2016-05-10T17:03:08.378Z,1462899788.378 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2016-05-10T17:03:08.379Z,1462899788.379 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2016-05-10T17:03:08.505Z,1462899788.505 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2016-05-10T17:03:08.506Z,1462899788.506 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2016-05-10T17:03:08.708Z,1462899788.708 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2016-05-10T17:03:08.708Z,1462899788.708 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2016-05-10T17:03:08.793Z,1462899788.793 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2016-05-10T17:03:08.985Z,1462899788.985 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2016-05-10T17:03:08.986Z,1462899788.986 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2016-05-10T17:03:09.071Z,1462899789.071 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2016-05-10T17:03:09.072Z,1462899789.072 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2016-05-10T17:03:09.350Z,1462899789.350 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2016-05-10T17:03:09.351Z,1462899789.351 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2016-05-10T17:03:09.698Z,1462899789.698 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2016-05-10T17:03:09.699Z,1462899789.699 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2016-05-10T17:03:10.003Z,1462899790.003 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2016-05-10T17:03:10.004Z,1462899790.004 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2016-05-10T17:03:10.516Z,1462899790.516 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2016-05-10T17:03:10.517Z,1462899790.517 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2016-05-10T17:03:10.718Z,1462899790.718 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2016-05-10T17:03:10.718Z,1462899790.718 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2016-05-10T17:03:10.822Z,1462899790.822 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2016-05-10T17:03:10.823Z,1462899790.823 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2016-05-10T17:03:11.266Z,1462899791.266 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2016-05-10T17:03:11.267Z,1462899791.267 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2016-05-10T17:03:11.378Z,1462899791.378 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2016-05-10T17:03:11.380Z,1462899791.380 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2016-05-10T17:03:11.380Z,1462899791.380 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2016-05-10T17:03:11.627Z,1462899791.627 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2016-05-10T17:03:11.628Z,1462899791.628 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2016-05-10T17:03:11.744Z,1462899791.744 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2016-05-10T17:03:11.842Z,1462899791.842 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2016-05-10T17:03:11.938Z,1462899791.938 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2016-05-10T17:03:12.028Z,1462899792.028 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2016-05-10T17:03:12.173Z,1462899792.173 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2016-05-10T17:03:12.351Z,1462899792.351 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2016-05-10T17:03:12.459Z,1462899792.459 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2016-05-10T17:03:12.556Z,1462899792.556 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2016-05-10T17:03:12.667Z,1462899792.667 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2016-05-10T17:03:12.845Z,1462899792.845 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2016-05-10T17:03:12.846Z,1462899792.846 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2016-05-10T17:03:12.854Z,1462899792.854 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2016-05-10T17:03:12.984Z,1462899792.984 [SBIT](DEBUG): Construct Startup Built In Test.
2016-05-10T17:03:13.016Z,1462899793.016 [SBIT] Loaded
2016-05-10T17:03:13.016Z,1462899793.016 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2016-05-10T17:03:13.017Z,1462899793.017 [IBIT](DEBUG): Construct Initiated Built In Test.
2016-05-10T17:03:13.046Z,1462899793.046 [IBIT] Loaded
2016-05-10T17:03:13.047Z,1462899793.047 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2016-05-10T17:03:13.049Z,1462899793.049 [CBIT](DEBUG): Construct Continuous Built In Test.
2016-05-10T17:03:13.202Z,1462899793.202 [CBIT] Loaded
2016-05-10T17:03:13.202Z,1462899793.202 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2016-05-10T17:03:13.202Z,1462899793.202 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2016-05-10T17:03:13.203Z,1462899793.203 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2016-05-10T17:03:13.254Z,1462899793.254 [VerticalControl](DEBUG): Construct VerticalControl.
2016-05-10T17:03:13.362Z,1462899793.362 [VerticalControl] Loaded
2016-05-10T17:03:13.363Z,1462899793.363 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2016-05-10T17:03:13.363Z,1462899793.363 [HorizontalControl](DEBUG): Construct HorizontalControl.
2016-05-10T17:03:13.430Z,1462899793.430 [HorizontalControl] Loaded
2016-05-10T17:03:13.430Z,1462899793.430 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2016-05-10T17:03:13.431Z,1462899793.431 [SpeedControl](DEBUG): Construct SpeedControl.
2016-05-10T17:03:13.437Z,1462899793.437 [SpeedControl] Loaded
2016-05-10T17:03:13.437Z,1462899793.437 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2016-05-10T17:03:13.438Z,1462899793.438 [LoopControl](DEBUG): Construct LoopControl.
2016-05-10T17:03:13.438Z,1462899793.438 [LoopControl] Loaded
2016-05-10T17:03:13.439Z,1462899793.439 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2016-05-10T17:03:13.439Z,1462899793.439 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2016-05-10T17:03:13.440Z,1462899793.440 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2016-05-10T17:03:13.463Z,1462899793.463 [DepthRateCalculator] Loaded
2016-05-10T17:03:13.463Z,1462899793.463 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2016-05-10T17:03:13.469Z,1462899793.469 [PitchRateCalculator] Loaded
2016-05-10T17:03:13.469Z,1462899793.469 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2016-05-10T17:03:13.481Z,1462899793.481 [SpeedCalculator] Loaded
2016-05-10T17:03:13.481Z,1462899793.481 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2016-05-10T17:03:13.498Z,1462899793.498 [TempGradientCalculator] Loaded
2016-05-10T17:03:13.498Z,1462899793.498 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2016-05-10T17:03:13.516Z,1462899793.516 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2016-05-10T17:03:13.517Z,1462899793.517 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2016-05-10T17:03:13.522Z,1462899793.522 [YawRateCalculator] Loaded
2016-05-10T17:03:13.522Z,1462899793.522 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2016-05-10T17:03:13.523Z,1462899793.523 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2016-05-10T17:03:13.523Z,1462899793.523 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2016-05-10T17:03:13.600Z,1462899793.600 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC
2016-05-10T17:03:13.600Z,1462899793.600 [StratificationFrontDetector](DEBUG): (re)initializing
2016-05-10T17:03:13.601Z,1462899793.601 [StratificationFrontDetector] Loaded
2016-05-10T17:03:13.601Z,1462899793.601 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2016-05-10T17:03:13.601Z,1462899793.601 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2016-05-10T17:03:13.602Z,1462899793.602 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2016-05-10T17:03:13.913Z,1462899793.913 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2016-05-10T17:03:13.914Z,1462899793.914 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2016-05-10T17:03:14.011Z,1462899794.011 [DeadReckonUsingSpeedCalculator] Loaded
2016-05-10T17:03:14.012Z,1462899794.012 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2016-05-10T17:03:14.030Z,1462899794.030 [NavChart] Loaded
2016-05-10T17:03:14.030Z,1462899794.030 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2016-05-10T17:03:14.034Z,1462899794.034 [UniversalFixResidualReporter] Loaded
2016-05-10T17:03:14.034Z,1462899794.034 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2016-05-10T17:03:14.035Z,1462899794.035 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2016-05-10T17:03:14.035Z,1462899794.035 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2016-05-10T17:03:14.041Z,1462899794.041 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2016-05-10T17:03:14.042Z,1462899794.042 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2016-05-10T17:03:14.231Z,1462899794.231 [Aanderaa_O2] Loaded
2016-05-10T17:03:14.232Z,1462899794.232 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2016-05-10T17:03:14.313Z,1462899794.313 [CTD_NeilBrown] Loaded
2016-05-10T17:03:14.313Z,1462899794.313 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2016-05-10T17:03:14.314Z,1462899794.314 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4059E4E0
2016-05-10T17:03:14.315Z,1462899794.315 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 7547
2016-05-10T17:03:14.317Z,1462899794.317 [ESPComponent](CRITICAL): No configuration setting for: ESPComponent.espSimulator
2016-05-10T17:03:14.324Z,1462899794.324 [ESPComponent](CRITICAL): No configuration setting for: ESPComponent.stopCompleteTimeout
2016-05-10T17:03:14.336Z,1462899794.336 [ESPComponent] Loaded
2016-05-10T17:03:14.336Z,1462899794.336 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2016-05-10T17:03:14.351Z,1462899794.351 [PAR_Licor] Loaded
2016-05-10T17:03:14.351Z,1462899794.351 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2016-05-10T17:03:14.406Z,1462899794.406 [WetLabsBB2FL] Loaded
2016-05-10T17:03:14.407Z,1462899794.407 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2016-05-10T17:03:14.408Z,1462899794.408 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 405CE4E0
2016-05-10T17:03:14.408Z,1462899794.408 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 7548
2016-05-10T17:03:14.409Z,1462899794.409 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2016-05-10T17:03:14.409Z,1462899794.409 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2016-05-10T17:03:14.688Z,1462899794.688 [AcousticModem_Benthos_ATM900] Loaded
2016-05-10T17:03:14.688Z,1462899794.688 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread.
2016-05-10T17:03:14.762Z,1462899794.762 [DataOverHttps] Loaded
2016-05-10T17:03:14.762Z,1462899794.762 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2016-05-10T17:03:14.776Z,1462899794.776 [Depth_Keller] Loaded
2016-05-10T17:03:14.776Z,1462899794.776 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2016-05-10T17:03:14.782Z,1462899794.782 [DropWeight] Loaded
2016-05-10T17:03:14.782Z,1462899794.782 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2016-05-10T17:03:14.882Z,1462899794.882 [NAL9602] Loaded
2016-05-10T17:03:14.882Z,1462899794.882 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2016-05-10T17:03:14.926Z,1462899794.926 [Onboard] Loaded
2016-05-10T17:03:14.926Z,1462899794.926 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2016-05-10T17:03:14.934Z,1462899794.934 [Radio_Surface] Loaded
2016-05-10T17:03:14.934Z,1462899794.934 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2016-05-10T17:03:14.935Z,1462899794.935 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409E54E0
2016-05-10T17:03:14.935Z,1462899794.935 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 7549
2016-05-10T17:03:14.988Z,1462899794.988 [PNI_TCM] Loaded
2016-05-10T17:03:14.988Z,1462899794.988 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2016-05-10T17:03:15.186Z,1462899795.186 [Rowe_600] Loaded
2016-05-10T17:03:15.186Z,1462899795.186 [ComponentRegistry](DEBUG): Component "Rowe_600" handled in its own thread.
2016-05-10T17:03:15.187Z,1462899795.187 [Rowe_600 ThreadHandler](DEBUG): Created PCaller Thread at 40A154E0
2016-05-10T17:03:15.188Z,1462899795.188 [Rowe_600 ThreadHandler](INFO): Protected caller Thread ID is 7550
2016-05-10T17:03:15.474Z,1462899795.474 [Rowe_600LCM] Loaded
2016-05-10T17:03:15.475Z,1462899795.475 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2016-05-10T17:03:15.476Z,1462899795.476 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 40A454E0
2016-05-10T17:03:15.476Z,1462899795.476 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 7551
2016-05-10T17:03:17.469Z,1462899797.469 [BPC1] Loaded
2016-05-10T17:03:17.470Z,1462899797.470 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2016-05-10T17:03:17.470Z,1462899797.470 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2016-05-10T17:03:17.471Z,1462899797.471 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2016-05-10T17:03:17.574Z,1462899797.574 [BuoyancyServo] Loaded
2016-05-10T17:03:17.575Z,1462899797.575 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2016-05-10T17:03:17.587Z,1462899797.587 [ElevatorServo] Loaded
2016-05-10T17:03:17.587Z,1462899797.587 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2016-05-10T17:03:17.599Z,1462899797.599 [MassServo] Loaded
2016-05-10T17:03:17.599Z,1462899797.599 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2016-05-10T17:03:17.611Z,1462899797.611 [RudderServo] Loaded
2016-05-10T17:03:17.612Z,1462899797.612 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2016-05-10T17:03:17.623Z,1462899797.623 [ThrusterServo] Loaded
2016-05-10T17:03:17.623Z,1462899797.623 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2016-05-10T17:03:17.624Z,1462899797.624 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2016-05-10T17:03:17.625Z,1462899797.625 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2016-05-10T17:03:17.741Z,1462899797.741 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2016-05-10T17:03:17.742Z,1462899797.742 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2016-05-10T17:03:17.768Z,1462899797.768 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2016-05-10T17:03:17.772Z,1462899797.772 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2016-05-10T17:03:17.773Z,1462899797.773 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2016-05-10T17:03:17.780Z,1462899797.780 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2016-05-10T17:03:17.784Z,1462899797.784 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AF34E0
2016-05-10T17:03:17.785Z,1462899797.785 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 7552
2016-05-10T17:03:17.790Z,1462899797.790 [Supervisor](INFO): Main Thread ID is 7460
2016-05-10T17:03:17.790Z,1462899797.790 [Supervisor](DEBUG): Running supervisor.
2016-05-10T17:03:17.790Z,1462899797.790 [CommandLine ThreadHandler](INFO): Handler Thread ID is 7553
2016-05-10T17:03:17.794Z,1462899797.794 [controlThread ThreadHandler](INFO): Handler Thread ID is 7554
2016-05-10T17:03:17.795Z,1462899797.795 [controlThread](DEBUG): Initializing ControlThread
2016-05-10T17:03:17.796Z,1462899797.796 [SBIT](INFO): Initialize SBIT Component.
2016-05-10T17:03:17.796Z,1462899797.796 [SBIT](IMPORTANT): git: 2015-11-13-11-g036008f
2016-05-10T17:03:17.796Z,1462899797.796 [SBIT](INFO): git hash: 036008fb27dd1443c9c6898c567944386f491f02
2016-05-10T17:03:17.797Z,1462899797.797 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2016-05-10T17:03:17.797Z,1462899797.797 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2016-05-10T17:03:17.798Z,1462899797.798 [SBIT](INFO): Beginning SBIT in 35.000000 seconds.
2016-05-10T17:03:17.798Z,1462899797.798 [IBIT](INFO): Initialize IBIT Component.
2016-05-10T17:03:17.799Z,1462899797.799 [CBIT](DEBUG): Initialize CBIT Component.
2016-05-10T17:03:17.799Z,1462899797.799 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2016-05-10T17:03:17.800Z,1462899797.800 [logger ThreadHandler](INFO): Handler Thread ID is 7555
2016-05-10T17:03:17.822Z,1462899797.822 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 7556
2016-05-10T17:03:17.822Z,1462899797.822 [CTD_NeilBrown](INFO): Powering down
2016-05-10T17:03:17.825Z,1462899797.825 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2016-05-10T17:03:17.827Z,1462899797.827 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2016-05-10T17:03:17.828Z,1462899797.828 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2016-05-10T17:03:17.828Z,1462899797.828 [LoopControl](DEBUG): Initialize LoopControlComponent.
2016-05-10T17:03:17.829Z,1462899797.829 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2016-05-10T17:03:17.833Z,1462899797.833 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2016-05-10T17:03:17.833Z,1462899797.833 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2016-05-10T17:03:17.834Z,1462899797.834 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2016-05-10T17:03:17.834Z,1462899797.834 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2016-05-10T17:03:17.835Z,1462899797.835 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2016-05-10T17:03:17.835Z,1462899797.835 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2016-05-10T17:03:17.836Z,1462899797.836 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2016-05-10T17:03:17.836Z,1462899797.836 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2016-05-10T17:03:17.837Z,1462899797.837 [NavChart](DEBUG): Initialize NavChart Navigation.
2016-05-10T17:03:17.837Z,1462899797.837 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2016-05-10T17:03:17.853Z,1462899797.853 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2016-05-10T17:03:17.886Z,1462899797.886 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 7557
2016-05-10T17:03:17.887Z,1462899797.887 [WetLabsBB2FL](INFO): Powering down
2016-05-10T17:03:17.911Z,1462899797.911 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2016-05-10T17:03:17.914Z,1462899797.914 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 7558
2016-05-10T17:03:17.929Z,1462899797.929 [Radio_Surface](INFO): Powering up
2016-05-10T17:03:17.938Z,1462899797.938 [Rowe_600 ThreadHandler](INFO): Handler Thread ID is 7559
2016-05-10T17:03:17.944Z,1462899797.944 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2016-05-10T17:03:17.944Z,1462899797.944 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2016-05-10T17:03:17.954Z,1462899797.954 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 7560
2016-05-10T17:03:17.954Z,1462899797.954 [Rowe_600LCM](INFO): Powering down
2016-05-10T17:03:17.994Z,1462899797.994 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 7561
2016-05-10T17:03:17.996Z,1462899797.996 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources/ElectronicNavigationCharts
2016-05-10T17:03:17.998Z,1462899797.998 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2016-05-10T17:03:17.999Z,1462899797.999 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2016-05-10T17:03:17.999Z,1462899797.999 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2016-05-10T17:03:17.999Z,1462899797.999 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2016-05-10T17:03:17.999Z,1462899797.999 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2016-05-10T17:03:17.999Z,1462899797.999 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2016-05-10T17:03:17.000Z,1462899798.000 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2016-05-10T17:03:17.000Z,1462899798.000 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2016-05-10T17:03:18.054Z,1462899798.054 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2016-05-10T17:03:18.055Z,1462899798.055 [Default:A.Wait](DEBUG): Construct Wait.
2016-05-10T17:03:18.057Z,1462899798.057 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2016-05-10T17:03:18.087Z,1462899798.087 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2016-05-10T17:03:18.090Z,1462899798.090 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2016-05-10T17:03:18.112Z,1462899798.112 [Default:E.Execute](DEBUG): Construct Execute.
2016-05-10T17:03:18.115Z,1462899798.115 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
xmlns:Guidance="Tethys/Guidance"
xmlns:Units="Tethys/Units"
xmlns:Universal="Tethys/Universal"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
Id="Default">

    <DefineArg Name="ElapsedSinceDefaultStarted"><Units:minute/><Value>0</Value></DefineArg>

    <Guidance:Wait>
        <Sequence/>
	<Description>Wait a moment to see if the scheduler starts a new mission before starting to actually run Default.
        </Description>
        <Setting><Guidance:Wait.duration/><Units:second/><Value>13</Value></Setting>
    </Guidance:Wait>

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

        <ReadDatum Id="Read_GPS">
            <Sequence/>
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

        <ReadDatum Id="Read_Iridium">
            <Sequence/>
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn 300</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>5</Value></Setting>
        </Guidance:Wait>

        <Assign><Sequence/><Arg Name="ElapsedSinceDefaultStarted"/><Elapsed><Universal:mission_started/></Elapsed></Assign>

        <Syslog Severity="Important">Default mission has been running for <Arg Name="ElapsedSinceDefaultStarted"/><Units:minute/></Syslog>

    </Aggregate>

    <Syslog Severity="Important">Restarting logs and Default mission.</Syslog>

    <Guidance:Execute>
        <Sequence/>
        <Setting><Guidance:Execute.command/><String>restart logs</String></Setting>
    </Guidance:Execute>

</Mission>


2016-05-10T17:03:18.126Z,1462899798.126 [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-10T17:03:18.172Z,1462899798.172 [ESPComponent](INFO): powering down ESP
2016-05-10T17:03:18.218Z,1462899798.218 [Rowe_600](INFO): Powering down
2016-05-10T17:03:18.595Z,1462899798.595 [AcousticModem_Benthos_ATM900](INFO): Powering up
2016-05-10T17:03:18.595Z,1462899798.595 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2016-05-10T17:03:18.783Z,1462899798.783 [Rowe_600LCM](INFO): Data requested. STOPPED ==> START
2016-05-10T17:03:18.784Z,1462899798.784 [Rowe_600LCM](INFO): Initializing
2016-05-10T17:03:18.784Z,1462899798.784 [Rowe_600LCM](IMPORTANT): Checking LCM
2016-05-10T17:03:18.784Z,1462899798.784 [Rowe_600LCM](IMPORTANT): LCM OK
2016-05-10T17:03:18.784Z,1462899798.784 [Rowe_600LCM](INFO): Powering up
2016-05-10T17:03:19.093Z,1462899799.093 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-05-10T17:03:19.236Z,1462899799.236 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2016-05-10T17:03:19.243Z,1462899799.243 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2016-05-10T17:03:19.266Z,1462899799.266 [ElevatorServo](DEBUG): Initializing EZServoServo.
2016-05-10T17:03:19.272Z,1462899799.272 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2016-05-10T17:03:19.277Z,1462899799.277 [MassServo](DEBUG): Initializing EZServoServo.
2016-05-10T17:03:19.283Z,1462899799.283 [MassServo](DEBUG): Initializing MassServo.
2016-05-10T17:03:19.302Z,1462899799.302 [RudderServo](DEBUG): Initializing EZServoServo.
2016-05-10T17:03:19.308Z,1462899799.308 [RudderServo](DEBUG): Initializing RudderServo.
2016-05-10T17:03:19.324Z,1462899799.324 [ThrusterServo](DEBUG): Initializing EZServoServo.
2016-05-10T17:03:19.332Z,1462899799.332 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2016-05-10T17:03:19.356Z,1462899799.356 [CommandLine](FAULT): Scheduling is paused
2016-05-10T17:03:19.590Z,1462899799.590 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-05-10T17:03:19.996Z,1462899799.996 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-05-10T17:03:20.323Z,1462899800.323 [NAL9602](INFO): Powering up NAL9602
2016-05-10T17:03:20.365Z,1462899800.365 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-05-10T17:03:20.826Z,1462899800.826 [Aanderaa_O2](INFO): Powering down
2016-05-10T17:03:20.985Z,1462899800.985 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-05-10T17:03:21.138Z,1462899801.138 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-05-10T17:03:21.629Z,1462899801.629 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-05-10T17:03:22.012Z,1462899802.012 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-05-10T17:03:23.246Z,1462899803.246 [Rowe_600LCM](INFO): Stopping previous instance(s) of Rowe LCM interface
2016-05-10T17:03:26.098Z,1462899806.098 [AcousticModem_Benthos_ATM900](DEBUG): 
2016-05-10T17:03:27.291Z,1462899807.291 [AcousticModem_Benthos_ATM900](DEBUG): Teledyne Benthos ATM-900 Series OEM w/burn wire
2016-05-10T17:03:27.291Z,1462899807.291 [AcousticModem_Benthos_ATM900](DEBUG): MF Frequency Band
2016-05-10T17:03:27.682Z,1462899807.682 [AcousticModem_Benthos_ATM900](DEBUG): Standard version 8.6.3
2016-05-10T17:03:28.083Z,1462899808.083 [AcousticModem_Benthos_ATM900](DEBUG): May 10 2016 16:56:06 
2016-05-10T17:03:28.891Z,1462899808.891 [AcousticModem_Benthos_ATM900](INFO): entering command mode
2016-05-10T17:03:29.369Z,1462899809.369 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgment
2016-05-10T17:03:29.370Z,1462899809.370 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 1: user:1>
2016-05-10T17:03:29.370Z,1462899809.370 [AcousticModem_Benthos_ATM900](INFO): command mode acknowledged
2016-05-10T17:03:29.785Z,1462899809.785 [AcousticModem_Benthos_ATM900](INFO): setting local address to 3
2016-05-10T17:03:30.338Z,1462899810.338 [AcousticModem_Benthos_ATM900](DEBUG): checking for local address setting acknowledgment
2016-05-10T17:03:30.339Z,1462899810.339 [AcousticModem_Benthos_ATM900](INFO): set local address to 3
2016-05-10T17:03:30.707Z,1462899810.707 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 2: user:2>
2016-05-10T17:03:31.195Z,1462899811.195 [NAL9602](INFO): NAL9602 initialized
2016-05-10T17:03:53.692Z,1462899833.692 [SBIT](IMPORTANT): Beginning Startup BIT
2016-05-10T17:03:53.703Z,1462899833.703 [CBIT](IMPORTANT): Beginning GF scan
2016-05-10T17:03:59.780Z,1462899839.780 [BPC1](ERROR): Failed to parse bank A battery data
2016-05-10T17:03:59.780Z,1462899839.780 [BPC1] Data Fault, FailCount= 1
2016-05-10T17:03:59.780Z,1462899839.780 [BPC1](ERROR): Data Fault
2016-05-10T17:03:59.900Z,1462899839.900 [CBIT](ERROR): Data Fault in component: BPC1
2016-05-10T17:04:01.118Z,1462899841.118 [CBIT](INFO): Clearing failed state for component BPC1
2016-05-10T17:04:01.119Z,1462899841.119 [BPC1] No Fault, FailCount= 1
2016-05-10T17:04:10.584Z,1462899850.584 [CommandLine](IMPORTANT): got command quit
2016-05-10T17:04:11.598Z,1462899851.598 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2016-05-10T17:04:11.598Z,1462899851.598 [CommandLine ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:04:11.782Z,1462899851.782 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2016-05-10T17:04:11.783Z,1462899851.783 [CommandLine ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:04:11.783Z,1462899851.783 [CommandLine](INFO): Join timeout helper Thread ID is 7596
2016-05-10T17:04:11.794Z,1462899851.794 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2016-05-10T17:04:11.794Z,1462899851.794 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:04:11.795Z,1462899851.795 [NavChartDb](INFO): Join timeout helper Thread ID is 7597
2016-05-10T17:04:12.981Z,1462899852.981 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2016-05-10T17:04:12.982Z,1462899852.982 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:04:12.994Z,1462899852.994 [ComponentRegistry](INFO): Shutting down Rowe_600LCM ThreadHandler
2016-05-10T17:04:12.995Z,1462899852.995 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:04:12.995Z,1462899852.995 [Rowe_600LCM](INFO): Join timeout helper Thread ID is 7598
2016-05-10T17:04:20.019Z,1462899860.019 [CBIT](IMPORTANT): No ground fault detected
2016-05-10T17:04:26.701Z,1462899866.701 [Rowe_600LCM](INFO): Starting Rowe LCM interface
2016-05-10T17:04:27.105Z,1462899867.105 [Rowe_600LCM ThreadHandler](INFO): Uninitializing protected caller thread.
2016-05-10T17:04:27.105Z,1462899867.105 [Rowe_600LCM](INFO): Powering down
2016-05-10T17:04:27.106Z,1462899867.106 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:04:27.117Z,1462899867.117 [ComponentRegistry](INFO): Shutting down Rowe_600 ThreadHandler
2016-05-10T17:04:27.117Z,1462899867.117 [Rowe_600 ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:04:27.117Z,1462899867.117 [Rowe_600](INFO): Join timeout helper Thread ID is 7605
2016-05-10T17:04:27.217Z,1462899867.217 [Rowe_600 ThreadHandler](INFO): Uninitializing protected caller thread.
2016-05-10T17:04:27.217Z,1462899867.217 [Rowe_600](INFO): Powering down
2016-05-10T17:04:27.218Z,1462899867.218 [Rowe_600 ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:04:27.233Z,1462899867.233 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2016-05-10T17:04:27.233Z,1462899867.233 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:04:27.233Z,1462899867.233 [Radio_Surface](INFO): Join timeout helper Thread ID is 7606
2016-05-10T17:04:27.581Z,1462899867.581 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2016-05-10T17:04:27.582Z,1462899867.582 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:04:27.586Z,1462899867.586 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2016-05-10T17:04:27.586Z,1462899867.586 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:04:27.587Z,1462899867.587 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 7607
2016-05-10T17:04:27.645Z,1462899867.645 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2016-05-10T17:04:27.646Z,1462899867.646 [WetLabsBB2FL](INFO): Powering down
2016-05-10T17:04:27.646Z,1462899867.646 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:04:27.654Z,1462899867.654 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2016-05-10T17:04:27.654Z,1462899867.654 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:04:27.655Z,1462899867.655 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 7608
2016-05-10T17:04:27.701Z,1462899867.701 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2016-05-10T17:04:27.702Z,1462899867.702 [CTD_NeilBrown](INFO): Powering down
2016-05-10T17:04:27.702Z,1462899867.702 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:04:27.718Z,1462899867.718 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2016-05-10T17:04:27.718Z,1462899867.718 [logger ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:04:27.719Z,1462899867.719 [logger](INFO): Join timeout helper Thread ID is 7609
2016-05-10T17:04:27.725Z,1462899867.725 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2016-05-10T17:04:27.726Z,1462899867.726 [logger ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:04:27.738Z,1462899867.738 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2016-05-10T17:04:27.738Z,1462899867.738 [CommandLine ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:04:27.738Z,1462899867.738 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2016-05-10T17:04:27.738Z,1462899867.738 [controlThread ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:04:27.739Z,1462899867.739 [controlThread](INFO): Join timeout helper Thread ID is 7610
2016-05-10T17:04:27.898Z,1462899867.898 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2016-05-10T17:04:27.898Z,1462899867.898 [controlThread](DEBUG): Uninitializing ControlThread
2016-05-10T17:04:27.898Z,1462899867.898 [Aanderaa_O2](INFO): Powering down
2016-05-10T17:04:27.900Z,1462899867.900 [AcousticModem_Benthos_ATM900](INFO): Powering down
2016-05-10T17:04:28.019Z,1462899868.019 [NAL9602](INFO): Powering down
2016-05-10T17:04:28.020Z,1462899868.020 [PNI_TCM](INFO): Powering down
2016-05-10T17:04:28.107Z,1462899868.107 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2016-05-10T17:04:28.108Z,1462899868.108 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2016-05-10T17:04:28.112Z,1462899868.112 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2016-05-10T17:04:28.112Z,1462899868.112 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2016-05-10T17:04:28.112Z,1462899868.112 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2016-05-10T17:04:28.113Z,1462899868.113 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2016-05-10T17:04:28.113Z,1462899868.113 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2016-05-10T17:04:28.113Z,1462899868.113 [BuoyancyServo](INFO): Powering down
2016-05-10T17:04:28.126Z,1462899868.126 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2016-05-10T17:04:28.126Z,1462899868.126 [ElevatorServo](INFO): Powering down
2016-05-10T17:04:28.127Z,1462899868.127 [MassServo](DEBUG): Uninitialize Mass Servo.
2016-05-10T17:04:28.127Z,1462899868.127 [MassServo](INFO): Powering down
2016-05-10T17:04:28.128Z,1462899868.128 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2016-05-10T17:04:28.128Z,1462899868.128 [RudderServo](INFO): Powering down
2016-05-10T17:04:28.129Z,1462899868.129 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2016-05-10T17:04:28.129Z,1462899868.129 [ThrusterServo](INFO): Powering down
2016-05-10T17:04:28.130Z,1462899868.130 [SBIT](DEBUG): Uninitialize SBIT Component.
2016-05-10T17:04:28.130Z,1462899868.130 [IBIT](DEBUG): Uninitialize IBIT Component.
2016-05-10T17:04:28.130Z,1462899868.130 [CBIT](DEBUG): Uninitialize CBIT Component.
2016-05-10T17:04:28.163Z,1462899868.163 [controlThread ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:04:28.224Z,1462899868.224 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:04:28.229Z,1462899868.229 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:04:28.290Z,1462899868.290 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:04:28.292Z,1462899868.292 [Rowe_600 ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:04:28.300Z,1462899868.300 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:04:28.347Z,1462899868.347 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:04:28.399Z,1462899868.399 [logger ThreadHandler](INFO): Thread cancelled.