2014-08-06T01:14:14.294Z,1407287654.294 [Supervisor](DEBUG): Initializing supervisor.
2014-08-06T01:14:14.297Z,1407287654.297 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0
2014-08-06T01:14:14.298Z,1407287654.298 [SyncHandler](INFO): Protected caller Thread ID is 1346
2014-08-06T01:14:14.298Z,1407287654.298 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2014-08-06T01:14:14.299Z,1407287654.299 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0
2014-08-06T01:14:14.300Z,1407287654.300 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1347
2014-08-06T01:14:14.302Z,1407287654.302 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2014-08-06T01:14:14.315Z,1407287654.315 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2014-08-06T01:14:14.316Z,1407287654.316 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0
2014-08-06T01:14:14.316Z,1407287654.316 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1348
2014-08-06T01:14:14.317Z,1407287654.317 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2014-08-06T01:14:14.318Z,1407287654.318 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0
2014-08-06T01:14:14.319Z,1407287654.319 [logger ThreadHandler](INFO): Protected caller Thread ID is 1349
2014-08-06T01:14:14.321Z,1407287654.321 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2014-08-06T01:14:14.322Z,1407287654.322 [Supervisor](INFO): Looking for Config files in directory: Config/
2014-08-06T01:14:14.323Z,1407287654.323 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2014-08-06T01:14:14.873Z,1407287654.873 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2014-08-06T01:14:14.874Z,1407287654.874 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2014-08-06T01:14:15.047Z,1407287655.047 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2014-08-06T01:14:15.047Z,1407287655.047 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2014-08-06T01:14:15.163Z,1407287655.163 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2014-08-06T01:14:15.164Z,1407287655.164 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2014-08-06T01:14:15.299Z,1407287655.299 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2014-08-06T01:14:15.299Z,1407287655.299 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2014-08-06T01:14:15.390Z,1407287655.390 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2014-08-06T01:14:15.536Z,1407287655.536 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2014-08-06T01:14:15.537Z,1407287655.537 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2014-08-06T01:14:15.628Z,1407287655.628 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2014-08-06T01:14:15.629Z,1407287655.629 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2014-08-06T01:14:15.825Z,1407287655.825 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2014-08-06T01:14:15.825Z,1407287655.825 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2014-08-06T01:14:16.150Z,1407287656.150 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2014-08-06T01:14:16.151Z,1407287656.151 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2014-08-06T01:14:16.498Z,1407287656.498 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2014-08-06T01:14:16.499Z,1407287656.499 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2014-08-06T01:14:17.059Z,1407287657.059 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2014-08-06T01:14:17.060Z,1407287657.060 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2014-08-06T01:14:17.284Z,1407287657.284 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2014-08-06T01:14:17.285Z,1407287657.285 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2014-08-06T01:14:17.395Z,1407287657.395 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2014-08-06T01:14:17.396Z,1407287657.396 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2014-08-06T01:14:17.845Z,1407287657.845 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2014-08-06T01:14:17.846Z,1407287657.846 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2014-08-06T01:14:17.965Z,1407287657.965 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2014-08-06T01:14:17.967Z,1407287657.967 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2014-08-06T01:14:17.968Z,1407287657.968 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2014-08-06T01:14:18.082Z,1407287658.082 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2014-08-06T01:14:18.212Z,1407287658.212 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Estimation.cfg
2014-08-06T01:14:18.331Z,1407287658.331 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2014-08-06T01:14:18.443Z,1407287658.443 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2014-08-06T01:14:20.370Z,1407287660.370 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2014-08-06T01:14:20.534Z,1407287660.534 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2014-08-06T01:14:20.643Z,1407287660.643 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2014-08-06T01:14:20.733Z,1407287660.733 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2014-08-06T01:14:20.837Z,1407287660.837 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2014-08-06T01:14:20.940Z,1407287660.940 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2014-08-06T01:14:21.060Z,1407287661.060 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2014-08-06T01:14:21.154Z,1407287661.154 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/
2014-08-06T01:14:21.155Z,1407287661.155 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2014-08-06T01:14:21.156Z,1407287661.156 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2014-08-06T01:14:21.209Z,1407287661.209 [VerticalControl](DEBUG): Construct VerticalControl.
2014-08-06T01:14:21.334Z,1407287661.334 [VerticalControl] Loaded
2014-08-06T01:14:21.334Z,1407287661.334 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2014-08-06T01:14:21.335Z,1407287661.335 [HorizontalControl](DEBUG): Construct HorizontalControl.
2014-08-06T01:14:21.410Z,1407287661.410 [HorizontalControl] Loaded
2014-08-06T01:14:21.410Z,1407287661.410 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2014-08-06T01:14:21.411Z,1407287661.411 [SpeedControl](DEBUG): Construct SpeedControl.
2014-08-06T01:14:21.416Z,1407287661.416 [SpeedControl] Loaded
2014-08-06T01:14:21.417Z,1407287661.417 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2014-08-06T01:14:21.417Z,1407287661.417 [LoopControl](DEBUG): Construct LoopControl.
2014-08-06T01:14:21.418Z,1407287661.418 [LoopControl] Loaded
2014-08-06T01:14:21.418Z,1407287661.418 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2014-08-06T01:14:21.419Z,1407287661.419 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2014-08-06T01:14:21.419Z,1407287661.419 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2014-08-06T01:14:21.522Z,1407287661.522 [SBIT](DEBUG): Construct Startup Built In Test.
2014-08-06T01:14:21.534Z,1407287661.534 [SBIT] Loaded
2014-08-06T01:14:21.534Z,1407287661.534 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2014-08-06T01:14:21.535Z,1407287661.535 [IBIT](DEBUG): Construct Initiated Built In Test.
2014-08-06T01:14:21.565Z,1407287661.565 [IBIT] Loaded
2014-08-06T01:14:21.565Z,1407287661.565 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2014-08-06T01:14:21.567Z,1407287661.567 [CBIT](DEBUG): Construct CBIT Built In Test.
2014-08-06T01:14:21.688Z,1407287661.688 [CBIT] Loaded
2014-08-06T01:14:21.688Z,1407287661.688 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2014-08-06T01:14:21.689Z,1407287661.689 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2014-08-06T01:14:21.689Z,1407287661.689 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2014-08-06T01:14:21.709Z,1407287661.709 [DepthRateCalculator] Loaded
2014-08-06T01:14:21.709Z,1407287661.709 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2014-08-06T01:14:21.715Z,1407287661.715 [PitchRateCalculator] Loaded
2014-08-06T01:14:21.715Z,1407287661.715 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2014-08-06T01:14:21.727Z,1407287661.727 [SpeedCalculator] Loaded
2014-08-06T01:14:21.727Z,1407287661.727 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2014-08-06T01:14:21.744Z,1407287661.744 [TempGradientCalculator] Loaded
2014-08-06T01:14:21.745Z,1407287661.745 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2014-08-06T01:14:21.750Z,1407287661.750 [YawRateCalculator] Loaded
2014-08-06T01:14:21.751Z,1407287661.751 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2014-08-06T01:14:21.751Z,1407287661.751 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2014-08-06T01:14:21.752Z,1407287661.752 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2014-08-06T01:14:28.391Z,1407287668.391 [HFRadarModelCalc] Loaded
2014-08-06T01:14:28.391Z,1407287668.391 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2014-08-06T01:14:33.276Z,1407287673.276 [HFRadarCompactModelForecaster] Loaded
2014-08-06T01:14:33.276Z,1407287673.276 [ComponentRegistry](DEBUG): SyncComponent "HFRadarCompactModelForecaster" handled in the control thread.
2014-08-06T01:14:34.596Z,1407287674.596 [HFRCMSpaceInterpolator] Loaded
2014-08-06T01:14:34.596Z,1407287674.596 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSpaceInterpolator" handled in the control thread.
2014-08-06T01:14:34.598Z,1407287674.598 [HFRCMTimeInterpolator] Loaded
2014-08-06T01:14:34.599Z,1407287674.599 [ComponentRegistry](DEBUG): SyncComponent "HFRCMTimeInterpolator" handled in the control thread.
2014-08-06T01:14:35.958Z,1407287675.958 [HFRCMReconstructedInterpolator] Loaded
2014-08-06T01:14:35.958Z,1407287675.958 [ComponentRegistry](DEBUG): SyncComponent "HFRCMReconstructedInterpolator" handled in the control thread.
2014-08-06T01:14:35.971Z,1407287675.971 [HFRCMSurfaceCurrentAtVehicleLocation] Loaded
2014-08-06T01:14:35.971Z,1407287675.971 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSurfaceCurrentAtVehicleLocation" handled in the control thread.
2014-08-06T01:14:35.999Z,1407287675.999 [HFRCMVirtualSurfaceDrifter] Loaded
2014-08-06T01:14:35.999Z,1407287675.999 [ComponentRegistry](DEBUG): SyncComponent "HFRCMVirtualSurfaceDrifter" handled in the control thread.
2014-08-06T01:14:35.000Z,1407287676.000 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2014-08-06T01:14:36.001Z,1407287676.001 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2014-08-06T01:14:36.240Z,1407287676.240 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2014-08-06T01:14:36.241Z,1407287676.241 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2014-08-06T01:14:36.326Z,1407287676.326 [DeadReckonUsingMultipleVelocitySources] Loaded
2014-08-06T01:14:36.327Z,1407287676.327 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2014-08-06T01:14:36.373Z,1407287676.373 [DeadReckonWithRespectToWater] Loaded
2014-08-06T01:14:36.374Z,1407287676.374 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToWater" handled in the control thread.
2014-08-06T01:14:36.422Z,1407287676.422 [DeadReckonWithRespectToSeafloor] Loaded
2014-08-06T01:14:36.423Z,1407287676.423 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToSeafloor" handled in the control thread.
2014-08-06T01:14:36.484Z,1407287676.484 [DeadReckonUsingDVLWaterTrack] Loaded
2014-08-06T01:14:36.484Z,1407287676.484 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingDVLWaterTrack" handled in the control thread.
2014-08-06T01:14:36.534Z,1407287676.534 [DeadReckonUsingCompactModelForecast] Loaded
2014-08-06T01:14:36.534Z,1407287676.534 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingCompactModelForecast" handled in the control thread.
2014-08-06T01:14:36.552Z,1407287676.552 [NavChart] Loaded
2014-08-06T01:14:36.553Z,1407287676.553 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2014-08-06T01:14:36.557Z,1407287676.557 [UniversalFixResidualReporter] Loaded
2014-08-06T01:14:36.557Z,1407287676.557 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2014-08-06T01:14:36.558Z,1407287676.558 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2014-08-06T01:14:36.558Z,1407287676.558 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2014-08-06T01:14:36.564Z,1407287676.564 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2014-08-06T01:14:36.565Z,1407287676.565 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2014-08-06T01:14:36.741Z,1407287676.741 [CTD_NeilBrown] Loaded
2014-08-06T01:14:36.742Z,1407287676.742 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2014-08-06T01:14:36.743Z,1407287676.743 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 407B94E0
2014-08-06T01:14:36.743Z,1407287676.743 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 1431
2014-08-06T01:14:36.760Z,1407287676.760 [PAR_Licor] Loaded
2014-08-06T01:14:36.760Z,1407287676.760 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2014-08-06T01:14:36.796Z,1407287676.796 [WetLabsBB2FL] Loaded
2014-08-06T01:14:36.797Z,1407287676.797 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2014-08-06T01:14:36.798Z,1407287676.798 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407E94E0
2014-08-06T01:14:36.798Z,1407287676.798 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1432
2014-08-06T01:14:36.799Z,1407287676.799 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2014-08-06T01:14:36.800Z,1407287676.800 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2014-08-06T01:14:37.099Z,1407287677.099 [AHRS_sp3003D] Loaded
2014-08-06T01:14:37.099Z,1407287677.099 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2014-08-06T01:14:37.367Z,1407287677.367 [Batt_Ocean_Server] Loaded
2014-08-06T01:14:37.367Z,1407287677.367 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2014-08-06T01:14:37.382Z,1407287677.382 [Depth_Keller] Loaded
2014-08-06T01:14:37.382Z,1407287677.382 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2014-08-06T01:14:37.387Z,1407287677.387 [DropWeight] Loaded
2014-08-06T01:14:37.387Z,1407287677.387 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2014-08-06T01:14:37.524Z,1407287677.524 [DVL_micro] Loaded
2014-08-06T01:14:37.524Z,1407287677.524 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2014-08-06T01:14:37.621Z,1407287677.621 [NAL9602] Loaded
2014-08-06T01:14:37.622Z,1407287677.622 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2014-08-06T01:14:37.665Z,1407287677.665 [Onboard] Loaded
2014-08-06T01:14:37.666Z,1407287677.666 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2014-08-06T01:14:37.673Z,1407287677.673 [Radio_Freewave] Loaded
2014-08-06T01:14:37.674Z,1407287677.674 [ComponentRegistry](DEBUG): Component "Radio_Freewave" handled in its own thread.
2014-08-06T01:14:37.675Z,1407287677.675 [Radio_Freewave ThreadHandler](DEBUG): Created PCaller Thread at 40A204E0
2014-08-06T01:14:37.675Z,1407287677.675 [Radio_Freewave ThreadHandler](INFO): Protected caller Thread ID is 1433
2014-08-06T01:14:37.810Z,1407287677.810 [DAT] Loaded
2014-08-06T01:14:37.810Z,1407287677.810 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2014-08-06T01:14:37.817Z,1407287677.817 [SCPI] Loaded
2014-08-06T01:14:37.818Z,1407287677.818 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread.
2014-08-06T01:14:37.818Z,1407287677.818 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2014-08-06T01:14:37.819Z,1407287677.819 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2014-08-06T01:14:37.920Z,1407287677.920 [BuoyancyServo] Loaded
2014-08-06T01:14:37.920Z,1407287677.920 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2014-08-06T01:14:37.933Z,1407287677.933 [ElevatorServo] Loaded
2014-08-06T01:14:37.933Z,1407287677.933 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2014-08-06T01:14:37.945Z,1407287677.945 [MassServo] Loaded
2014-08-06T01:14:37.945Z,1407287677.945 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2014-08-06T01:14:37.958Z,1407287677.958 [RudderServo] Loaded
2014-08-06T01:14:37.958Z,1407287677.958 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2014-08-06T01:14:37.970Z,1407287677.970 [ThrusterServo] Loaded
2014-08-06T01:14:37.970Z,1407287677.970 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2014-08-06T01:14:37.971Z,1407287677.971 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2014-08-06T01:14:37.971Z,1407287677.971 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2014-08-06T01:14:38.134Z,1407287678.134 [InternalSim] Loaded
2014-08-06T01:14:38.135Z,1407287678.135 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2014-08-06T01:14:38.135Z,1407287678.135 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2014-08-06T01:14:38.136Z,1407287678.136 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2014-08-06T01:14:38.160Z,1407287678.160 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2014-08-06T01:14:38.162Z,1407287678.162 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2014-08-06T01:14:38.163Z,1407287678.163 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2014-08-06T01:14:38.170Z,1407287678.170 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2014-08-06T01:14:38.172Z,1407287678.172 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AD14E0
2014-08-06T01:14:38.172Z,1407287678.172 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1434
2014-08-06T01:14:38.177Z,1407287678.177 [Supervisor](INFO): Main Thread ID is 774
2014-08-06T01:14:38.177Z,1407287678.177 [Supervisor](DEBUG): Running supervisor.
2014-08-06T01:14:38.178Z,1407287678.178 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1435
2014-08-06T01:14:38.183Z,1407287678.183 [controlThread ThreadHandler](INFO): Handler Thread ID is 1436
2014-08-06T01:14:38.183Z,1407287678.183 [controlThread](DEBUG): Initializing ControlThread
2014-08-06T01:14:38.184Z,1407287678.184 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2014-08-06T01:14:38.186Z,1407287678.186 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2014-08-06T01:14:38.186Z,1407287678.186 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2014-08-06T01:14:38.187Z,1407287678.187 [LoopControl](DEBUG): Initialize LoopControlComponent.
2014-08-06T01:14:38.187Z,1407287678.187 [SBIT](INFO): Initialize SBIT Component.
2014-08-06T01:14:38.188Z,1407287678.188 [SBIT](IMPORTANT): Tethys CM Info: SVN revision: 11478
2014-08-06T01:14:38.188Z,1407287678.188 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2014-08-06T01:14:38.188Z,1407287678.188 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2014-08-06T01:14:38.189Z,1407287678.189 [IBIT](INFO): Initialize IBIT Component.
2014-08-06T01:14:38.190Z,1407287678.190 [CBIT](DEBUG): Initialize CBIT Component.
2014-08-06T01:14:38.190Z,1407287678.190 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2014-08-06T01:14:38.191Z,1407287678.191 [logger ThreadHandler](INFO): Handler Thread ID is 1437
2014-08-06T01:14:38.209Z,1407287678.209 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 1438
2014-08-06T01:14:38.210Z,1407287678.210 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2014-08-06T01:14:38.213Z,1407287678.213 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2014-08-06T01:14:38.213Z,1407287678.213 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2014-08-06T01:14:38.214Z,1407287678.214 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2014-08-06T01:14:38.214Z,1407287678.214 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2014-08-06T01:14:38.214Z,1407287678.214 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2014-08-06T01:14:38.217Z,1407287678.217 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2014-08-06T01:14:38.229Z,1407287678.229 [HFRadarCompactModelForecaster](DEBUG): Found new ECs!
2014-08-06T01:14:38.231Z,1407287678.231 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1440
2014-08-06T01:14:38.232Z,1407287678.232 [WetLabsBB2FL](INFO): Powering down
2014-08-06T01:14:38.270Z,1407287678.270 [Radio_Freewave ThreadHandler](INFO): Handler Thread ID is 1441
2014-08-06T01:14:38.291Z,1407287678.291 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1442
2014-08-06T01:14:38.305Z,1407287678.305 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2014-08-06T01:14:38.306Z,1407287678.306 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2014-08-06T01:14:38.306Z,1407287678.306 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2014-08-06T01:14:38.306Z,1407287678.306 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2014-08-06T01:14:38.307Z,1407287678.307 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2014-08-06T01:14:38.307Z,1407287678.307 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2014-08-06T01:14:38.307Z,1407287678.307 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2014-08-06T01:14:38.307Z,1407287678.307 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2014-08-06T01:14:38.308Z,1407287678.308 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2014-08-06T01:14:47.428Z,1407287687.428 [HFRadarCompactModelForecaster](IMPORTANT): forecast time 201408052200: published 50 modes in rows, 61 hours in columns
2014-08-06T01:14:47.447Z,1407287687.447 [HFRadarCompactModelForecaster](IMPORTANT): expansionCoefficients_[0][48] = 19.649141 for 2014-08-05T22:00:00.000Z
2014-08-06T01:14:47.448Z,1407287687.448 [HFRCMSpaceInterpolator](DEBUG): Initializing HFRCMSpaceInterpolator component with verbosity level 0.
2014-08-06T01:14:47.450Z,1407287687.450 [HFRCMTimeInterpolator](DEBUG): Initializing HFRCMTimeInterpolator component.
2014-08-06T01:14:47.450Z,1407287687.450 [HFRCMReconstructedInterpolator](INFO): Initializing HFRCMReconstructedInterpolator component with velocityAccuracy_ = 0.300000 m/s.
2014-08-06T01:14:47.459Z,1407287687.459 [HFRCMSurfaceCurrentAtVehicleLocation](DEBUG): Initializing HFRCMSurfaceCurrentAtVehicleLocation component.
2014-08-06T01:14:47.460Z,1407287687.460 [HFRCMVirtualSurfaceDrifter](DEBUG): Initializing HFRCMVirtualSurfaceDrifter component.
2014-08-06T01:14:47.460Z,1407287687.460 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2014-08-06T01:14:47.461Z,1407287687.461 [DeadReckonWithRespectToWater](DEBUG): Initializing DeadReckonWithRespectToWater component.
2014-08-06T01:14:47.461Z,1407287687.461 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component.
2014-08-06T01:14:47.461Z,1407287687.461 [DeadReckonUsingDVLWaterTrack](DEBUG): Initializing DeadReckonUsingDVLWaterTrack component.
2014-08-06T01:14:47.462Z,1407287687.462 [DeadReckonUsingCompactModelForecast](DEBUG): Initializing DeadReckonUsingCompactModelForecast component.
2014-08-06T01:14:47.462Z,1407287687.462 [NavChart](DEBUG): Initialize NavChart Navigation.
2014-08-06T01:14:47.463Z,1407287687.463 [UniversalFixResidualReporter](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2014-08-06T01:14:48.949Z,1407287688.949 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2014-08-06T01:14:48.982Z,1407287688.982 [InternalSim](DEBUG):  InternalSim initializing...
2014-08-06T01:14:49.090Z,1407287689.090 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2014-08-06T01:14:49.169Z,1407287689.169 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2014-08-06T01:14:49.208Z,1407287689.208 [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>


2014-08-06T01:14:49.208Z,1407287689.208 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2014-08-06T01:14:49.280Z,1407287689.280 [Default:A.GoToSurface](DEBUG): Construct GoToSurface.
2014-08-06T01:14:49.350Z,1407287689.350 [Default:CheckIn:A.SetSpeed](DEBUG): Construct.
2014-08-06T01:14:49.357Z,1407287689.357 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2014-08-06T01:14:49.384Z,1407287689.384 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Construct.
2014-08-06T01:14:49.390Z,1407287689.390 [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">

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

    <Aggregate Id="CheckIn">

        <When>
            <Elapsed><Universal:platform_communications/></Elapsed>
            <Gt><Units:minute/><Value>5.0</Value></Gt>
            <And><Universal:platform_conversation/><Eq><True/></Eq></And>
            <Or><Elapsed><Universal:platform_communications/></Elapsed><Gt><Units:hour/><Value>1.0</Value></Gt></Or>
        </When>

<!-- TODO: Do we really want this When operating on platform_communications? or on something else like time_fix? -->

<!-- Run application at high speed -->

        <Guidance:SetSpeed>
            <Parallel/>
            <Setting><Guidance:SetSpeed.period/><Units:millisecond/><Value>400</Value></Setting>
        </Guidance:SetSpeed>

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

<!-- Do data comms -->

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

    </Aggregate>

    <Aggregate Id="WaitAtTheSurface">

        <Sequence/>

        <Guidance:SetSpeed Id="RunApplicationAtLowSpeed">
            <Parallel/>
            <Setting><Guidance:SetSpeed.period/><Units:second/><Value>5</Value></Setting>
        </Guidance:SetSpeed>

    </Aggregate>

</Mission>


2014-08-06T01:14:49.417Z,1407287689.417 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,PAR_Licor,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,DAT,SCPI,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,HFRadarModelCalc,HFRadarCompactModelForecaster,HFRCMSpaceInterpolator,HFRCMTimeInterpolator,HFRCMReconstructedInterpolator,HFRCMSurfaceCurrentAtVehicleLocation,HFRCMVirtualSurfaceDrifter,DeadReckonUsingMultipleVelocitySources,DeadReckonWithRespectToWater,DeadReckonWithRespectToSeafloor,DeadReckonUsingDVLWaterTrack,DeadReckonUsingCompactModelForecast,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2014-08-06T01:14:49.428Z,1407287689.428 [Radio_Freewave](INFO): Powering up
2014-08-06T01:14:49.595Z,1407287689.595 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2014-08-06T01:14:49.784Z,1407287689.784 [DVL_micro](INFO): Initializing
2014-08-06T01:14:49.815Z,1407287689.815 [NAL9602](INFO): Powering up NAL9602
2014-08-06T01:14:49.859Z,1407287689.859 [DAT](INFO): Powering up
2014-08-06T01:14:49.859Z,1407287689.859 [DAT](DEBUG): Initializing DAT.
2014-08-06T01:14:50.233Z,1407287690.233 [Radio_Freewave](IMPORTANT): Starting PPPD with command:/sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0
2014-08-06T01:14:57.543Z,1407287697.543 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2014-08-06T01:14:57.555Z,1407287697.555 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2014-08-06T01:14:57.582Z,1407287697.582 [ElevatorServo](DEBUG): Initializing EZServoServo.
2014-08-06T01:14:57.584Z,1407287697.584 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2014-08-06T01:14:57.616Z,1407287697.616 [MassServo](DEBUG): Initializing EZServoServo.
2014-08-06T01:14:57.623Z,1407287697.623 [MassServo](DEBUG): Initializing MassServo.
2014-08-06T01:14:57.629Z,1407287697.629 [RudderServo](DEBUG): Initializing EZServoServo.
2014-08-06T01:14:57.635Z,1407287697.635 [RudderServo](DEBUG): Initializing RudderServo.
2014-08-06T01:14:57.641Z,1407287697.641 [ThrusterServo](DEBUG): Initializing EZServoServo.
2014-08-06T01:14:57.647Z,1407287697.647 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2014-08-06T01:14:58.020Z,1407287698.020 [AHRS_sp3003D](ERROR): readHeadingMagBin got 0x420DA4090B
2014-08-06T01:14:58.020Z,1407287698.020 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2014-08-06T01:14:58.020Z,1407287698.020 [AHRS_sp3003D] Hardware Fault, FailCount= 1
2014-08-06T01:14:58.020Z,1407287698.020 [AHRS_sp3003D](ERROR): Hardware Fault
2014-08-06T01:14:58.633Z,1407287698.633 [SBIT](IMPORTANT): Beginning Startup BIT
2014-08-06T01:14:58.636Z,1407287698.636 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2014-08-06T01:14:58.637Z,1407287698.637 [CBIT](IMPORTANT): Beginning GF scan
2014-08-06T01:14:58.733Z,1407287698.733 [AHRS_sp3003D](INFO): Powering down
2014-08-06T01:15:00.324Z,1407287700.324 [NAL9602](INFO): NAL9602 initialized
2014-08-06T01:15:00.416Z,1407287700.416 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D
2014-08-06T01:15:00.417Z,1407287700.417 [AHRS_sp3003D] No Fault, FailCount= 1
2014-08-06T01:15:00.677Z,1407287700.677 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2014-08-06T01:15:10.217Z,1407287710.217 [DAT](INFO): Powering down
2014-08-06T01:15:25.611Z,1407287725.611 [CBIT](IMPORTANT): No ground fault detected
2014-08-06T01:15:52.738Z,1407287752.738 [SBIT](IMPORTANT): SBIT PASSED
2014-08-06T01:15:53.188Z,1407287753.188 [MissionManager](IMPORTANT): Started mission Startup
2014-08-06T01:15:53.188Z,1407287753.188 [Startup] Running Loop=1
2014-08-06T01:15:53.188Z,1407287753.188 [Startup](INFO): Aggregate::initialize Startup
2014-08-06T01:15:53.188Z,1407287753.188 [Startup:A.GoToSurface] Running Loop=1
2014-08-06T01:15:53.188Z,1407287753.188 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-08-06T01:15:53.189Z,1407287753.189 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2014-08-06T01:15:53.190Z,1407287753.190 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2014-08-06T01:15:53.190Z,1407287753.190 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s.
2014-08-06T01:15:53.196Z,1407287753.196 [Startup:StartupSatComms] Running Loop=1
2014-08-06T01:15:53.196Z,1407287753.196 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2014-08-06T01:15:53.196Z,1407287753.196 [Startup:StartupSatComms:A] Running Loop=1
2014-08-06T01:15:53.658Z,1407287753.658 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2014-08-06T01:16:53.551Z,1407287813.551 [Startup:StartupSatComms:A](INFO): Timed out from 2014-08-06T01:15:53.2Z
2014-08-06T01:16:53.551Z,1407287813.551 [Startup:StartupSatComms:A] Stopped
2014-08-06T01:16:53.551Z,1407287813.551 [Startup:StartupSatComms:B] Running Loop=1
2014-08-06T01:16:54.041Z,1407287814.041 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2014-08-06T01:17:53.891Z,1407287873.891 [Startup:StartupSatComms:B](INFO): Timed out from 2014-08-06T01:16:53.6Z
2014-08-06T01:17:53.892Z,1407287873.892 [Startup:StartupSatComms:B] Stopped
2014-08-06T01:17:53.892Z,1407287873.892 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2014-08-06T01:17:53.892Z,1407287873.892 [Startup:StartupSatComms] Stopped
2014-08-06T01:17:53.892Z,1407287873.892 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2014-08-06T01:17:53.893Z,1407287873.893 [Startup](INFO): Completed Startup
2014-08-06T01:17:53.893Z,1407287873.893 [Startup] Stopped
2014-08-06T01:17:53.893Z,1407287873.893 [Startup](INFO): Aggregate::uninitialize Startup
2014-08-06T01:17:53.893Z,1407287873.893 [Startup:A.GoToSurface] Stopped
2014-08-06T01:17:53.893Z,1407287873.893 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-08-06T01:17:54.381Z,1407287874.381 [MissionManager](IMPORTANT): Started mission Default
2014-08-06T01:17:54.382Z,1407287874.382 [Default] Running Loop=1
2014-08-06T01:17:54.382Z,1407287874.382 [Default](INFO): Aggregate::initialize Default
2014-08-06T01:17:54.382Z,1407287874.382 [Default:A.GoToSurface] Running Loop=1
2014-08-06T01:17:54.382Z,1407287874.382 [Default:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-08-06T01:17:54.382Z,1407287874.382 [Default:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2014-08-06T01:17:54.383Z,1407287874.383 [Default:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2014-08-06T01:17:54.383Z,1407287874.383 [Default:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s.
2014-08-06T01:17:54.383Z,1407287874.383 [Default:CheckIn] Running Loop=1
2014-08-06T01:17:54.384Z,1407287874.384 [Default:CheckIn](INFO): Aggregate::initialize Default:CheckIn
2014-08-06T01:17:54.384Z,1407287874.384 [Default:CheckIn:A.SetSpeed] Running Loop=1
2014-08-06T01:17:54.384Z,1407287874.384 [Default:CheckIn:A.SetSpeed](DEBUG): Initialize.
2014-08-06T01:17:54.384Z,1407287874.384 [Default:CheckIn:Read_GPS] Running Loop=1
2014-08-06T01:17:54.385Z,1407287874.385 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2014-08-06T01:17:54.387Z,1407287874.387 [Default:CheckIn:A.SetSpeed] Running Loop=1
2014-08-06T01:17:54.429Z,1407287874.429 [Default:WaitAtTheSurface] Running Loop=1
2014-08-06T01:17:54.429Z,1407287874.429 [Default:WaitAtTheSurface](INFO): Aggregate::initialize Default:WaitAtTheSurface
2014-08-06T01:17:54.430Z,1407287874.430 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Running Loop=1
2014-08-06T01:17:54.430Z,1407287874.430 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Initialize.
2014-08-06T01:17:54.867Z,1407287874.867 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Running Loop=1
2014-08-06T01:18:02.720Z,1407287882.720 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-08-06T01:18:02.720Z,1407287882.720 [DVL_micro] Data Fault, FailCount= 1
2014-08-06T01:18:02.720Z,1407287882.720 [DVL_micro](ERROR): Data Fault
2014-08-06T01:18:02.753Z,1407287882.753 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-08-06T01:18:03.133Z,1407287883.133 [DVL_micro](INFO): uninitialize:Powering down
2014-08-06T01:18:03.579Z,1407287883.579 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-08-06T01:18:03.579Z,1407287883.579 [DVL_micro] Hardware Fault, FailCount= 1
2014-08-06T01:18:03.579Z,1407287883.579 [DVL_micro](ERROR): Hardware Fault
2014-08-06T01:18:03.996Z,1407287883.996 [DVL_micro](INFO): Initializing
2014-08-06T01:18:04.064Z,1407287884.064 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-08-06T01:18:04.064Z,1407287884.064 [DVL_micro] No Fault, FailCount= 1
2014-08-06T01:21:08.633Z,1407288068.633 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-08-06T01:21:08.633Z,1407288068.633 [DVL_micro] Data Fault, FailCount= 1
2014-08-06T01:21:08.633Z,1407288068.633 [DVL_micro](ERROR): Data Fault
2014-08-06T01:21:08.701Z,1407288068.701 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-08-06T01:21:09.045Z,1407288069.045 [DVL_micro](INFO): uninitialize:Powering down
2014-08-06T01:21:09.509Z,1407288069.509 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-08-06T01:21:09.509Z,1407288069.509 [DVL_micro] Hardware Fault, FailCount= 1
2014-08-06T01:21:09.509Z,1407288069.509 [DVL_micro](ERROR): Hardware Fault
2014-08-06T01:21:09.985Z,1407288069.985 [DVL_micro](INFO): Initializing
2014-08-06T01:21:10.063Z,1407288070.063 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-08-06T01:21:10.063Z,1407288070.063 [DVL_micro] No Fault, FailCount= 1
2014-08-06T01:22:09.603Z,1407288129.603 [CommandLine](IMPORTANT): got command restart application
2014-08-06T01:22:10.686Z,1407288130.686 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2014-08-06T01:22:10.686Z,1407288130.686 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-08-06T01:22:10.706Z,1407288130.706 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2014-08-06T01:22:10.706Z,1407288130.706 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-08-06T01:22:10.707Z,1407288130.707 [CommandLine](INFO): Join timeout helper Thread ID is 1501
2014-08-06T01:22:10.716Z,1407288130.716 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2014-08-06T01:22:10.716Z,1407288130.716 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-08-06T01:22:10.716Z,1407288130.716 [NavChartDb](INFO): Join timeout helper Thread ID is 1502
2014-08-06T01:22:10.903Z,1407288130.903 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2014-08-06T01:22:10.903Z,1407288130.903 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-08-06T01:22:10.915Z,1407288130.915 [ComponentRegistry](INFO): Shutting down Radio_Freewave ThreadHandler
2014-08-06T01:22:10.915Z,1407288130.915 [Radio_Freewave ThreadHandler](INFO): Thread cancelled.
2014-08-06T01:22:10.915Z,1407288130.915 [Radio_Freewave](INFO): Join timeout helper Thread ID is 1503
2014-08-06T01:22:11.276Z,1407288131.276 [Radio_Freewave ThreadHandler](INFO): Uninitializing protected caller thread.
2014-08-06T01:22:11.380Z,1407288131.380 [Radio_Freewave](INFO): Powering down
2014-08-06T01:22:11.784Z,1407288131.784 [Radio_Freewave ThreadHandler](INFO): Thread cancelled.
2014-08-06T01:22:11.804Z,1407288131.804 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2014-08-06T01:22:11.804Z,1407288131.804 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-08-06T01:22:11.805Z,1407288131.805 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1505
2014-08-06T01:22:11.961Z,1407288131.961 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2014-08-06T01:22:11.961Z,1407288131.961 [WetLabsBB2FL](INFO): Powering down
2014-08-06T01:22:11.962Z,1407288131.962 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-08-06T01:22:11.973Z,1407288131.973 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2014-08-06T01:22:11.973Z,1407288131.973 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-08-06T01:22:11.973Z,1407288131.973 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 1506
2014-08-06T01:22:12.089Z,1407288132.089 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2014-08-06T01:22:12.089Z,1407288132.089 [CTD_NeilBrown](INFO): Powering down
2014-08-06T01:22:12.090Z,1407288132.090 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-08-06T01:22:12.110Z,1407288132.110 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2014-08-06T01:22:12.110Z,1407288132.110 [logger ThreadHandler](INFO): Thread cancelled.
2014-08-06T01:22:12.110Z,1407288132.110 [logger](INFO): Join timeout helper Thread ID is 1507
2014-08-06T01:22:12.149Z,1407288132.149 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2014-08-06T01:22:12.149Z,1407288132.149 [logger ThreadHandler](INFO): Thread cancelled.
2014-08-06T01:22:12.170Z,1407288132.170 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2014-08-06T01:22:12.170Z,1407288132.170 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-08-06T01:22:12.170Z,1407288132.170 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2014-08-06T01:22:12.170Z,1407288132.170 [controlThread ThreadHandler](INFO): Thread cancelled.
2014-08-06T01:22:12.171Z,1407288132.171 [controlThread](INFO): Join timeout helper Thread ID is 1508
2014-08-06T01:22:12.428Z,1407288132.428 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2014-08-06T01:22:12.428Z,1407288132.428 [controlThread](DEBUG): Uninitializing ControlThread
2014-08-06T01:22:12.429Z,1407288132.429 [AHRS_sp3003D](INFO): Powering down
2014-08-06T01:22:12.430Z,1407288132.430 [DVL_micro](INFO): uninitialize:Powering down
2014-08-06T01:22:12.431Z,1407288132.431 [NAL9602](INFO): Powering down
2014-08-06T01:22:12.432Z,1407288132.432 [DAT](INFO): Powering down
2014-08-06T01:22:12.434Z,1407288132.434 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2014-08-06T01:22:12.436Z,1407288132.436 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2014-08-06T01:22:12.437Z,1407288132.437 [Default] Stopped
2014-08-06T01:22:12.437Z,1407288132.437 [Default](INFO): Aggregate::uninitialize Default
2014-08-06T01:22:12.437Z,1407288132.437 [Default:A.GoToSurface] Stopped
2014-08-06T01:22:12.437Z,1407288132.437 [Default:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-08-06T01:22:12.437Z,1407288132.437 [Default:CheckIn] Stopped
2014-08-06T01:22:12.438Z,1407288132.438 [Default:CheckIn](INFO): Aggregate::uninitialize Default:CheckIn
2014-08-06T01:22:12.438Z,1407288132.438 [Default:CheckIn:A.SetSpeed] Stopped
2014-08-06T01:22:12.438Z,1407288132.438 [Default:CheckIn:A.SetSpeed](DEBUG): Uninitialize.
2014-08-06T01:22:12.438Z,1407288132.438 [Default:CheckIn:Read_GPS] Stopped
2014-08-06T01:22:12.438Z,1407288132.438 [Default:WaitAtTheSurface] Stopped
2014-08-06T01:22:12.438Z,1407288132.438 [Default:WaitAtTheSurface](INFO): Aggregate::uninitialize Default:WaitAtTheSurface
2014-08-06T01:22:12.438Z,1407288132.438 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Stopped
2014-08-06T01:22:12.438Z,1407288132.438 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Uninitialize.
2014-08-06T01:22:12.441Z,1407288132.441 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2014-08-06T01:22:12.441Z,1407288132.441 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2014-08-06T01:22:12.442Z,1407288132.442 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2014-08-06T01:22:12.442Z,1407288132.442 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2014-08-06T01:22:12.442Z,1407288132.442 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2014-08-06T01:22:12.443Z,1407288132.443 [BuoyancyServo](INFO): Powering down
2014-08-06T01:22:12.457Z,1407288132.457 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2014-08-06T01:22:12.457Z,1407288132.457 [ElevatorServo](INFO): Powering down
2014-08-06T01:22:12.458Z,1407288132.458 [MassServo](DEBUG): Uninitialize Mass Servo.
2014-08-06T01:22:12.458Z,1407288132.458 [MassServo](INFO): Powering down
2014-08-06T01:22:12.459Z,1407288132.459 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2014-08-06T01:22:12.459Z,1407288132.459 [RudderServo](INFO): Powering down
2014-08-06T01:22:12.460Z,1407288132.460 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2014-08-06T01:22:12.460Z,1407288132.460 [ThrusterServo](INFO): Powering down
2014-08-06T01:22:12.461Z,1407288132.461 [SBIT](DEBUG): Uninitialize SBIT Component.
2014-08-06T01:22:12.461Z,1407288132.461 [IBIT](DEBUG): Uninitialize IBIT Component.
2014-08-06T01:22:12.462Z,1407288132.462 [CBIT](DEBUG): Uninitialize CBIT Component.
2014-08-06T01:22:12.505Z,1407288132.505 [controlThread ThreadHandler](INFO): Thread cancelled.
2014-08-06T01:22:12.591Z,1407288132.591 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-08-06T01:22:12.594Z,1407288132.594 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-08-06T01:22:12.606Z,1407288132.606 [Radio_Freewave ThreadHandler](INFO): Thread cancelled.
2014-08-06T01:22:12.666Z,1407288132.666 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-08-06T01:22:12.702Z,1407288132.702 [logger ThreadHandler](INFO): Thread cancelled.