2015-07-21T21:41:03.950Z,1437514863.950 [Supervisor](DEBUG): Initializing supervisor.
2015-07-21T21:41:03.954Z,1437514863.954 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0
2015-07-21T21:41:03.954Z,1437514863.954 [SyncHandler](INFO): Protected caller Thread ID is 765
2015-07-21T21:41:03.954Z,1437514863.954 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2015-07-21T21:41:03.956Z,1437514863.956 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0
2015-07-21T21:41:03.957Z,1437514863.957 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 766
2015-07-21T21:41:03.960Z,1437514863.960 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2015-07-21T21:41:03.972Z,1437514863.972 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2015-07-21T21:41:03.976Z,1437514863.976 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0
2015-07-21T21:41:03.977Z,1437514863.977 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 767
2015-07-21T21:41:03.978Z,1437514863.978 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2015-07-21T21:41:03.980Z,1437514863.980 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0
2015-07-21T21:41:03.981Z,1437514863.981 [logger ThreadHandler](INFO): Protected caller Thread ID is 768
2015-07-21T21:41:03.983Z,1437514863.983 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2015-07-21T21:41:03.983Z,1437514863.983 [Supervisor](INFO): Looking for Config files in directory: Config/
2015-07-21T21:41:03.987Z,1437514863.987 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2015-07-21T21:41:04.387Z,1437514864.387 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2015-07-21T21:41:04.388Z,1437514864.388 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2015-07-21T21:41:04.583Z,1437514864.583 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2015-07-21T21:41:04.585Z,1437514864.585 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2015-07-21T21:41:04.709Z,1437514864.709 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2015-07-21T21:41:04.710Z,1437514864.710 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2015-07-21T21:41:04.851Z,1437514864.851 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2015-07-21T21:41:04.852Z,1437514864.852 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2015-07-21T21:41:04.947Z,1437514864.947 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2015-07-21T21:41:05.167Z,1437514865.167 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2015-07-21T21:41:05.168Z,1437514865.168 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2015-07-21T21:41:05.266Z,1437514865.266 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2015-07-21T21:41:05.267Z,1437514865.267 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2015-07-21T21:41:05.568Z,1437514865.568 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2015-07-21T21:41:05.569Z,1437514865.569 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2015-07-21T21:41:05.958Z,1437514865.958 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2015-07-21T21:41:05.958Z,1437514865.958 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2015-07-21T21:41:06.313Z,1437514866.313 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2015-07-21T21:41:06.314Z,1437514866.314 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2015-07-21T21:41:06.910Z,1437514866.910 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2015-07-21T21:41:06.911Z,1437514866.911 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2015-07-21T21:41:07.151Z,1437514867.151 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2015-07-21T21:41:07.151Z,1437514867.151 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2015-07-21T21:41:07.266Z,1437514867.266 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2015-07-21T21:41:07.267Z,1437514867.267 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2015-07-21T21:41:07.778Z,1437514867.778 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2015-07-21T21:41:07.779Z,1437514867.779 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2015-07-21T21:41:07.945Z,1437514867.945 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2015-07-21T21:41:07.947Z,1437514867.947 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2015-07-21T21:41:07.950Z,1437514867.950 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2015-07-21T21:41:08.224Z,1437514868.224 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2015-07-21T21:41:08.225Z,1437514868.225 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2015-07-21T21:41:08.361Z,1437514868.361 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2015-07-21T21:41:08.469Z,1437514868.469 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2015-07-21T21:41:08.577Z,1437514868.577 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2015-07-21T21:41:08.745Z,1437514868.745 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2015-07-21T21:41:08.904Z,1437514868.904 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2015-07-21T21:41:09.022Z,1437514869.022 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2015-07-21T21:41:09.122Z,1437514869.122 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2015-07-21T21:41:09.216Z,1437514869.216 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2015-07-21T21:41:09.326Z,1437514869.326 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2015-07-21T21:41:09.530Z,1437514869.530 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2015-07-21T21:41:09.535Z,1437514869.535 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2015-07-21T21:41:09.608Z,1437514869.608 [VerticalControl](DEBUG): Construct VerticalControl.
2015-07-21T21:41:09.749Z,1437514869.749 [VerticalControl] Loaded
2015-07-21T21:41:09.750Z,1437514869.750 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2015-07-21T21:41:09.751Z,1437514869.751 [HorizontalControl](DEBUG): Construct HorizontalControl.
2015-07-21T21:41:09.828Z,1437514869.828 [HorizontalControl] Loaded
2015-07-21T21:41:09.828Z,1437514869.828 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2015-07-21T21:41:09.829Z,1437514869.829 [SpeedControl](DEBUG): Construct SpeedControl.
2015-07-21T21:41:09.839Z,1437514869.839 [SpeedControl] Loaded
2015-07-21T21:41:09.839Z,1437514869.839 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2015-07-21T21:41:09.840Z,1437514869.840 [LoopControl](DEBUG): Construct LoopControl.
2015-07-21T21:41:09.841Z,1437514869.841 [LoopControl] Loaded
2015-07-21T21:41:09.841Z,1437514869.841 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2015-07-21T21:41:09.841Z,1437514869.841 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2015-07-21T21:41:09.842Z,1437514869.842 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2015-07-21T21:41:09.993Z,1437514869.993 [SBIT](DEBUG): Construct Startup Built In Test.
2015-07-21T21:41:10.005Z,1437514870.005 [SBIT] Loaded
2015-07-21T21:41:10.005Z,1437514870.005 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2015-07-21T21:41:10.010Z,1437514870.010 [IBIT](DEBUG): Construct Initiated Built In Test.
2015-07-21T21:41:10.045Z,1437514870.045 [IBIT] Loaded
2015-07-21T21:41:10.045Z,1437514870.045 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2015-07-21T21:41:10.047Z,1437514870.047 [CBIT](DEBUG): Construct Continuous Built In Test.
2015-07-21T21:41:10.201Z,1437514870.201 [CBIT] Loaded
2015-07-21T21:41:10.201Z,1437514870.201 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2015-07-21T21:41:10.202Z,1437514870.202 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2015-07-21T21:41:10.202Z,1437514870.202 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2015-07-21T21:41:10.230Z,1437514870.230 [DepthRateCalculator] Loaded
2015-07-21T21:41:10.230Z,1437514870.230 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2015-07-21T21:41:10.241Z,1437514870.241 [PitchRateCalculator] Loaded
2015-07-21T21:41:10.241Z,1437514870.241 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2015-07-21T21:41:10.253Z,1437514870.253 [SpeedCalculator] Loaded
2015-07-21T21:41:10.254Z,1437514870.254 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2015-07-21T21:41:10.270Z,1437514870.270 [TempGradientCalculator] Loaded
2015-07-21T21:41:10.271Z,1437514870.271 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2015-07-21T21:41:10.276Z,1437514870.276 [YawRateCalculator] Loaded
2015-07-21T21:41:10.276Z,1437514870.276 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2015-07-21T21:41:10.277Z,1437514870.277 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2015-07-21T21:41:10.277Z,1437514870.277 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2015-07-21T21:41:10.371Z,1437514870.371 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2015-07-21T21:41:10.371Z,1437514870.371 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2015-07-21T21:41:10.664Z,1437514870.664 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2015-07-21T21:41:10.666Z,1437514870.666 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2015-07-21T21:41:10.797Z,1437514870.797 [DeadReckonUsingMultipleVelocitySources] Loaded
2015-07-21T21:41:10.797Z,1437514870.797 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2015-07-21T21:41:10.859Z,1437514870.859 [DeadReckonUsingSpeedCalculator] Loaded
2015-07-21T21:41:10.859Z,1437514870.859 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2015-07-21T21:41:10.881Z,1437514870.881 [NavChart] Loaded
2015-07-21T21:41:10.881Z,1437514870.881 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2015-07-21T21:41:10.886Z,1437514870.886 [UniversalFixResidualReporter] Loaded
2015-07-21T21:41:10.886Z,1437514870.886 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2015-07-21T21:41:10.887Z,1437514870.887 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2015-07-21T21:41:10.887Z,1437514870.887 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2015-07-21T21:41:10.896Z,1437514870.896 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2015-07-21T21:41:10.896Z,1437514870.896 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2015-07-21T21:41:11.123Z,1437514871.123 [Aanderaa_O2] Loaded
2015-07-21T21:41:11.124Z,1437514871.124 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2015-07-21T21:41:11.210Z,1437514871.210 [CTD_NeilBrown] Loaded
2015-07-21T21:41:11.210Z,1437514871.210 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2015-07-21T21:41:11.212Z,1437514871.212 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 405914E0
2015-07-21T21:41:11.212Z,1437514871.212 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 847
2015-07-21T21:41:11.228Z,1437514871.228 [ESPComponent] Loaded
2015-07-21T21:41:11.229Z,1437514871.229 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2015-07-21T21:41:11.248Z,1437514871.248 [PAR_Licor] Loaded
2015-07-21T21:41:11.249Z,1437514871.249 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2015-07-21T21:41:11.305Z,1437514871.305 [WetLabsBB2FL] Loaded
2015-07-21T21:41:11.306Z,1437514871.306 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2015-07-21T21:41:11.308Z,1437514871.308 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 405C14E0
2015-07-21T21:41:11.308Z,1437514871.308 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 848
2015-07-21T21:41:11.309Z,1437514871.309 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2015-07-21T21:41:11.309Z,1437514871.309 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2015-07-21T21:41:11.844Z,1437514871.844 [AcousticModem_Benthos_ATM900] Loaded
2015-07-21T21:41:11.844Z,1437514871.844 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread.
2015-07-21T21:41:12.030Z,1437514872.030 [DataOverHttps] Loaded
2015-07-21T21:41:12.031Z,1437514872.031 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2015-07-21T21:41:12.049Z,1437514872.049 [Depth_Keller] Loaded
2015-07-21T21:41:12.049Z,1437514872.049 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2015-07-21T21:41:12.054Z,1437514872.054 [DropWeight] Loaded
2015-07-21T21:41:12.054Z,1437514872.054 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2015-07-21T21:41:12.158Z,1437514872.158 [NAL9602] Loaded
2015-07-21T21:41:12.158Z,1437514872.158 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2015-07-21T21:41:12.205Z,1437514872.205 [Onboard] Loaded
2015-07-21T21:41:12.205Z,1437514872.205 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2015-07-21T21:41:12.213Z,1437514872.213 [Radio_Surface] Loaded
2015-07-21T21:41:12.213Z,1437514872.213 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2015-07-21T21:41:12.221Z,1437514872.221 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408054E0
2015-07-21T21:41:12.222Z,1437514872.222 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 849
2015-07-21T21:41:12.440Z,1437514872.440 [PNI_TCM] Loaded
2015-07-21T21:41:12.441Z,1437514872.441 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2015-07-21T21:41:12.649Z,1437514872.649 [Rowe_600] Loaded
2015-07-21T21:41:12.650Z,1437514872.650 [ComponentRegistry](DEBUG): Component "Rowe_600" handled in its own thread.
2015-07-21T21:41:12.654Z,1437514872.654 [Rowe_600 ThreadHandler](DEBUG): Created PCaller Thread at 408354E0
2015-07-21T21:41:12.654Z,1437514872.654 [Rowe_600 ThreadHandler](INFO): Protected caller Thread ID is 850
2015-07-21T21:41:14.779Z,1437514874.779 [BPC1] Loaded
2015-07-21T21:41:14.779Z,1437514874.779 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2015-07-21T21:41:14.779Z,1437514874.779 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2015-07-21T21:41:14.781Z,1437514874.781 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2015-07-21T21:41:14.922Z,1437514874.922 [BuoyancyServo] Loaded
2015-07-21T21:41:14.922Z,1437514874.922 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2015-07-21T21:41:14.935Z,1437514874.935 [ElevatorServo] Loaded
2015-07-21T21:41:14.936Z,1437514874.936 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2015-07-21T21:41:14.948Z,1437514874.948 [MassServo] Loaded
2015-07-21T21:41:14.948Z,1437514874.948 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2015-07-21T21:41:14.965Z,1437514874.965 [RudderServo] Loaded
2015-07-21T21:41:14.965Z,1437514874.965 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2015-07-21T21:41:14.978Z,1437514874.978 [ThrusterServo] Loaded
2015-07-21T21:41:14.978Z,1437514874.978 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2015-07-21T21:41:14.979Z,1437514874.979 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2015-07-21T21:41:14.979Z,1437514874.979 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2015-07-21T21:41:15.126Z,1437514875.126 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2015-07-21T21:41:15.126Z,1437514875.126 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2015-07-21T21:41:15.165Z,1437514875.165 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2015-07-21T21:41:15.173Z,1437514875.173 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2015-07-21T21:41:15.174Z,1437514875.174 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2015-07-21T21:41:15.181Z,1437514875.181 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2015-07-21T21:41:15.186Z,1437514875.186 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 408E34E0
2015-07-21T21:41:15.186Z,1437514875.186 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 851
2015-07-21T21:41:15.191Z,1437514875.191 [Supervisor](INFO): Main Thread ID is 764
2015-07-21T21:41:15.191Z,1437514875.191 [Supervisor](DEBUG): Running supervisor.
2015-07-21T21:41:15.192Z,1437514875.192 [CommandLine ThreadHandler](INFO): Handler Thread ID is 852
2015-07-21T21:41:15.198Z,1437514875.198 [controlThread ThreadHandler](INFO): Handler Thread ID is 853
2015-07-21T21:41:15.199Z,1437514875.199 [controlThread](DEBUG): Initializing ControlThread
2015-07-21T21:41:15.200Z,1437514875.200 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2015-07-21T21:41:15.202Z,1437514875.202 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2015-07-21T21:41:15.202Z,1437514875.202 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2015-07-21T21:41:15.203Z,1437514875.203 [LoopControl](DEBUG): Initialize LoopControlComponent.
2015-07-21T21:41:15.203Z,1437514875.203 [SBIT](INFO): Initialize SBIT Component.
2015-07-21T21:41:15.204Z,1437514875.204 [SBIT](IMPORTANT): Tethys CM Info: SVN revision:12496
2015-07-21T21:41:15.204Z,1437514875.204 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2015-07-21T21:41:15.204Z,1437514875.204 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2015-07-21T21:41:15.205Z,1437514875.205 [SBIT](INFO): Beginning SBIT in 63.000000 seconds.
2015-07-21T21:41:15.206Z,1437514875.206 [IBIT](INFO): Initialize IBIT Component.
2015-07-21T21:41:15.207Z,1437514875.207 [CBIT](DEBUG): Initialize CBIT Component.
2015-07-21T21:41:15.207Z,1437514875.207 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2015-07-21T21:41:15.207Z,1437514875.207 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2015-07-21T21:41:15.210Z,1437514875.210 [logger ThreadHandler](INFO): Handler Thread ID is 854
2015-07-21T21:41:15.230Z,1437514875.230 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2015-07-21T21:41:15.231Z,1437514875.231 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2015-07-21T21:41:15.231Z,1437514875.231 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2015-07-21T21:41:15.231Z,1437514875.231 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2015-07-21T21:41:15.232Z,1437514875.232 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2015-07-21T21:41:15.232Z,1437514875.232 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-07-21T21:41:15.233Z,1437514875.233 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after this many seconds: 120.000000
2015-07-21T21:41:15.233Z,1437514875.233 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after this many seconds: 20.000000
2015-07-21T21:41:15.234Z,1437514875.234 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2015-07-21T21:41:15.234Z,1437514875.234 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after this many seconds: 120.000000
2015-07-21T21:41:15.234Z,1437514875.234 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after this many seconds: 20.000000
2015-07-21T21:41:15.235Z,1437514875.235 [NavChart](DEBUG): Initialize NavChart Navigation.
2015-07-21T21:41:15.235Z,1437514875.235 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2015-07-21T21:41:15.259Z,1437514875.259 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2015-07-21T21:41:15.275Z,1437514875.275 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 856
2015-07-21T21:41:15.276Z,1437514875.276 [WetLabsBB2FL](INFO): Powering down
2015-07-21T21:41:15.298Z,1437514875.298 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 855
2015-07-21T21:41:15.301Z,1437514875.301 [CTD_NeilBrown](INFO): Powering down
2015-07-21T21:41:15.300Z,1437514875.300 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 857
2015-07-21T21:41:15.332Z,1437514875.332 [Radio_Surface](INFO): Powering up
2015-07-21T21:41:15.338Z,1437514875.338 [Rowe_600 ThreadHandler](INFO): Handler Thread ID is 858
2015-07-21T21:41:15.343Z,1437514875.343 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 859
2015-07-21T21:41:15.364Z,1437514875.364 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2015-07-21T21:41:15.366Z,1437514875.366 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2015-07-21T21:41:15.366Z,1437514875.366 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2015-07-21T21:41:15.367Z,1437514875.367 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2015-07-21T21:41:15.367Z,1437514875.367 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2015-07-21T21:41:15.367Z,1437514875.367 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2015-07-21T21:41:15.367Z,1437514875.367 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2015-07-21T21:41:15.367Z,1437514875.367 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2015-07-21T21:41:15.368Z,1437514875.368 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2015-07-21T21:41:15.391Z,1437514875.391 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2015-07-21T21:41:15.400Z,1437514875.400 [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://aosn.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://aosn.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>


2015-07-21T21:41:15.401Z,1437514875.401 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2015-07-21T21:41:15.491Z,1437514875.491 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2015-07-21T21:41:15.492Z,1437514875.492 [Default:A.GoToSurface](DEBUG): Construct GoToSurface.
2015-07-21T21:41:15.539Z,1437514875.539 [Default:SplitLargeDefaultLogs:A.Execute](DEBUG): Construct Execute.
2015-07-21T21:41:15.551Z,1437514875.551 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2015-07-21T21:41:15.564Z,1437514875.564 [Default:CheckIn:WaitAnHour:A.Wait](DEBUG): Construct Wait.
2015-07-21T21:41:15.565Z,1437514875.565 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2015-07-21T21:41:15.578Z,1437514875.578 [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://aosn.mbari.org/tethys/Xml/Tethys.xsd
Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
Id="Default">

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

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

    <ReadDatum Id="Read_GPS">
        <Sequence/>
        <Timeout Duration="P5M"/>
<!-- NOTE: Original Default.xml didn't have a timeout on the GPS read, so theoretically could have hung indefinitely there... -->
        <Universal:time_fix/>
    </ReadDatum>

    <Aggregate Id="ReportMinutesSinceMissionStarted">

        <When>
            <Elapsed><Universal:mission_started/></Elapsed>
            <Gt><Units:minute/><Value>10</Value></Gt>
            <And><Elapsed><Universal:time_fix/></Elapsed><Lt><Units:millisecond/><Value>500</Value></Lt></And>
        </When>

        <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>

    <Aggregate Id="SplitLargeDefaultLogs">

        <When>
            <Arg Name="ElapsedSinceDefaultStarted"/>
            <Gt><Units:day/><Value>1</Value></Gt>
        </When>

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

    </Aggregate>

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

        <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>

        <Aggregate Id="WaitAnHour">

            <When>
                <Universal:platform_conversation/>
                <Eq><False/></Eq>
            </When>

            <Guidance:Wait>
                <Sequence/>
                <Setting><Guidance:Wait.duration/><Units:hour/><Value>1</Value></Setting>
            </Guidance:Wait>

        </Aggregate>

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

    </Aggregate>

</Mission>


2015-07-21T21:41:15.583Z,1437514875.583 [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,YawRateCalculator,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2015-07-21T21:41:15.603Z,1437514875.603 [Rowe_600](INFO): Powering down
2015-07-21T21:41:15.688Z,1437514875.688 [AcousticModem_Benthos_ATM900](INFO): Powering up
2015-07-21T21:41:15.688Z,1437514875.688 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2015-07-21T21:41:15.880Z,1437514875.880 [Rowe_600](INFO): Initializing
2015-07-21T21:41:15.895Z,1437514875.895 [Rowe_600](INFO): Powering up
2015-07-21T21:41:16.180Z,1437514876.180 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-07-21T21:41:16.381Z,1437514876.381 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-07-21T21:41:16.496Z,1437514876.496 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2015-07-21T21:41:16.508Z,1437514876.508 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2015-07-21T21:41:16.519Z,1437514876.519 [ElevatorServo](DEBUG): Initializing EZServoServo.
2015-07-21T21:41:16.537Z,1437514876.537 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2015-07-21T21:41:16.543Z,1437514876.543 [MassServo](DEBUG): Initializing EZServoServo.
2015-07-21T21:41:16.549Z,1437514876.549 [MassServo](DEBUG): Initializing MassServo.
2015-07-21T21:41:16.566Z,1437514876.566 [RudderServo](DEBUG): Initializing EZServoServo.
2015-07-21T21:41:16.572Z,1437514876.572 [RudderServo](DEBUG): Initializing RudderServo.
2015-07-21T21:41:16.586Z,1437514876.586 [ThrusterServo](DEBUG): Initializing EZServoServo.
2015-07-21T21:41:16.592Z,1437514876.592 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2015-07-21T21:41:16.629Z,1437514876.629 [CommandLine](FAULT): Scheduling is paused
2015-07-21T21:41:16.840Z,1437514876.840 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-07-21T21:41:16.845Z,1437514876.845 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-07-21T21:41:17.153Z,1437514877.153 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-07-21T21:41:17.155Z,1437514877.155 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-07-21T21:41:17.498Z,1437514877.498 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2015-07-21T21:41:17.498Z,1437514877.498 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2015-07-21T21:41:17.498Z,1437514877.498 [BuoyancyServo] Communications Fault, FailCount= 1
2015-07-21T21:41:17.498Z,1437514877.498 [BuoyancyServo](ERROR): Communications Fault
2015-07-21T21:41:17.712Z,1437514877.712 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2015-07-21T21:41:17.728Z,1437514877.728 [NAL9602](INFO): Powering up NAL9602
2015-07-21T21:41:17.761Z,1437514877.761 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-07-21T21:41:17.778Z,1437514877.778 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-07-21T21:41:17.784Z,1437514877.784 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2015-07-21T21:41:17.786Z,1437514877.786 [BuoyancyServo](INFO): Powering down
2015-07-21T21:41:18.162Z,1437514878.162 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-07-21T21:41:18.179Z,1437514878.179 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-07-21T21:41:18.556Z,1437514878.556 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-07-21T21:41:18.557Z,1437514878.557 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-07-21T21:41:19.036Z,1437514879.036 [Aanderaa_O2](INFO): Powering down
2015-07-21T21:41:19.120Z,1437514879.120 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-07-21T21:41:19.124Z,1437514879.124 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-07-21T21:41:19.402Z,1437514879.402 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-07-21T21:41:19.404Z,1437514879.404 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-07-21T21:41:20.001Z,1437514880.001 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2015-07-21T21:41:20.001Z,1437514880.001 [BuoyancyServo] No Fault, FailCount= 1
2015-07-21T21:41:20.244Z,1437514880.244 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2015-07-21T21:41:20.363Z,1437514880.363 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2015-07-21T21:41:23.328Z,1437514883.328 [AcousticModem_Benthos_ATM900](DEBUG): 
2015-07-21T21:41:24.703Z,1437514884.703 [AcousticModem_Benthos_ATM900](DEBUG): Teledyne Benthos ATM-900 Series OEM w/burn wire
2015-07-21T21:41:24.713Z,1437514884.713 [AcousticModem_Benthos_ATM900](DEBUG): MF Frequency Band
2015-07-21T21:41:24.715Z,1437514884.715 [AcousticModem_Benthos_ATM900](DEBUG): Standard version 8.6.3
2015-07-21T21:41:25.335Z,1437514885.335 [AcousticModem_Benthos_ATM900](DEBUG): Jul 21 2015 21:45:34 
2015-07-21T21:41:26.171Z,1437514886.171 [AcousticModem_Benthos_ATM900](INFO): entering command mode
2015-07-21T21:41:26.609Z,1437514886.609 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgment
2015-07-21T21:41:26.612Z,1437514886.612 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 1: user:1>
2015-07-21T21:41:26.612Z,1437514886.612 [AcousticModem_Benthos_ATM900](INFO): command mode acknowledged
2015-07-21T21:41:27.034Z,1437514887.034 [AcousticModem_Benthos_ATM900](INFO): setting local address to 3
2015-07-21T21:41:27.463Z,1437514887.463 [AcousticModem_Benthos_ATM900](DEBUG): checking for local address setting acknowledgment
2015-07-21T21:41:27.474Z,1437514887.474 [AcousticModem_Benthos_ATM900](INFO): set local address to 3
2015-07-21T21:41:27.902Z,1437514887.902 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 2: user:2>
2015-07-21T21:41:28.838Z,1437514888.838 [NAL9602](INFO): NAL9602 initialized
2015-07-21T21:41:57.796Z,1437514917.796 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0.411542 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:41:58.211Z,1437514918.211 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0.826990 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:41:58.827Z,1437514918.827 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1.435331 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:41:59.156Z,1437514919.156 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1.772661 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:41:59.545Z,1437514919.545 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2.161365 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:41:59.992Z,1437514919.992 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2.600144 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:00.391Z,1437514920.391 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3.007080 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:00.754Z,1437514920.754 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3.371147 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:01.148Z,1437514921.148 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3.764858 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:01.552Z,1437514921.552 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4.168987 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:01.942Z,1437514921.942 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4.558792 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:02.329Z,1437514922.329 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4.945796 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:02.800Z,1437514922.800 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5.408813 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:03.114Z,1437514923.114 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5.731118 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:03.536Z,1437514923.536 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 6.153072 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:03.984Z,1437514923.984 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 6.600670 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:04.345Z,1437514924.345 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 6.961231 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:04.713Z,1437514924.713 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 7.329904 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:05.140Z,1437514925.140 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 7.756465 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:05.524Z,1437514925.524 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 8.140363 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:05.930Z,1437514925.930 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 8.547199 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:06.329Z,1437514926.329 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 8.945316 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:06.704Z,1437514926.704 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 9.321102 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:07.118Z,1437514927.118 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 9.735144 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:07.546Z,1437514927.546 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 10.162710 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:07.934Z,1437514927.934 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 10.550515 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:08.366Z,1437514928.366 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 10.982888 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:08.734Z,1437514928.734 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 11.334730 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:09.179Z,1437514929.179 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 11.787634 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:09.504Z,1437514929.504 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 12.121058 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:09.921Z,1437514929.921 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 12.537606 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:10.302Z,1437514930.302 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 12.918898 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:10.695Z,1437514930.695 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 13.312009 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:11.100Z,1437514931.100 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 13.716338 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:11.528Z,1437514931.528 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 14.144805 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:11.904Z,1437514931.904 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 14.521091 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:12.357Z,1437514932.357 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 14.973795 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:12.756Z,1437514932.756 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 15.364500 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:13.181Z,1437514933.181 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 15.789260 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:13.570Z,1437514933.570 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 16.178165 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:13.931Z,1437514933.931 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 16.548044 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:14.362Z,1437514934.362 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 16.978511 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:14.758Z,1437514934.758 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 17.374628 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:15.152Z,1437514935.152 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 17.760226 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:15.561Z,1437514935.561 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 18.177475 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:15.891Z,1437514935.891 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 18.507492 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:16.303Z,1437514936.303 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 18.920034 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:16.712Z,1437514936.712 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 19.328369 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:17.137Z,1437514937.137 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 19.753330 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:42:18.807Z,1437514938.807 [SBIT](IMPORTANT): Beginning Startup BIT
2015-07-21T21:42:18.829Z,1437514938.829 [CBIT](IMPORTANT): Beginning GF scan
2015-07-21T21:42:45.729Z,1437514965.729 [CBIT](IMPORTANT): No ground fault detected
2015-07-21T21:43:12.706Z,1437514992.706 [SBIT](IMPORTANT): SBIT PASSED
2015-07-21T21:43:12.978Z,1437514992.978 [MissionManager](IMPORTANT): Started mission Startup
2015-07-21T21:43:12.979Z,1437514992.979 [Startup] Running Loop=1
2015-07-21T21:43:12.979Z,1437514992.979 [Startup](DEBUG): Aggregate::initialize Startup
2015-07-21T21:43:12.979Z,1437514992.979 [Startup:A.GoToSurface] Running Loop=1
2015-07-21T21:43:12.980Z,1437514992.980 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2015-07-21T21:43:12.981Z,1437514992.981 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2015-07-21T21:43:12.990Z,1437514992.990 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2015-07-21T21:43:12.991Z,1437514992.991 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s.
2015-07-21T21:43:13.032Z,1437514993.032 [Startup:StartupSatComms] Running Loop=1
2015-07-21T21:43:13.032Z,1437514993.032 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2015-07-21T21:43:13.033Z,1437514993.033 [Startup:StartupSatComms:A] Running Loop=1
2015-07-21T21:43:13.355Z,1437514993.355 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2015-07-21T21:44:13.156Z,1437515053.156 [Startup:StartupSatComms:A](INFO): Timed out from 2015-07-21T21:43:13.0Z
2015-07-21T21:44:13.157Z,1437515053.157 [Startup:StartupSatComms:A] Stopped
2015-07-21T21:44:13.157Z,1437515053.157 [Startup:StartupSatComms:B] Running Loop=1
2015-07-21T21:44:13.613Z,1437515053.613 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2015-07-21T21:44:15.408Z,1437515055.408 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2015-07-21T21:44:15.409Z,1437515055.409 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2015-07-21T21:44:15.409Z,1437515055.409 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2015-07-21T21:44:15.429Z,1437515055.429 [DeadReckonUsingSpeedCalculator](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2015-07-21T21:44:15.430Z,1437515055.430 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2015-07-21T21:44:15.430Z,1437515055.430 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2015-07-21T21:44:15.567Z,1437515055.567 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2015-07-21T21:44:15.567Z,1437515055.567 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2015-07-21T21:44:15.882Z,1437515055.882 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2015-07-21T21:44:15.882Z,1437515055.882 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2015-07-21T21:44:15.883Z,1437515055.883 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2015-07-21T21:44:15.883Z,1437515055.883 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2015-07-21T21:44:16.175Z,1437515056.175 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-07-21T21:44:16.177Z,1437515056.177 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after this many seconds: 120.000000
2015-07-21T21:44:16.177Z,1437515056.177 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after this many seconds: 20.000000
2015-07-21T21:44:16.178Z,1437515056.178 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2015-07-21T21:44:16.187Z,1437515056.187 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after this many seconds: 120.000000
2015-07-21T21:44:16.188Z,1437515056.188 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after this many seconds: 20.000000
2015-07-21T21:44:16.573Z,1437515056.573 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1.158001 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:16.956Z,1437515056.956 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1.548612 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:17.360Z,1437515057.360 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1.952541 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:17.763Z,1437515057.763 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2.347552 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:18.125Z,1437515058.125 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2.717632 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:18.552Z,1437515058.552 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3.136680 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:18.961Z,1437515058.961 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3.554234 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:19.349Z,1437515059.349 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3.929614 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:19.780Z,1437515059.780 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4.372905 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:20.176Z,1437515060.176 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4.769222 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:20.563Z,1437515060.563 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5.147408 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:20.925Z,1437515060.925 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5.518188 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:21.388Z,1437515061.388 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5.972492 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:21.749Z,1437515061.749 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 6.333253 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:22.162Z,1437515062.162 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 6.742589 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:22.553Z,1437515062.553 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 7.145518 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:22.944Z,1437515062.944 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 7.537329 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:23.503Z,1437515063.503 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 8.088082 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:23.845Z,1437515063.845 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 8.437225 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:24.298Z,1437515064.298 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 8.891135 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:24.664Z,1437515064.664 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 9.256702 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:25.088Z,1437515065.088 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 9.681063 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:25.481Z,1437515065.481 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 10.073874 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:25.845Z,1437515065.845 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 10.438241 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:26.234Z,1437515066.234 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 10.826745 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:26.629Z,1437515066.629 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 11.213043 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:27.026Z,1437515067.026 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 11.605754 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:27.445Z,1437515067.445 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 12.025609 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:27.843Z,1437515067.843 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 12.427132 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:28.241Z,1437515068.241 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 12.834167 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:28.690Z,1437515068.690 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 13.282465 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:29.002Z,1437515069.002 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 13.594552 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:29.434Z,1437515069.434 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 14.017906 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:29.848Z,1437515069.848 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 14.440967 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:30.235Z,1437515070.235 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 14.818852 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:30.659Z,1437515070.659 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 15.243313 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:31.017Z,1437515071.017 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 15.610186 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:31.422Z,1437515071.422 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 16.014516 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:31.830Z,1437515071.830 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 16.422251 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:32.243Z,1437515072.243 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 16.835993 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:32.662Z,1437515072.662 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 17.247029 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:33.073Z,1437515073.073 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 17.666083 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:33.456Z,1437515073.456 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 18.048882 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:33.840Z,1437515073.840 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 18.424061 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:34.260Z,1437515074.260 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 18.848122 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:34.655Z,1437515074.655 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 19.247345 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:44:35.072Z,1437515075.072 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 19.665293 seconds since last successful read, accepting data for 20.000000 seconds.
2015-07-21T21:45:06.255Z,1437515106.255 [BPC1](ERROR): Failed to receive battery data
2015-07-21T21:45:06.255Z,1437515106.255 [BPC1] Communications Fault, FailCount= 1
2015-07-21T21:45:06.255Z,1437515106.255 [BPC1](ERROR): Communications Fault
2015-07-21T21:45:06.437Z,1437515106.437 [CBIT](ERROR): Communications Fault in component: BPC1
2015-07-21T21:45:07.602Z,1437515107.602 [CBIT](INFO): Clearing failed state for component BPC1
2015-07-21T21:45:07.603Z,1437515107.603 [BPC1] No Fault, FailCount= 1
2015-07-21T21:45:07.694Z,1437515107.694 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.023938
2015-07-21T21:45:33.158Z,1437515133.158 [BPC1](ERROR): Failed to receive battery data
2015-07-21T21:45:33.158Z,1437515133.158 [BPC1] Communications Fault, FailCount= 2
2015-07-21T21:45:33.158Z,1437515133.158 [BPC1](ERROR): Communications Fault
2015-07-21T21:45:33.288Z,1437515133.288 [Startup:StartupSatComms:B](INFO): Timed out from 2015-07-21T21:44:13.2Z
2015-07-21T21:45:33.288Z,1437515133.288 [Startup:StartupSatComms:B] Stopped
2015-07-21T21:45:33.289Z,1437515133.289 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2015-07-21T21:45:33.289Z,1437515133.289 [Startup:StartupSatComms] Stopped
2015-07-21T21:45:33.289Z,1437515133.289 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2015-07-21T21:45:33.291Z,1437515133.291 [Startup](INFO): Completed Startup
2015-07-21T21:45:33.300Z,1437515133.300 [Startup] Stopped
2015-07-21T21:45:33.300Z,1437515133.300 [Startup](DEBUG): Aggregate::uninitialize Startup
2015-07-21T21:45:33.300Z,1437515133.300 [Startup:A.GoToSurface] Stopped
2015-07-21T21:45:33.300Z,1437515133.300 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2015-07-21T21:45:33.434Z,1437515133.434 [CBIT](ERROR): Communications Fault in component: BPC1
2015-07-21T21:45:33.691Z,1437515133.691 [MissionManager](IMPORTANT): Started mission Default
2015-07-21T21:45:33.692Z,1437515133.692 [Default] Running Loop=1
2015-07-21T21:45:33.700Z,1437515133.700 [Default](DEBUG): Aggregate::initialize Default
2015-07-21T21:45:33.701Z,1437515133.701 [Default:A.GoToSurface] Running Loop=1
2015-07-21T21:45:33.701Z,1437515133.701 [Default:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2015-07-21T21:45:33.702Z,1437515133.702 [Default:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2015-07-21T21:45:33.702Z,1437515133.702 [Default:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2015-07-21T21:45:33.703Z,1437515133.703 [Default:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s.
2015-07-21T21:45:33.762Z,1437515133.762 [Default:Read_GPS] Running Loop=1
2015-07-21T21:45:34.060Z,1437515134.060 [Default:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2015-07-21T21:45:34.768Z,1437515134.768 [CBIT](INFO): Clearing failed state for component BPC1
2015-07-21T21:45:34.769Z,1437515134.769 [BPC1] No Fault, FailCount= 2
2015-07-21T21:45:45.155Z,1437515145.155 [CommandLine](IMPORTANT): got command show stack
2015-07-21T21:45:45.156Z,1437515145.156 [CommandLine](IMPORTANT): Behavior Stack:

2015-07-21T21:45:45.157Z,1437515145.157 [Default](IMPORTANT): Priority 0: Default:A.GoToSurface
2015-07-21T21:45:45.158Z,1437515145.158 [Default](IMPORTANT): Priority 1: Default:Read_GPS
2015-07-21T21:46:19.110Z,1437515179.110 [BPC1](ERROR): Failed to parse bank A battery data
2015-07-21T21:46:19.110Z,1437515179.110 [BPC1] Data Fault, FailCount= 1
2015-07-21T21:46:19.111Z,1437515179.111 [BPC1](ERROR): Data Fault
2015-07-21T21:46:19.254Z,1437515179.254 [CBIT](ERROR): Data Fault in component: BPC1
2015-07-21T21:46:20.448Z,1437515180.448 [CBIT](INFO): Clearing failed state for component BPC1
2015-07-21T21:46:20.448Z,1437515180.448 [BPC1] No Fault, FailCount= 1
2015-07-21T21:46:32.304Z,1437515192.304 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2015-07-21T21:46:33.507Z,1437515193.507 [NAL9602](INFO): GPS fix at 20150721T214625: (36.802727, -121.788039)
2015-07-21T21:46:33.887Z,1437515193.887 [Default:Read_GPS] Stopped
2015-07-21T21:46:33.887Z,1437515193.887 [Default:CheckIn] Running Loop=1
2015-07-21T21:46:33.887Z,1437515193.887 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2015-07-21T21:46:33.887Z,1437515193.887 [Default:CheckIn:Read_Iridium] Running Loop=1
2015-07-21T21:46:34.365Z,1437515194.365 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2015-07-21T21:46:51.214Z,1437515211.214 [NAL9602](INFO): Powering down
2015-07-21T21:47:02.316Z,1437515222.316 [BPC1](ERROR): Failed to parse bank A battery data
2015-07-21T21:47:02.316Z,1437515222.316 [BPC1] Data Fault, FailCount= 1
2015-07-21T21:47:02.317Z,1437515222.317 [BPC1](ERROR): Data Fault
2015-07-21T21:47:02.533Z,1437515222.533 [CBIT](ERROR): Data Fault in component: BPC1
2015-07-21T21:47:14.063Z,1437515234.063 [CBIT](INFO): Clearing failed state for component BPC1
2015-07-21T21:47:14.063Z,1437515234.063 [BPC1] No Fault, FailCount= 1
2015-07-21T21:47:25.577Z,1437515245.577 [CommandLine](IMPORTANT): got command report mod platform_buoyancy_position
2015-07-21T21:47:38.062Z,1437515258.062 [CommandLine](IMPORTANT): got command report mod NAL9602.sigQuality
2015-07-21T21:47:39.850Z,1437515259.850 [BPC1](ERROR): Failed to receive battery data
2015-07-21T21:47:39.850Z,1437515259.850 [BPC1] Communications Fault, FailCount= 2
2015-07-21T21:47:39.850Z,1437515259.850 [BPC1](ERROR): Communications Fault
2015-07-21T21:47:40.111Z,1437515260.111 [CBIT](ERROR): Communications Fault in component: BPC1
2015-07-21T21:47:40.115Z,1437515260.115 [Reporter](INFO): platform_buoyancy_position 951.908354 cc
2015-07-21T21:47:40.117Z,1437515260.117 [Reporter](INFO): NAL9602.sigQuality 0 count
2015-07-21T21:47:41.390Z,1437515261.390 [CBIT](INFO): Clearing failed state for component BPC1
2015-07-21T21:47:41.390Z,1437515261.390 [BPC1] No Fault, FailCount= 2
2015-07-21T21:48:20.997Z,1437515300.997 [BPC1](ERROR): Failed to receive battery data
2015-07-21T21:48:20.997Z,1437515300.997 [BPC1] Communications Fault, FailCount= 1
2015-07-21T21:48:20.997Z,1437515300.997 [BPC1](ERROR): Communications Fault
2015-07-21T21:48:21.196Z,1437515301.196 [CBIT](ERROR): Communications Fault in component: BPC1
2015-07-21T21:48:22.257Z,1437515302.257 [CBIT](INFO): Clearing failed state for component BPC1
2015-07-21T21:48:22.258Z,1437515302.258 [BPC1] No Fault, FailCount= 1
2015-07-21T21:49:01.679Z,1437515341.679 [BPC1](ERROR): Failed to receive battery data
2015-07-21T21:49:01.680Z,1437515341.680 [BPC1] Communications Fault, FailCount= 1
2015-07-21T21:49:01.680Z,1437515341.680 [BPC1](ERROR): Communications Fault
2015-07-21T21:49:01.892Z,1437515341.892 [CBIT](ERROR): Communications Fault in component: BPC1
2015-07-21T21:49:02.992Z,1437515342.992 [CBIT](INFO): Clearing failed state for component BPC1
2015-07-21T21:49:02.993Z,1437515342.993 [BPC1] No Fault, FailCount= 1
2015-07-21T21:49:20.592Z,1437515360.592 [BPC1](ERROR): Failed to receive battery data
2015-07-21T21:49:20.593Z,1437515360.593 [BPC1] Communications Fault, FailCount= 2
2015-07-21T21:49:20.593Z,1437515360.593 [BPC1](ERROR): Communications Fault
2015-07-21T21:49:20.853Z,1437515360.853 [CBIT](ERROR): Communications Fault in component: BPC1
2015-07-21T21:49:21.913Z,1437515361.913 [CBIT](INFO): Clearing failed state for component BPC1
2015-07-21T21:49:21.913Z,1437515361.913 [BPC1] No Fault, FailCount= 2
2015-07-21T21:49:42.600Z,1437515382.600 [BPC1](ERROR): Failed to receive battery data
2015-07-21T21:49:42.601Z,1437515382.601 [BPC1] Communications Fault, FailCount= 3
2015-07-21T21:49:42.601Z,1437515382.601 [BPC1](ERROR): Communications Fault
2015-07-21T21:49:42.827Z,1437515382.827 [CBIT](ERROR): Communications Fault in component: BPC1
2015-07-21T21:49:43.901Z,1437515383.901 [CBIT](INFO): Clearing failed state for component BPC1
2015-07-21T21:49:43.901Z,1437515383.901 [BPC1] No Fault, FailCount= 3
2015-07-21T21:50:30.702Z,1437515430.702 [BPC1](ERROR): Failed to receive battery data
2015-07-21T21:50:30.702Z,1437515430.702 [BPC1] Communications Fault, FailCount= 1
2015-07-21T21:50:30.702Z,1437515430.702 [BPC1](ERROR): Communications Fault
2015-07-21T21:50:30.996Z,1437515430.996 [CBIT](ERROR): Communications Fault in component: BPC1
2015-07-21T21:50:32.276Z,1437515432.276 [CBIT](INFO): Clearing failed state for component BPC1
2015-07-21T21:50:32.276Z,1437515432.276 [BPC1] No Fault, FailCount= 1
2015-07-21T21:51:01.644Z,1437515461.644 [BPC1](ERROR): Failed to receive battery data
2015-07-21T21:51:01.644Z,1437515461.644 [BPC1] Communications Fault, FailCount= 2
2015-07-21T21:51:01.645Z,1437515461.645 [BPC1](ERROR): Communications Fault
2015-07-21T21:51:01.942Z,1437515461.942 [CBIT](ERROR): Communications Fault in component: BPC1
2015-07-21T21:51:03.083Z,1437515463.083 [CBIT](INFO): Clearing failed state for component BPC1
2015-07-21T21:51:03.083Z,1437515463.083 [BPC1] No Fault, FailCount= 2
2015-07-21T21:51:21.568Z,1437515481.568 [CBIT](DEBUG): EFC running - data check-sum false
2015-07-21T21:51:25.677Z,1437515485.677 [CommandLine](IMPORTANT): got command restart system
2015-07-21T21:51:28.441Z,1437515488.441 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2015-07-21T21:51:28.442Z,1437515488.442 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-07-21T21:51:28.584Z,1437515488.584 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2015-07-21T21:51:28.585Z,1437515488.585 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-07-21T21:51:28.587Z,1437515488.587 [CommandLine](INFO): Join timeout helper Thread ID is 929
2015-07-21T21:51:28.593Z,1437515488.593 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2015-07-21T21:51:28.593Z,1437515488.593 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-07-21T21:51:28.594Z,1437515488.594 [NavChartDb](INFO): Join timeout helper Thread ID is 930
2015-07-21T21:51:28.934Z,1437515488.934 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2015-07-21T21:51:28.934Z,1437515488.934 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-07-21T21:51:28.949Z,1437515488.949 [ComponentRegistry](INFO): Shutting down Rowe_600 ThreadHandler
2015-07-21T21:51:28.949Z,1437515488.949 [Rowe_600 ThreadHandler](INFO): Thread cancelled.
2015-07-21T21:51:28.950Z,1437515488.950 [Rowe_600](INFO): Join timeout helper Thread ID is 932
2015-07-21T21:51:29.302Z,1437515489.302 [Rowe_600 ThreadHandler](INFO): Uninitializing protected caller thread.
2015-07-21T21:51:29.303Z,1437515489.303 [Rowe_600](INFO): Powering down
2015-07-21T21:51:29.390Z,1437515489.390 [Rowe_600 ThreadHandler](INFO): Thread cancelled.
2015-07-21T21:51:29.401Z,1437515489.401 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2015-07-21T21:51:29.402Z,1437515489.402 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-07-21T21:51:29.402Z,1437515489.402 [Radio_Surface](INFO): Join timeout helper Thread ID is 933
2015-07-21T21:51:29.750Z,1437515489.750 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2015-07-21T21:51:29.751Z,1437515489.751 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-07-21T21:51:29.751Z,1437515489.751 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2015-07-21T21:51:29.751Z,1437515489.751 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2015-07-21T21:51:29.752Z,1437515489.752 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 936
2015-07-21T21:51:30.027Z,1437515490.027 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2015-07-21T21:51:30.027Z,1437515490.027 [WetLabsBB2FL](INFO): Powering down
2015-07-21T21:51:30.028Z,1437515490.028 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2015-07-21T21:51:30.047Z,1437515490.047 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2015-07-21T21:51:30.048Z,1437515490.048 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2015-07-21T21:51:30.048Z,1437515490.048 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 937
2015-07-21T21:51:30.071Z,1437515490.071 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2015-07-21T21:51:30.071Z,1437515490.071 [CTD_NeilBrown](INFO): Powering down
2015-07-21T21:51:30.072Z,1437515490.072 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2015-07-21T21:51:30.099Z,1437515490.099 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2015-07-21T21:51:30.099Z,1437515490.099 [logger ThreadHandler](INFO): Thread cancelled.
2015-07-21T21:51:30.100Z,1437515490.100 [logger](INFO): Join timeout helper Thread ID is 938
2015-07-21T21:51:30.163Z,1437515490.163 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2015-07-21T21:51:30.163Z,1437515490.163 [logger ThreadHandler](INFO): Thread cancelled.
2015-07-21T21:51:30.179Z,1437515490.179 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2015-07-21T21:51:30.180Z,1437515490.180 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-07-21T21:51:30.180Z,1437515490.180 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2015-07-21T21:51:30.180Z,1437515490.180 [controlThread ThreadHandler](INFO): Thread cancelled.
2015-07-21T21:51:30.180Z,1437515490.180 [controlThread](INFO): Join timeout helper Thread ID is 939
2015-07-21T21:51:31.107Z,1437515491.107 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2015-07-21T21:51:31.107Z,1437515491.107 [controlThread](DEBUG): Uninitializing ControlThread
2015-07-21T21:51:31.107Z,1437515491.107 [Aanderaa_O2](INFO): Powering down
2015-07-21T21:51:31.109Z,1437515491.109 [AcousticModem_Benthos_ATM900](INFO): Powering down
2015-07-21T21:51:31.237Z,1437515491.237 [NAL9602](INFO): Powering down
2015-07-21T21:51:31.238Z,1437515491.238 [PNI_TCM](INFO): Powering down
2015-07-21T21:51:31.325Z,1437515491.325 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2015-07-21T21:51:31.327Z,1437515491.327 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2015-07-21T21:51:31.327Z,1437515491.327 [Default] Stopped
2015-07-21T21:51:31.327Z,1437515491.327 [Default](DEBUG): Aggregate::uninitialize Default
2015-07-21T21:51:31.328Z,1437515491.328 [Default:A.GoToSurface] Stopped
2015-07-21T21:51:31.328Z,1437515491.328 [Default:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2015-07-21T21:51:31.328Z,1437515491.328 [Default:CheckIn] Stopped
2015-07-21T21:51:31.328Z,1437515491.328 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2015-07-21T21:51:31.328Z,1437515491.328 [Default:CheckIn:Read_Iridium] Stopped
2015-07-21T21:51:31.331Z,1437515491.331 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2015-07-21T21:51:31.331Z,1437515491.331 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2015-07-21T21:51:31.332Z,1437515491.332 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2015-07-21T21:51:31.332Z,1437515491.332 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2015-07-21T21:51:31.332Z,1437515491.332 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2015-07-21T21:51:31.333Z,1437515491.333 [BuoyancyServo](INFO): Powering down
2015-07-21T21:51:31.344Z,1437515491.344 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2015-07-21T21:51:31.345Z,1437515491.345 [ElevatorServo](INFO): Powering down
2015-07-21T21:51:31.346Z,1437515491.346 [MassServo](DEBUG): Uninitialize Mass Servo.
2015-07-21T21:51:31.346Z,1437515491.346 [MassServo](INFO): Powering down
2015-07-21T21:51:31.347Z,1437515491.347 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2015-07-21T21:51:31.347Z,1437515491.347 [RudderServo](INFO): Powering down
2015-07-21T21:51:31.348Z,1437515491.348 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2015-07-21T21:51:31.348Z,1437515491.348 [ThrusterServo](INFO): Powering down
2015-07-21T21:51:31.349Z,1437515491.349 [SBIT](DEBUG): Uninitialize SBIT Component.
2015-07-21T21:51:31.349Z,1437515491.349 [IBIT](DEBUG): Uninitialize IBIT Component.
2015-07-21T21:51:31.349Z,1437515491.349 [CBIT](DEBUG): Uninitialize CBIT Component.
2015-07-21T21:51:31.385Z,1437515491.385 [controlThread ThreadHandler](INFO): Thread cancelled.
2015-07-21T21:51:31.451Z,1437515491.451 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2015-07-21T21:51:31.466Z,1437515491.466 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2015-07-21T21:51:31.561Z,1437515491.561 [Rowe_600 ThreadHandler](INFO): Thread cancelled.
2015-07-21T21:51:31.569Z,1437515491.569 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-07-21T21:51:31.732Z,1437515491.732 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-07-21T21:51:31.795Z,1437515491.795 [logger ThreadHandler](INFO): Thread cancelled.