2014-05-22T15:44:28.531Z,1400773468.531 [Supervisor](DEBUG): Initializing supervisor.
2014-05-22T15:44:28.533Z,1400773468.533 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0
2014-05-22T15:44:28.534Z,1400773468.534 [SyncHandler](INFO): Protected caller Thread ID is 980
2014-05-22T15:44:28.534Z,1400773468.534 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2014-05-22T15:44:28.535Z,1400773468.535 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0
2014-05-22T15:44:28.536Z,1400773468.536 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 981
2014-05-22T15:44:28.539Z,1400773468.539 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2014-05-22T15:44:28.550Z,1400773468.550 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2014-05-22T15:44:28.552Z,1400773468.552 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0
2014-05-22T15:44:28.552Z,1400773468.552 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 982
2014-05-22T15:44:28.553Z,1400773468.553 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2014-05-22T15:44:28.554Z,1400773468.554 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0
2014-05-22T15:44:28.554Z,1400773468.554 [logger ThreadHandler](INFO): Protected caller Thread ID is 983
2014-05-22T15:44:28.556Z,1400773468.556 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2014-05-22T15:44:28.557Z,1400773468.557 [Supervisor](INFO): Looking for Config files in directory: Config/
2014-05-22T15:44:28.558Z,1400773468.558 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2014-05-22T15:44:28.927Z,1400773468.927 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2014-05-22T15:44:28.928Z,1400773468.928 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2014-05-22T15:44:29.219Z,1400773469.219 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2014-05-22T15:44:29.219Z,1400773469.219 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2014-05-22T15:44:29.307Z,1400773469.307 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2014-05-22T15:44:29.307Z,1400773469.307 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2014-05-22T15:44:29.497Z,1400773469.497 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2014-05-22T15:44:29.498Z,1400773469.498 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2014-05-22T15:44:29.666Z,1400773469.666 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2014-05-22T15:44:29.666Z,1400773469.666 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2014-05-22T15:44:29.980Z,1400773469.980 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2014-05-22T15:44:29.980Z,1400773469.980 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2014-05-22T15:44:30.167Z,1400773470.167 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2014-05-22T15:44:30.168Z,1400773470.168 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2014-05-22T15:44:30.518Z,1400773470.518 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2014-05-22T15:44:30.519Z,1400773470.519 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2014-05-22T15:44:30.630Z,1400773470.630 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2014-05-22T15:44:30.631Z,1400773470.631 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2014-05-22T15:44:31.157Z,1400773471.157 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2014-05-22T15:44:31.157Z,1400773471.157 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2014-05-22T15:44:31.292Z,1400773471.292 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2014-05-22T15:44:31.293Z,1400773471.293 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2014-05-22T15:44:31.388Z,1400773471.388 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2014-05-22T15:44:31.502Z,1400773471.502 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2014-05-22T15:44:31.503Z,1400773471.503 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2014-05-22T15:44:31.608Z,1400773471.608 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2014-05-22T15:44:31.609Z,1400773471.609 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2014-05-22T15:44:31.750Z,1400773471.750 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2014-05-22T15:44:31.752Z,1400773471.752 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2014-05-22T15:44:31.753Z,1400773471.753 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2014-05-22T15:44:31.864Z,1400773471.864 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2014-05-22T15:44:32.000Z,1400773472.000 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2014-05-22T15:44:32.100Z,1400773472.100 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2014-05-22T15:44:32.195Z,1400773472.195 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2014-05-22T15:44:32.347Z,1400773472.347 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2014-05-22T15:44:32.470Z,1400773472.470 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2014-05-22T15:44:32.558Z,1400773472.558 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2014-05-22T15:44:32.666Z,1400773472.666 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2014-05-22T15:44:32.770Z,1400773472.770 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2014-05-22T15:44:32.870Z,1400773472.870 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2014-05-22T15:44:32.960Z,1400773472.960 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Estimation.cfg
2014-05-22T15:44:33.064Z,1400773473.064 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/
2014-05-22T15:44:33.064Z,1400773473.064 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2014-05-22T15:44:33.066Z,1400773473.066 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2014-05-22T15:44:33.424Z,1400773473.424 [AHRS_sp3003D] Loaded
2014-05-22T15:44:33.424Z,1400773473.424 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2014-05-22T15:44:33.734Z,1400773473.734 [Batt_Ocean_Server] Loaded
2014-05-22T15:44:33.734Z,1400773473.734 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2014-05-22T15:44:33.748Z,1400773473.748 [Depth_Keller] Loaded
2014-05-22T15:44:33.748Z,1400773473.748 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2014-05-22T15:44:33.753Z,1400773473.753 [DropWeight] Loaded
2014-05-22T15:44:33.754Z,1400773473.754 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2014-05-22T15:44:33.902Z,1400773473.902 [DVL_micro] Loaded
2014-05-22T15:44:33.903Z,1400773473.903 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2014-05-22T15:44:34.008Z,1400773474.008 [NAL9602] Loaded
2014-05-22T15:44:34.008Z,1400773474.008 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2014-05-22T15:44:34.063Z,1400773474.063 [Onboard] Loaded
2014-05-22T15:44:34.064Z,1400773474.064 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2014-05-22T15:44:34.071Z,1400773474.071 [Radio_Freewave] Loaded
2014-05-22T15:44:34.071Z,1400773474.071 [ComponentRegistry](DEBUG): Component "Radio_Freewave" handled in its own thread.
2014-05-22T15:44:34.073Z,1400773474.073 [Radio_Freewave ThreadHandler](DEBUG): Created PCaller Thread at 4060F4E0
2014-05-22T15:44:34.073Z,1400773474.073 [Radio_Freewave ThreadHandler](INFO): Protected caller Thread ID is 1065
2014-05-22T15:44:34.080Z,1400773474.080 [SCPI] Loaded
2014-05-22T15:44:34.080Z,1400773474.080 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread.
2014-05-22T15:44:34.081Z,1400773474.081 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2014-05-22T15:44:34.082Z,1400773474.082 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2014-05-22T15:44:34.252Z,1400773474.252 [InternalSim] Loaded
2014-05-22T15:44:34.253Z,1400773474.253 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2014-05-22T15:44:34.253Z,1400773474.253 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2014-05-22T15:44:34.254Z,1400773474.254 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2014-05-22T15:44:34.515Z,1400773474.515 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2014-05-22T15:44:34.515Z,1400773474.515 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2014-05-22T15:44:34.521Z,1400773474.521 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2014-05-22T15:44:34.522Z,1400773474.522 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2014-05-22T15:44:34.606Z,1400773474.606 [DeadReckonUsingMultipleVelocitySources] Loaded
2014-05-22T15:44:34.606Z,1400773474.606 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2014-05-22T15:44:34.654Z,1400773474.654 [DeadReckonWithRespectToWater] Loaded
2014-05-22T15:44:34.654Z,1400773474.654 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToWater" handled in the control thread.
2014-05-22T15:44:34.703Z,1400773474.703 [DeadReckonWithRespectToSeafloor] Loaded
2014-05-22T15:44:34.703Z,1400773474.703 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToSeafloor" handled in the control thread.
2014-05-22T15:44:34.753Z,1400773474.753 [DeadReckonUsingDVLWaterTrack] Loaded
2014-05-22T15:44:34.753Z,1400773474.753 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingDVLWaterTrack" handled in the control thread.
2014-05-22T15:44:34.803Z,1400773474.803 [DeadReckonUsingCompactModelForecast] Loaded
2014-05-22T15:44:34.804Z,1400773474.804 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingCompactModelForecast" handled in the control thread.
2014-05-22T15:44:34.820Z,1400773474.820 [NavChart] Loaded
2014-05-22T15:44:34.821Z,1400773474.821 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2014-05-22T15:44:34.825Z,1400773474.825 [UniversalFixResidualReporter] Loaded
2014-05-22T15:44:34.825Z,1400773474.825 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2014-05-22T15:44:34.826Z,1400773474.826 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2014-05-22T15:44:34.826Z,1400773474.826 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2014-05-22T15:44:34.878Z,1400773474.878 [VerticalControl](DEBUG): Construct VerticalControl.
2014-05-22T15:44:34.995Z,1400773474.995 [VerticalControl] Loaded
2014-05-22T15:44:34.996Z,1400773474.996 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2014-05-22T15:44:34.996Z,1400773474.996 [HorizontalControl](DEBUG): Construct HorizontalControl.
2014-05-22T15:44:35.068Z,1400773475.068 [HorizontalControl] Loaded
2014-05-22T15:44:35.068Z,1400773475.068 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2014-05-22T15:44:35.069Z,1400773475.069 [SpeedControl](DEBUG): Construct SpeedControl.
2014-05-22T15:44:35.071Z,1400773475.071 [SpeedControl] Loaded
2014-05-22T15:44:35.071Z,1400773475.071 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2014-05-22T15:44:35.072Z,1400773475.072 [LoopControl](DEBUG): Construct LoopControl.
2014-05-22T15:44:35.073Z,1400773475.073 [LoopControl] Loaded
2014-05-22T15:44:35.073Z,1400773475.073 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2014-05-22T15:44:35.073Z,1400773475.073 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2014-05-22T15:44:35.074Z,1400773475.074 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2014-05-22T15:44:35.093Z,1400773475.093 [DepthRateCalculator] Loaded
2014-05-22T15:44:35.094Z,1400773475.094 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2014-05-22T15:44:35.099Z,1400773475.099 [PitchRateCalculator] Loaded
2014-05-22T15:44:35.100Z,1400773475.100 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2014-05-22T15:44:35.107Z,1400773475.107 [SpeedCalculator] Loaded
2014-05-22T15:44:35.107Z,1400773475.107 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2014-05-22T15:44:35.125Z,1400773475.125 [TempGradientCalculator] Loaded
2014-05-22T15:44:35.125Z,1400773475.125 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2014-05-22T15:44:35.131Z,1400773475.131 [YawRateCalculator] Loaded
2014-05-22T15:44:35.131Z,1400773475.131 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2014-05-22T15:44:35.131Z,1400773475.131 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2014-05-22T15:44:35.132Z,1400773475.132 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2014-05-22T15:44:35.245Z,1400773475.245 [CTD_NeilBrown] Loaded
2014-05-22T15:44:35.245Z,1400773475.245 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2014-05-22T15:44:35.246Z,1400773475.246 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4075E4E0
2014-05-22T15:44:35.246Z,1400773475.246 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 1066
2014-05-22T15:44:35.260Z,1400773475.260 [ISUS] Loaded
2014-05-22T15:44:35.261Z,1400773475.261 [ComponentRegistry](DEBUG): SyncComponent "ISUS" handled in the control thread.
2014-05-22T15:44:35.276Z,1400773475.276 [PAR_Licor] Loaded
2014-05-22T15:44:35.277Z,1400773475.277 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2014-05-22T15:44:35.313Z,1400773475.313 [WetLabsBB2FL] Loaded
2014-05-22T15:44:35.314Z,1400773475.314 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2014-05-22T15:44:35.315Z,1400773475.315 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4078E4E0
2014-05-22T15:44:35.315Z,1400773475.315 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1067
2014-05-22T15:44:35.316Z,1400773475.316 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2014-05-22T15:44:35.316Z,1400773475.316 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2014-05-22T15:44:35.416Z,1400773475.416 [SBIT](DEBUG): Construct Startup Built In Test.
2014-05-22T15:44:35.428Z,1400773475.428 [SBIT] Loaded
2014-05-22T15:44:35.429Z,1400773475.429 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2014-05-22T15:44:35.429Z,1400773475.429 [IBIT](DEBUG): Construct Initiated Built In Test.
2014-05-22T15:44:35.443Z,1400773475.443 [IBIT] Loaded
2014-05-22T15:44:35.443Z,1400773475.443 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2014-05-22T15:44:35.445Z,1400773475.445 [CBIT](DEBUG): Construct CBIT Built In Test.
2014-05-22T15:44:35.517Z,1400773475.517 [CBIT] Loaded
2014-05-22T15:44:35.517Z,1400773475.517 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2014-05-22T15:44:35.518Z,1400773475.518 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2014-05-22T15:44:35.518Z,1400773475.518 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2014-05-22T15:44:40.358Z,1400773480.358 [HFRadarModelCalc] Loaded
2014-05-22T15:44:40.358Z,1400773480.358 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2014-05-22T15:44:44.173Z,1400773484.173 [HFRadarCompactModelForecaster] Loaded
2014-05-22T15:44:44.173Z,1400773484.173 [ComponentRegistry](DEBUG): SyncComponent "HFRadarCompactModelForecaster" handled in the control thread.
2014-05-22T15:44:45.219Z,1400773485.219 [HFRCMSpaceInterpolator] Loaded
2014-05-22T15:44:45.220Z,1400773485.220 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSpaceInterpolator" handled in the control thread.
2014-05-22T15:44:45.222Z,1400773485.222 [HFRCMTimeInterpolator] Loaded
2014-05-22T15:44:45.222Z,1400773485.222 [ComponentRegistry](DEBUG): SyncComponent "HFRCMTimeInterpolator" handled in the control thread.
2014-05-22T15:44:45.235Z,1400773485.235 [HFRCMSurfaceCurrentAtVehicleLocation] Loaded
2014-05-22T15:44:45.236Z,1400773485.236 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSurfaceCurrentAtVehicleLocation" handled in the control thread.
2014-05-22T15:44:45.265Z,1400773485.265 [HFRCMVirtualSurfaceDrifter] Loaded
2014-05-22T15:44:45.266Z,1400773485.266 [ComponentRegistry](DEBUG): SyncComponent "HFRCMVirtualSurfaceDrifter" handled in the control thread.
2014-05-22T15:44:45.266Z,1400773485.266 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2014-05-22T15:44:45.267Z,1400773485.267 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2014-05-22T15:44:45.373Z,1400773485.373 [BuoyancyServo] Loaded
2014-05-22T15:44:45.374Z,1400773485.374 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2014-05-22T15:44:45.386Z,1400773485.386 [ElevatorServo] Loaded
2014-05-22T15:44:45.387Z,1400773485.387 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2014-05-22T15:44:45.399Z,1400773485.399 [MassServo] Loaded
2014-05-22T15:44:45.399Z,1400773485.399 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2014-05-22T15:44:45.412Z,1400773485.412 [RudderServo] Loaded
2014-05-22T15:44:45.412Z,1400773485.412 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2014-05-22T15:44:45.424Z,1400773485.424 [ThrusterServo] Loaded
2014-05-22T15:44:45.424Z,1400773485.424 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2014-05-22T15:44:45.425Z,1400773485.425 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2014-05-22T15:44:45.425Z,1400773485.425 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2014-05-22T15:44:45.451Z,1400773485.451 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2014-05-22T15:44:45.453Z,1400773485.453 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2014-05-22T15:44:45.454Z,1400773485.454 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2014-05-22T15:44:45.460Z,1400773485.460 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2014-05-22T15:44:45.461Z,1400773485.461 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A4F4E0
2014-05-22T15:44:45.462Z,1400773485.462 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1068
2014-05-22T15:44:45.467Z,1400773485.467 [Supervisor](INFO): Main Thread ID is 766
2014-05-22T15:44:45.467Z,1400773485.467 [Supervisor](DEBUG): Running supervisor.
2014-05-22T15:44:45.467Z,1400773485.467 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1069
2014-05-22T15:44:45.472Z,1400773485.472 [controlThread ThreadHandler](INFO): Handler Thread ID is 1070
2014-05-22T15:44:45.472Z,1400773485.472 [controlThread](DEBUG): Initializing ControlThread
2014-05-22T15:44:45.475Z,1400773485.475 [logger ThreadHandler](INFO): Handler Thread ID is 1071
2014-05-22T15:44:45.494Z,1400773485.494 [Radio_Freewave ThreadHandler](INFO): Handler Thread ID is 1072
2014-05-22T15:44:45.510Z,1400773485.510 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 1073
2014-05-22T15:44:45.511Z,1400773485.511 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2014-05-22T15:44:45.514Z,1400773485.514 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2014-05-22T15:44:45.523Z,1400773485.523 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1075
2014-05-22T15:44:45.524Z,1400773485.524 [WetLabsBB2FL](INFO): Powering down
2014-05-22T15:44:45.553Z,1400773485.553 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1076
2014-05-22T15:44:45.556Z,1400773485.556 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2014-05-22T15:44:45.556Z,1400773485.556 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2014-05-22T15:44:45.557Z,1400773485.557 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2014-05-22T15:44:45.557Z,1400773485.557 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2014-05-22T15:44:45.557Z,1400773485.557 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2014-05-22T15:44:45.558Z,1400773485.558 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2014-05-22T15:44:45.558Z,1400773485.558 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2014-05-22T15:44:45.558Z,1400773485.558 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2014-05-22T15:44:45.559Z,1400773485.559 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2014-05-22T15:44:47.075Z,1400773487.075 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2014-05-22T15:44:47.111Z,1400773487.111 [InternalSim](DEBUG):  InternalSim initializing...
2014-05-22T15:44:47.244Z,1400773487.244 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2014-05-22T15:44:47.244Z,1400773487.244 [DeadReckonWithRespectToWater](DEBUG): Initializing DeadReckonWithRespectToWater component.
2014-05-22T15:44:47.245Z,1400773487.245 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component.
2014-05-22T15:44:47.245Z,1400773487.245 [DeadReckonUsingDVLWaterTrack](DEBUG): Initializing DeadReckonUsingDVLWaterTrack component.
2014-05-22T15:44:47.245Z,1400773487.245 [DeadReckonUsingCompactModelForecast](DEBUG): Initializing DeadReckonUsingCompactModelForecast component.
2014-05-22T15:44:47.246Z,1400773487.246 [NavChart](DEBUG): Initialize NavChart Navigation.
2014-05-22T15:44:47.246Z,1400773487.246 [UniversalFixResidualReporter](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2014-05-22T15:44:47.246Z,1400773487.246 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2014-05-22T15:44:47.253Z,1400773487.253 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2014-05-22T15:44:47.253Z,1400773487.253 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2014-05-22T15:44:47.254Z,1400773487.254 [LoopControl](DEBUG): Initialize LoopControlComponent.
2014-05-22T15:44:47.254Z,1400773487.254 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2014-05-22T15:44:47.255Z,1400773487.255 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2014-05-22T15:44:47.255Z,1400773487.255 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2014-05-22T15:44:47.255Z,1400773487.255 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2014-05-22T15:44:47.256Z,1400773487.256 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2014-05-22T15:44:47.284Z,1400773487.284 [SBIT](INFO): Initialize SBIT Component.
2014-05-22T15:44:47.285Z,1400773487.285 [SBIT](IMPORTANT): Tethys CM Info: 
 $Rev:11330
2014-05-22T15:44:47.285Z,1400773487.285 [SBIT](IMPORTANT): Kernel Release:2.6.27.8
2014-05-22T15:44:47.286Z,1400773487.286 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2014-05-22T15:44:47.286Z,1400773487.286 [IBIT](INFO): Initialize IBIT Component.
2014-05-22T15:44:47.287Z,1400773487.287 [CBIT](DEBUG): Initialize CBIT Component.
2014-05-22T15:44:47.287Z,1400773487.287 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2014-05-22T15:44:47.320Z,1400773487.320 [HFRadarCompactModelForecaster](DEBUG): Found new ECs!
2014-05-22T15:44:47.784Z,1400773487.784 [Radio_Freewave](INFO): Powering up
2014-05-22T15:44:48.596Z,1400773488.596 [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-05-22T15:44:56.405Z,1400773496.405 [HFRadarCompactModelForecaster](IMPORTANT): Forecast time 201405221100: published 50 modes in rows, 61 hours in columns, 3050 elements.
2014-05-22T15:44:56.424Z,1400773496.424 [HFRCMSpaceInterpolator](DEBUG): Initializing HFRCMSpaceInterpolator component.
2014-05-22T15:44:56.426Z,1400773496.426 [HFRCMTimeInterpolator](DEBUG): Initializing HFRCMTimeInterpolator component.
2014-05-22T15:44:56.426Z,1400773496.426 [HFRCMSurfaceCurrentAtVehicleLocation](DEBUG): Initializing HFRCMSurfaceCurrentAtVehicleLocation component.
2014-05-22T15:44:56.427Z,1400773496.427 [HFRCMVirtualSurfaceDrifter](DEBUG): Initializing HFRCMVirtualSurfaceDrifter component.
2014-05-22T15:44:56.429Z,1400773496.429 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2014-05-22T15:44:56.455Z,1400773496.455 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2014-05-22T15:44:56.484Z,1400773496.484 [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-05-22T15:44:56.485Z,1400773496.485 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2014-05-22T15:44:56.569Z,1400773496.569 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2014-05-22T15:44:56.579Z,1400773496.579 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2014-05-22T15:44:56.592Z,1400773496.592 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-05-22T15:44:56.617Z,1400773496.617 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2014-05-22T15:44:56.628Z,1400773496.628 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-05-22T15:44:56.655Z,1400773496.655 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2014-05-22T15:44:56.682Z,1400773496.682 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Construct.
2014-05-22T15:44:56.689Z,1400773496.689 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-05-22T15:44:56.710Z,1400773496.710 [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="NeedGPS"><True/></DefineArg>

    <Aggregate Id="GPS">

        <When>
            <Arg Name="NeedGPS"/>
        </When>

<!-- Run at high speed -->

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

<!-- Get to the surface -->

        <Guidance:GoToSurface>
            <Sequence/>
        </Guidance:GoToSurface>

<!-- Get GPS fix -->

        <ReadDatum Id="Read_GPS">
            <Universal:latitude_fix/>
        </ReadDatum>

        <Assign><Sequence/><Arg Name="NeedGPS"/><False/></Assign>

    </Aggregate>

    <Aggregate Id="Iridium">

        <Sequence/>

<!-- Run at high speed -->

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

<!-- Get to the surface -->

        <Guidance:GoToSurface>
            <Sequence/>
        </Guidance:GoToSurface>

<!-- 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="CallIridium">

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

        <Assign><Sequence/><Arg Name="NeedGPS"/><True/></Assign>

        <Call RefId="Iridium"/>

    </Aggregate>

    <Aggregate Id="WaitAtTheSurface">

        <Sequence/>

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

        <Guidance:GoToSurface>
            <Parallel/>
        </Guidance:GoToSurface>

    </Aggregate>

</Mission>


2014-05-22T15:44:56.718Z,1400773496.718 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,SCPI,ISUS,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,HFRadarModelCalc,HFRadarCompactModelForecaster,HFRCMSpaceInterpolator,HFRCMTimeInterpolator,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-05-22T15:44:56.795Z,1400773496.795 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2014-05-22T15:44:57.509Z,1400773497.509 [DVL_micro](INFO): Initializing
2014-05-22T15:44:57.535Z,1400773497.535 [NAL9602](INFO): Powering up NAL9602
2014-05-22T15:44:58.265Z,1400773498.265 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2014-05-22T15:44:58.274Z,1400773498.274 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2014-05-22T15:44:58.306Z,1400773498.306 [ElevatorServo](DEBUG): Initializing EZServoServo.
2014-05-22T15:44:58.322Z,1400773498.322 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2014-05-22T15:44:58.344Z,1400773498.344 [MassServo](DEBUG): Initializing EZServoServo.
2014-05-22T15:44:58.350Z,1400773498.350 [MassServo](DEBUG): Initializing MassServo.
2014-05-22T15:44:58.372Z,1400773498.372 [RudderServo](DEBUG): Initializing EZServoServo.
2014-05-22T15:44:58.390Z,1400773498.390 [RudderServo](DEBUG): Initializing RudderServo.
2014-05-22T15:44:58.411Z,1400773498.411 [ThrusterServo](DEBUG): Initializing EZServoServo.
2014-05-22T15:44:58.418Z,1400773498.418 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2014-05-22T15:44:58.978Z,1400773498.978 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2014-05-22T15:44:58.979Z,1400773498.979 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2014-05-22T15:44:58.979Z,1400773498.979 [AHRS_sp3003D] Hardware Fault, FailCount= 1
2014-05-22T15:44:58.979Z,1400773498.979 [AHRS_sp3003D](ERROR): Hardware Fault
2014-05-22T15:44:59.450Z,1400773499.450 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2014-05-22T15:44:59.482Z,1400773499.482 [AHRS_sp3003D](INFO): Powering down
2014-05-22T15:45:00.924Z,1400773500.924 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D
2014-05-22T15:45:00.924Z,1400773500.924 [AHRS_sp3003D] No Fault, FailCount= 1
2014-05-22T15:45:01.075Z,1400773501.075 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2014-05-22T15:45:02.207Z,1400773502.207 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2014-05-22T15:45:02.207Z,1400773502.207 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2014-05-22T15:45:02.208Z,1400773502.208 [AHRS_sp3003D] Hardware Fault, FailCount= 2
2014-05-22T15:45:02.208Z,1400773502.208 [AHRS_sp3003D](ERROR): Hardware Fault
2014-05-22T15:45:02.887Z,1400773502.887 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2014-05-22T15:45:02.936Z,1400773502.936 [AHRS_sp3003D](INFO): Powering down
2014-05-22T15:45:03.370Z,1400773503.370 [SBIT](IMPORTANT): Beginning Startup BIT
2014-05-22T15:45:03.373Z,1400773503.373 [CBIT](IMPORTANT): Beginning GF scan
2014-05-22T15:45:04.330Z,1400773504.330 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D
2014-05-22T15:45:04.330Z,1400773504.330 [AHRS_sp3003D] No Fault, FailCount= 2
2014-05-22T15:45:04.595Z,1400773504.595 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2014-05-22T15:45:05.909Z,1400773505.909 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2014-05-22T15:45:05.909Z,1400773505.909 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2014-05-22T15:45:05.909Z,1400773505.909 [AHRS_sp3003D] Hardware Fault, FailCount= 3
2014-05-22T15:45:05.909Z,1400773505.909 [AHRS_sp3003D](ERROR): Hardware Fault
2014-05-22T15:45:06.194Z,1400773506.194 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2014-05-22T15:45:06.236Z,1400773506.236 [AHRS_sp3003D](INFO): Powering down
2014-05-22T15:45:07.671Z,1400773507.671 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D
2014-05-22T15:45:07.672Z,1400773507.672 [AHRS_sp3003D] No Fault, FailCount= 3
2014-05-22T15:45:07.808Z,1400773507.808 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2014-05-22T15:45:08.258Z,1400773508.258 [NAL9602](INFO): NAL9602 initialized
2014-05-22T15:45:08.946Z,1400773508.946 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2014-05-22T15:45:08.946Z,1400773508.946 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2014-05-22T15:45:08.946Z,1400773508.946 [AHRS_sp3003D] Hardware Fault, FailCount= 4
2014-05-22T15:45:08.946Z,1400773508.946 [AHRS_sp3003D](ERROR): Hardware Fault
2014-05-22T15:45:09.254Z,1400773509.254 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2014-05-22T15:45:09.288Z,1400773509.288 [AHRS_sp3003D](INFO): Powering down
2014-05-22T15:45:10.588Z,1400773510.588 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D
2014-05-22T15:45:10.588Z,1400773510.588 [AHRS_sp3003D] No Fault, FailCount= 4
2014-05-22T15:45:10.871Z,1400773510.871 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2014-05-22T15:45:11.810Z,1400773511.810 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2014-05-22T15:45:11.810Z,1400773511.810 [AHRS_sp3003D](ERROR): readHeadingMagBin got 0xA409A0
2014-05-22T15:45:11.811Z,1400773511.811 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2014-05-22T15:45:11.811Z,1400773511.811 [AHRS_sp3003D] Hardware Fault, FailCount= 5
2014-05-22T15:45:11.811Z,1400773511.811 [AHRS_sp3003D](ERROR): Hardware Fault
2014-05-22T15:45:11.955Z,1400773511.955 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2014-05-22T15:45:11.955Z,1400773511.955 [CBIT](CRITICAL): Hardware Fault in component: AHRS_sp3003D
2014-05-22T15:45:12.073Z,1400773512.073 [AHRS_sp3003D](INFO): Powering down
2014-05-22T15:45:12.300Z,1400773512.300 [CommandLine](FAULT): Scheduling is paused
2014-05-22T15:45:29.711Z,1400773529.711 [CBIT](IMPORTANT): No ground fault detected
2014-05-22T15:45:57.436Z,1400773557.436 [SBIT](IMPORTANT): SBIT PASSED
2014-05-22T15:45:57.754Z,1400773557.754 [MissionManager](IMPORTANT): Started mission Startup
2014-05-22T15:45:57.754Z,1400773557.754 [Startup] Running Loop=1
2014-05-22T15:45:57.754Z,1400773557.754 [Startup](INFO): Aggregate::initialize Startup
2014-05-22T15:45:57.755Z,1400773557.755 [Startup:A.GoToSurface] Running Loop=1
2014-05-22T15:45:57.755Z,1400773557.755 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-22T15:45:57.761Z,1400773557.761 [Startup:StartupSatComms] Running Loop=1
2014-05-22T15:45:57.761Z,1400773557.761 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2014-05-22T15:45:57.761Z,1400773557.761 [Startup:StartupSatComms:A] Running Loop=1
2014-05-22T15:45:58.159Z,1400773558.159 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2014-05-22T15:46:54.118Z,1400773614.118 [CommandLine](IMPORTANT): got command failComponent
2014-05-22T15:46:54.118Z,1400773614.118 [CommandLine](IMPORTANT): Failed components:
2014-05-22T15:46:54.118Z,1400773614.118 [CommandLine](IMPORTANT): AHRS_sp3003D: Hardware Fault
2014-05-22T15:46:58.200Z,1400773618.200 [Startup:StartupSatComms:A](INFO): Timed out from 2014-05-22T15:45:57.8Z
2014-05-22T15:46:58.200Z,1400773618.200 [Startup:StartupSatComms:A] Stopped
2014-05-22T15:46:58.200Z,1400773618.200 [Startup:StartupSatComms:B] Running Loop=1
2014-05-22T15:46:58.552Z,1400773618.552 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2014-05-22T15:47:58.548Z,1400773678.548 [Startup:StartupSatComms:B](INFO): Timed out from 2014-05-22T15:46:58.2Z
2014-05-22T15:47:58.548Z,1400773678.548 [Startup:StartupSatComms:B] Stopped
2014-05-22T15:47:58.548Z,1400773678.548 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2014-05-22T15:47:58.548Z,1400773678.548 [Startup:StartupSatComms] Stopped
2014-05-22T15:47:58.548Z,1400773678.548 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2014-05-22T15:47:58.549Z,1400773678.549 [Startup](INFO): Completed Startup
2014-05-22T15:47:58.549Z,1400773678.549 [Startup] Stopped
2014-05-22T15:47:58.549Z,1400773678.549 [Startup](INFO): Aggregate::uninitialize Startup
2014-05-22T15:47:58.549Z,1400773678.549 [Startup:A.GoToSurface] Stopped
2014-05-22T15:47:58.550Z,1400773678.550 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-22T15:47:59.013Z,1400773679.013 [MissionManager](IMPORTANT): Started mission Default
2014-05-22T15:47:59.013Z,1400773679.013 [Default] Running Loop=1
2014-05-22T15:47:59.013Z,1400773679.013 [Default](INFO): Aggregate::initialize Default
2014-05-22T15:47:59.013Z,1400773679.013 [Default:Iridium] Running Loop=1
2014-05-22T15:47:59.013Z,1400773679.013 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-22T15:47:59.013Z,1400773679.013 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-22T15:47:59.013Z,1400773679.013 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-22T15:47:59.014Z,1400773679.014 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-22T15:47:59.014Z,1400773679.014 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-22T15:47:59.014Z,1400773679.014 [Default:CallIridium] Running Loop=1
2014-05-22T15:47:59.014Z,1400773679.014 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-05-22T15:47:59.014Z,1400773679.014 [Default:CallIridium:A] Running Loop=1
2014-05-22T15:47:59.016Z,1400773679.016 [Default:CallIridium:A] Stopped
2014-05-22T15:47:59.017Z,1400773679.017 [Default:CallIridium:B] Running Loop=1
2014-05-22T15:47:59.017Z,1400773679.017 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-05-22T15:47:59.034Z,1400773679.034 [Default:Iridium:B.GoToSurface] Stopped
2014-05-22T15:47:59.034Z,1400773679.034 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-22T15:47:59.034Z,1400773679.034 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-22T15:47:59.035Z,1400773679.035 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-22T15:47:59.040Z,1400773679.040 [Default:GPS] Running Loop=1
2014-05-22T15:47:59.040Z,1400773679.040 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-05-22T15:47:59.040Z,1400773679.040 [Default:GPS:A.SetSpeed] Running Loop=1
2014-05-22T15:47:59.040Z,1400773679.040 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-05-22T15:47:59.040Z,1400773679.040 [Default:GPS:B.GoToSurface] Running Loop=1
2014-05-22T15:47:59.040Z,1400773679.040 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-22T15:47:59.083Z,1400773679.083 [Default:GPS:B.GoToSurface] Stopped
2014-05-22T15:47:59.083Z,1400773679.083 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-22T15:47:59.083Z,1400773679.083 [Default:GPS:Read_GPS] Running Loop=1
2014-05-22T15:47:59.083Z,1400773679.083 [Default:GPS:A.SetSpeed] Running Loop=1
2014-05-22T15:47:59.344Z,1400773679.344 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2014-05-22T15:47:59.347Z,1400773679.347 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2014-05-22T15:48:03.747Z,1400773683.747 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-22T15:48:03.748Z,1400773683.748 [DVL_micro] Data Fault, FailCount= 1
2014-05-22T15:48:03.748Z,1400773683.748 [DVL_micro](ERROR): Data Fault
2014-05-22T15:48:03.831Z,1400773683.831 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-22T15:48:04.171Z,1400773684.171 [DVL_micro](INFO): uninitialize:Powering down
2014-05-22T15:48:04.512Z,1400773684.512 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-22T15:48:04.512Z,1400773684.512 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-22T15:48:04.512Z,1400773684.512 [DVL_micro](ERROR): Hardware Fault
2014-05-22T15:48:04.911Z,1400773684.911 [DVL_micro](INFO): Initializing
2014-05-22T15:48:04.962Z,1400773684.962 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-22T15:48:04.963Z,1400773684.963 [DVL_micro] No Fault, FailCount= 1
2014-05-22T15:48:31.841Z,1400773711.841 [CommandLine](IMPORTANT): got command failComponent
2014-05-22T15:48:31.841Z,1400773711.841 [CommandLine](IMPORTANT): Failed components:
2014-05-22T15:48:31.841Z,1400773711.841 [CommandLine](IMPORTANT): AHRS_sp3003D: Hardware Fault
2014-05-22T15:50:12.115Z,1400773812.115 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2014-05-22T15:50:12.188Z,1400773812.188 [CBIT](INFO): Clearing failed count for component AHRS_sp3003D
2014-05-22T15:50:12.188Z,1400773812.188 [AHRS_sp3003D] No Fault, FailCount= 5
2014-05-22T15:50:12.505Z,1400773812.505 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2014-05-22T15:50:19.428Z,1400773819.428 [CommandLine](IMPORTANT): got command help failComponent
2014-05-22T15:51:08.963Z,1400773868.963 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-22T15:51:08.963Z,1400773868.963 [DVL_micro] Data Fault, FailCount= 1
2014-05-22T15:51:08.963Z,1400773868.963 [DVL_micro](ERROR): Data Fault
2014-05-22T15:51:08.998Z,1400773868.998 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-22T15:51:09.497Z,1400773869.497 [DVL_micro](INFO): uninitialize:Powering down
2014-05-22T15:51:09.911Z,1400773869.911 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-22T15:51:09.911Z,1400773869.911 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-22T15:51:09.911Z,1400773869.911 [DVL_micro](ERROR): Hardware Fault
2014-05-22T15:51:10.347Z,1400773870.347 [DVL_micro](INFO): Initializing
2014-05-22T15:51:10.409Z,1400773870.409 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-22T15:51:10.409Z,1400773870.409 [DVL_micro] No Fault, FailCount= 1
2014-05-22T15:51:16.997Z,1400773876.997 [CommandLine](IMPORTANT): got command failComponent none AHRS_sp3003D
2014-05-22T15:51:16.997Z,1400773876.997 [CommandLine](IMPORTANT): AHRS_sp3003D failureMode is No Fault
2014-05-22T15:51:41.647Z,1400773901.647 [CommandLine](IMPORTANT): got command failComponent
2014-05-22T15:51:41.647Z,1400773901.647 [CommandLine](IMPORTANT): Failed components:
2014-05-22T15:51:41.647Z,1400773901.647 [CommandLine](IMPORTANT): No failed Components.
2014-05-22T15:51:53.174Z,1400773913.174 [CommandLine](IMPORTANT): got command ibit
2014-05-22T15:51:53.795Z,1400773913.795 [IBIT](IMPORTANT): Beginning Initiated BIT
2014-05-22T15:51:53.795Z,1400773913.795 [IBIT](IMPORTANT): Beginning control surface checks.
2014-05-22T15:51:53.797Z,1400773913.797 [CBIT](IMPORTANT): Beginning GF scan
2014-05-22T15:51:55.044Z,1400773915.044 [Radio_Freewave](INFO): Powering down
2014-05-22T15:51:55.952Z,1400773915.952 [Radio_Freewave](INFO): Powering up
2014-05-22T15:51:57.156Z,1400773917.156 [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-05-22T15:52:20.139Z,1400773940.139 [CBIT](IMPORTANT): No ground fault detected
2014-05-22T15:53:44.873Z,1400774024.873 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired.
2014-05-22T15:53:45.354Z,1400774025.354 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 231.419998
Voltage: 16.051750
2014-05-22T15:53:45.355Z,1400774025.355 [IBIT](IMPORTANT): batteryCapacityThreshold: 5.000000 Ah
2014-05-22T15:53:45.355Z,1400774025.355 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.500000 V
2014-05-22T15:53:45.784Z,1400774025.784 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2014-05-22T15:53:45.784Z,1400774025.784 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2014-05-22T15:53:45.785Z,1400774025.785 [IBIT](IMPORTANT): Pressure:11.265132 PSI
2014-05-22T15:53:45.785Z,1400774025.785 [IBIT](IMPORTANT): Humidity:8.867475 %
2014-05-22T15:53:46.261Z,1400774026.261 [IBIT](IMPORTANT): surfaceThreshold: 0.500000 m
2014-05-22T15:53:46.261Z,1400774026.261 [IBIT](IMPORTANT): buoyancyNeutral: 300.000000 cc
2014-05-22T15:53:46.261Z,1400774026.261 [IBIT](IMPORTANT): massDefault: 0.000000 cm
2014-05-22T15:53:46.262Z,1400774026.262 [IBIT](IMPORTANT): stopDepth: 112.000000 m
2014-05-22T15:53:46.262Z,1400774026.262 [IBIT](IMPORTANT): abortDepth: 130.000000 m
2014-05-22T15:53:46.262Z,1400774026.262 [IBIT](IMPORTANT): IBIT FAILED
2014-05-22T15:54:14.655Z,1400774054.655 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-22T15:54:14.655Z,1400774054.655 [DVL_micro] Data Fault, FailCount= 1
2014-05-22T15:54:14.655Z,1400774054.655 [DVL_micro](ERROR): Data Fault
2014-05-22T15:54:14.749Z,1400774054.749 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-22T15:54:15.095Z,1400774055.095 [DVL_micro](INFO): uninitialize:Powering down
2014-05-22T15:54:15.507Z,1400774055.507 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-22T15:54:15.507Z,1400774055.507 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-22T15:54:15.507Z,1400774055.507 [DVL_micro](ERROR): Hardware Fault
2014-05-22T15:54:15.926Z,1400774055.926 [DVL_micro](INFO): Initializing
2014-05-22T15:54:15.988Z,1400774055.988 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-22T15:54:15.988Z,1400774055.988 [DVL_micro] No Fault, FailCount= 1
2014-05-22T15:55:10.157Z,1400774110.157 [NAL9602](FAULT): GPS failed to acquire within timeout.
2014-05-22T15:55:10.157Z,1400774110.157 [NAL9602] Data Fault, FailCount= 1
2014-05-22T15:55:10.157Z,1400774110.157 [NAL9602](ERROR): Data Fault
2014-05-22T15:55:10.190Z,1400774110.190 [CBIT](ERROR): Data Fault in component: NAL9602
2014-05-22T15:55:10.565Z,1400774110.565 [NAL9602](INFO): Powering down
2014-05-22T15:55:11.441Z,1400774111.441 [CBIT](INFO): Clearing failed state for component NAL9602
2014-05-22T15:55:11.441Z,1400774111.441 [NAL9602] No Fault, FailCount= 1
2014-05-22T15:55:15.966Z,1400774115.966 [NAL9602](INFO): Powering up NAL9602
2014-05-22T15:55:26.686Z,1400774126.686 [NAL9602](INFO): NAL9602 initialized
2014-05-22T15:55:36.232Z,1400774136.232 [CommandLine](IMPORTANT): got command failComponent
2014-05-22T15:55:36.232Z,1400774136.232 [CommandLine](IMPORTANT): Failed components:
2014-05-22T15:55:36.233Z,1400774136.233 [CommandLine](IMPORTANT): No failed Components.
2014-05-22T15:55:40.782Z,1400774140.782 [CommandLine](IMPORTANT): got command restart application
2014-05-22T15:55:41.787Z,1400774141.787 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-22T15:55:41.788Z,1400774141.788 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-05-22T15:55:41.883Z,1400774141.883 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2014-05-22T15:55:41.883Z,1400774141.883 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-05-22T15:55:41.884Z,1400774141.884 [CommandLine](INFO): Join timeout helper Thread ID is 1126
2014-05-22T15:55:41.884Z,1400774141.884 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2014-05-22T15:55:41.885Z,1400774141.885 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-05-22T15:55:41.885Z,1400774141.885 [NavChartDb](INFO): Join timeout helper Thread ID is 1127
2014-05-22T15:55:42.252Z,1400774142.252 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-22T15:55:42.252Z,1400774142.252 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-05-22T15:55:42.264Z,1400774142.264 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2014-05-22T15:55:42.264Z,1400774142.264 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-05-22T15:55:42.264Z,1400774142.264 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1128
2014-05-22T15:55:42.621Z,1400774142.621 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-22T15:55:42.621Z,1400774142.621 [WetLabsBB2FL](INFO): Powering down
2014-05-22T15:55:42.622Z,1400774142.622 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-05-22T15:55:42.636Z,1400774142.636 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2014-05-22T15:55:42.637Z,1400774142.637 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-05-22T15:55:42.637Z,1400774142.637 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 1129
2014-05-22T15:55:42.725Z,1400774142.725 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-22T15:55:42.725Z,1400774142.725 [CTD_NeilBrown](INFO): Powering down
2014-05-22T15:55:42.726Z,1400774142.726 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-05-22T15:55:42.745Z,1400774142.745 [ComponentRegistry](INFO): Shutting down Radio_Freewave ThreadHandler
2014-05-22T15:55:42.745Z,1400774142.745 [Radio_Freewave ThreadHandler](INFO): Thread cancelled.
2014-05-22T15:55:42.745Z,1400774142.745 [Radio_Freewave](INFO): Join timeout helper Thread ID is 1130
2014-05-22T15:55:42.933Z,1400774142.933 [Radio_Freewave ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-22T15:55:43.036Z,1400774143.036 [Radio_Freewave](INFO): Powering down
2014-05-22T15:55:43.442Z,1400774143.442 [Radio_Freewave ThreadHandler](INFO): Thread cancelled.
2014-05-22T15:55:43.451Z,1400774143.451 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2014-05-22T15:55:43.451Z,1400774143.451 [logger ThreadHandler](INFO): Thread cancelled.
2014-05-22T15:55:43.451Z,1400774143.451 [logger](INFO): Join timeout helper Thread ID is 1133
2014-05-22T15:55:43.494Z,1400774143.494 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-22T15:55:43.494Z,1400774143.494 [logger ThreadHandler](INFO): Thread cancelled.
2014-05-22T15:55:43.510Z,1400774143.510 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2014-05-22T15:55:43.511Z,1400774143.511 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-05-22T15:55:43.511Z,1400774143.511 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2014-05-22T15:55:43.511Z,1400774143.511 [controlThread ThreadHandler](INFO): Thread cancelled.
2014-05-22T15:55:43.511Z,1400774143.511 [controlThread](INFO): Join timeout helper Thread ID is 1134
2014-05-22T15:55:43.542Z,1400774143.542 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-22T15:55:43.542Z,1400774143.542 [controlThread](DEBUG): Uninitializing ControlThread
2014-05-22T15:55:43.542Z,1400774143.542 [AHRS_sp3003D](INFO): Powering down
2014-05-22T15:55:43.543Z,1400774143.543 [DVL_micro](INFO): uninitialize:Powering down
2014-05-22T15:55:43.544Z,1400774143.544 [NAL9602](INFO): Powering down
2014-05-22T15:55:43.547Z,1400774143.547 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2014-05-22T15:55:43.550Z,1400774143.550 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2014-05-22T15:55:43.550Z,1400774143.550 [Default] Stopped
2014-05-22T15:55:43.551Z,1400774143.551 [Default](INFO): Aggregate::uninitialize Default
2014-05-22T15:55:43.551Z,1400774143.551 [Default:GPS] Stopped
2014-05-22T15:55:43.551Z,1400774143.551 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-05-22T15:55:43.551Z,1400774143.551 [Default:GPS:A.SetSpeed] Stopped
2014-05-22T15:55:43.551Z,1400774143.551 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-05-22T15:55:43.551Z,1400774143.551 [Default:GPS:Read_GPS] Stopped
2014-05-22T15:55:43.551Z,1400774143.551 [Default:Iridium] Stopped
2014-05-22T15:55:43.551Z,1400774143.551 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-22T15:55:43.551Z,1400774143.551 [Default:Iridium:A.SetSpeed] Stopped
2014-05-22T15:55:43.552Z,1400774143.552 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-22T15:55:43.552Z,1400774143.552 [Default:Iridium:Read_Iridium] Stopped
2014-05-22T15:55:43.552Z,1400774143.552 [Default:CallIridium] Stopped
2014-05-22T15:55:43.552Z,1400774143.552 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-22T15:55:43.552Z,1400774143.552 [Default:CallIridium:B] Stopped
2014-05-22T15:55:43.552Z,1400774143.552 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-22T15:55:43.557Z,1400774143.557 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2014-05-22T15:55:43.558Z,1400774143.558 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2014-05-22T15:55:43.558Z,1400774143.558 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2014-05-22T15:55:43.558Z,1400774143.558 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2014-05-22T15:55:43.559Z,1400774143.559 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2014-05-22T15:55:43.559Z,1400774143.559 [BuoyancyServo](INFO): Powering down
2014-05-22T15:55:43.574Z,1400774143.574 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2014-05-22T15:55:43.574Z,1400774143.574 [ElevatorServo](INFO): Powering down
2014-05-22T15:55:43.575Z,1400774143.575 [MassServo](DEBUG): Uninitialize Mass Servo.
2014-05-22T15:55:43.575Z,1400774143.575 [MassServo](INFO): Powering down
2014-05-22T15:55:43.576Z,1400774143.576 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2014-05-22T15:55:43.576Z,1400774143.576 [RudderServo](INFO): Powering down
2014-05-22T15:55:43.576Z,1400774143.576 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2014-05-22T15:55:43.577Z,1400774143.577 [ThrusterServo](INFO): Powering down
2014-05-22T15:55:43.577Z,1400774143.577 [SBIT](DEBUG): Uninitialize SBIT Component.
2014-05-22T15:55:43.578Z,1400774143.578 [IBIT](DEBUG): Uninitialize IBIT Component.
2014-05-22T15:55:43.578Z,1400774143.578 [CBIT](DEBUG): Uninitialize CBIT Component.
2014-05-22T15:55:43.623Z,1400774143.623 [controlThread ThreadHandler](INFO): Thread cancelled.
2014-05-22T15:55:43.639Z,1400774143.639 [Radio_Freewave ThreadHandler](INFO): Thread cancelled.
2014-05-22T15:55:43.714Z,1400774143.714 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-05-22T15:55:43.717Z,1400774143.717 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-05-22T15:55:43.765Z,1400774143.765 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-05-22T15:55:43.799Z,1400774143.799 [logger ThreadHandler](INFO): Thread cancelled.