2014-06-03T17:41:59.207Z,1401817319.207 [Supervisor](DEBUG): Initializing supervisor.
2014-06-03T17:41:59.209Z,1401817319.209 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0
2014-06-03T17:41:59.210Z,1401817319.210 [SyncHandler](INFO): Protected caller Thread ID is 776
2014-06-03T17:41:59.210Z,1401817319.210 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2014-06-03T17:41:59.211Z,1401817319.211 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0
2014-06-03T17:41:59.212Z,1401817319.212 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 777
2014-06-03T17:41:59.214Z,1401817319.214 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2014-06-03T17:41:59.226Z,1401817319.226 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2014-06-03T17:41:59.227Z,1401817319.227 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0
2014-06-03T17:41:59.227Z,1401817319.227 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 778
2014-06-03T17:41:59.228Z,1401817319.228 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2014-06-03T17:41:59.229Z,1401817319.229 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0
2014-06-03T17:41:59.229Z,1401817319.229 [logger ThreadHandler](INFO): Protected caller Thread ID is 779
2014-06-03T17:41:59.232Z,1401817319.232 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2014-06-03T17:41:59.232Z,1401817319.232 [Supervisor](INFO): Looking for Config files in directory: Config/
2014-06-03T17:41:59.235Z,1401817319.235 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2014-06-03T17:41:59.585Z,1401817319.585 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2014-06-03T17:41:59.587Z,1401817319.587 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2014-06-03T17:41:59.869Z,1401817319.869 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2014-06-03T17:41:59.871Z,1401817319.871 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2014-06-03T17:41:59.958Z,1401817319.958 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2014-06-03T17:41:59.959Z,1401817319.959 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2014-06-03T17:42:00.147Z,1401817320.147 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2014-06-03T17:42:00.148Z,1401817320.148 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2014-06-03T17:42:00.317Z,1401817320.317 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2014-06-03T17:42:00.317Z,1401817320.317 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2014-06-03T17:42:00.630Z,1401817320.630 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2014-06-03T17:42:00.633Z,1401817320.633 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2014-06-03T17:42:00.822Z,1401817320.822 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2014-06-03T17:42:00.824Z,1401817320.824 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2014-06-03T17:42:01.165Z,1401817321.165 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2014-06-03T17:42:01.166Z,1401817321.166 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2014-06-03T17:42:01.280Z,1401817321.280 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2014-06-03T17:42:01.280Z,1401817321.280 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2014-06-03T17:42:01.790Z,1401817321.790 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2014-06-03T17:42:01.792Z,1401817321.792 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2014-06-03T17:42:01.906Z,1401817321.906 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2014-06-03T17:42:01.908Z,1401817321.908 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2014-06-03T17:42:01.996Z,1401817321.996 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2014-06-03T17:42:02.117Z,1401817322.117 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2014-06-03T17:42:02.119Z,1401817322.119 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2014-06-03T17:42:02.226Z,1401817322.226 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2014-06-03T17:42:02.227Z,1401817322.227 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2014-06-03T17:42:02.370Z,1401817322.370 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2014-06-03T17:42:02.372Z,1401817322.372 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2014-06-03T17:42:02.377Z,1401817322.377 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2014-06-03T17:42:02.490Z,1401817322.490 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2014-06-03T17:42:02.622Z,1401817322.622 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2014-06-03T17:42:06.559Z,1401817326.559 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2014-06-03T17:42:06.654Z,1401817326.654 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2014-06-03T17:42:06.974Z,1401817326.974 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2014-06-03T17:42:07.092Z,1401817327.092 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2014-06-03T17:42:07.180Z,1401817327.180 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2014-06-03T17:42:07.285Z,1401817327.285 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2014-06-03T17:42:07.386Z,1401817327.386 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2014-06-03T17:42:07.484Z,1401817327.484 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2014-06-03T17:42:07.573Z,1401817327.573 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Estimation.cfg
2014-06-03T17:42:07.674Z,1401817327.674 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2014-06-03T17:42:09.340Z,1401817329.340 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2014-06-03T17:42:09.918Z,1401817329.918 [AHRS_sp3003D] Loaded
2014-06-03T17:42:09.918Z,1401817329.918 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2014-06-03T17:42:10.216Z,1401817330.216 [Batt_Ocean_Server] Loaded
2014-06-03T17:42:10.216Z,1401817330.216 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2014-06-03T17:42:10.230Z,1401817330.230 [Depth_Keller] Loaded
2014-06-03T17:42:10.230Z,1401817330.230 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2014-06-03T17:42:10.235Z,1401817330.235 [DropWeight] Loaded
2014-06-03T17:42:10.235Z,1401817330.235 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2014-06-03T17:42:10.378Z,1401817330.378 [DVL_micro] Loaded
2014-06-03T17:42:10.378Z,1401817330.378 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2014-06-03T17:42:10.479Z,1401817330.479 [NAL9602] Loaded
2014-06-03T17:42:10.479Z,1401817330.479 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2014-06-03T17:42:10.532Z,1401817330.532 [Onboard] Loaded
2014-06-03T17:42:10.532Z,1401817330.532 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2014-06-03T17:42:10.539Z,1401817330.539 [Radio_Freewave] Loaded
2014-06-03T17:42:10.539Z,1401817330.539 [ComponentRegistry](DEBUG): Component "Radio_Freewave" handled in its own thread.
2014-06-03T17:42:10.540Z,1401817330.540 [Radio_Freewave ThreadHandler](DEBUG): Created PCaller Thread at 406104E0
2014-06-03T17:42:10.541Z,1401817330.541 [Radio_Freewave ThreadHandler](INFO): Protected caller Thread ID is 862
2014-06-03T17:42:10.548Z,1401817330.548 [SCPI] Loaded
2014-06-03T17:42:10.548Z,1401817330.548 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread.
2014-06-03T17:42:10.549Z,1401817330.549 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2014-06-03T17:42:10.549Z,1401817330.549 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2014-06-03T17:42:10.746Z,1401817330.746 [InternalSim] Loaded
2014-06-03T17:42:10.746Z,1401817330.746 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2014-06-03T17:42:10.747Z,1401817330.747 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2014-06-03T17:42:10.749Z,1401817330.749 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2014-06-03T17:42:11.035Z,1401817331.035 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2014-06-03T17:42:11.035Z,1401817331.035 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2014-06-03T17:42:11.044Z,1401817331.044 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2014-06-03T17:42:11.044Z,1401817331.044 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2014-06-03T17:42:11.140Z,1401817331.140 [DeadReckonUsingMultipleVelocitySources] Loaded
2014-06-03T17:42:11.140Z,1401817331.140 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2014-06-03T17:42:11.186Z,1401817331.186 [DeadReckonWithRespectToWater] Loaded
2014-06-03T17:42:11.186Z,1401817331.186 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToWater" handled in the control thread.
2014-06-03T17:42:11.233Z,1401817331.233 [DeadReckonWithRespectToSeafloor] Loaded
2014-06-03T17:42:11.233Z,1401817331.233 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToSeafloor" handled in the control thread.
2014-06-03T17:42:11.280Z,1401817331.280 [DeadReckonUsingDVLWaterTrack] Loaded
2014-06-03T17:42:11.281Z,1401817331.281 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingDVLWaterTrack" handled in the control thread.
2014-06-03T17:42:11.328Z,1401817331.328 [DeadReckonUsingCompactModelForecast] Loaded
2014-06-03T17:42:11.329Z,1401817331.329 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingCompactModelForecast" handled in the control thread.
2014-06-03T17:42:11.345Z,1401817331.345 [NavChart] Loaded
2014-06-03T17:42:11.345Z,1401817331.345 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2014-06-03T17:42:11.349Z,1401817331.349 [UniversalFixResidualReporter] Loaded
2014-06-03T17:42:11.349Z,1401817331.349 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2014-06-03T17:42:11.350Z,1401817331.350 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2014-06-03T17:42:11.351Z,1401817331.351 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2014-06-03T17:42:11.419Z,1401817331.419 [VerticalControl](DEBUG): Construct VerticalControl.
2014-06-03T17:42:11.531Z,1401817331.531 [VerticalControl] Loaded
2014-06-03T17:42:11.531Z,1401817331.531 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2014-06-03T17:42:11.532Z,1401817331.532 [HorizontalControl](DEBUG): Construct HorizontalControl.
2014-06-03T17:42:11.600Z,1401817331.600 [HorizontalControl] Loaded
2014-06-03T17:42:11.600Z,1401817331.600 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2014-06-03T17:42:11.601Z,1401817331.601 [SpeedControl](DEBUG): Construct SpeedControl.
2014-06-03T17:42:11.603Z,1401817331.603 [SpeedControl] Loaded
2014-06-03T17:42:11.603Z,1401817331.603 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2014-06-03T17:42:11.604Z,1401817331.604 [LoopControl](DEBUG): Construct LoopControl.
2014-06-03T17:42:11.604Z,1401817331.604 [LoopControl] Loaded
2014-06-03T17:42:11.605Z,1401817331.605 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2014-06-03T17:42:11.605Z,1401817331.605 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2014-06-03T17:42:11.607Z,1401817331.607 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2014-06-03T17:42:11.637Z,1401817331.637 [DepthRateCalculator] Loaded
2014-06-03T17:42:11.637Z,1401817331.637 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2014-06-03T17:42:11.642Z,1401817331.642 [PitchRateCalculator] Loaded
2014-06-03T17:42:11.643Z,1401817331.643 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2014-06-03T17:42:11.650Z,1401817331.650 [SpeedCalculator] Loaded
2014-06-03T17:42:11.650Z,1401817331.650 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2014-06-03T17:42:11.667Z,1401817331.667 [TempGradientCalculator] Loaded
2014-06-03T17:42:11.667Z,1401817331.667 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2014-06-03T17:42:11.673Z,1401817331.673 [YawRateCalculator] Loaded
2014-06-03T17:42:11.673Z,1401817331.673 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2014-06-03T17:42:11.673Z,1401817331.673 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2014-06-03T17:42:11.674Z,1401817331.674 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2014-06-03T17:42:11.806Z,1401817331.806 [CTD_NeilBrown] Loaded
2014-06-03T17:42:11.807Z,1401817331.807 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2014-06-03T17:42:11.808Z,1401817331.808 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4075F4E0
2014-06-03T17:42:11.808Z,1401817331.808 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 863
2014-06-03T17:42:11.821Z,1401817331.821 [ISUS] Loaded
2014-06-03T17:42:11.822Z,1401817331.822 [ComponentRegistry](DEBUG): SyncComponent "ISUS" handled in the control thread.
2014-06-03T17:42:11.837Z,1401817331.837 [PAR_Licor] Loaded
2014-06-03T17:42:11.837Z,1401817331.837 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2014-06-03T17:42:11.872Z,1401817331.872 [WetLabsBB2FL] Loaded
2014-06-03T17:42:11.872Z,1401817331.872 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2014-06-03T17:42:11.873Z,1401817331.873 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4078F4E0
2014-06-03T17:42:11.874Z,1401817331.874 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 864
2014-06-03T17:42:11.874Z,1401817331.874 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2014-06-03T17:42:11.875Z,1401817331.875 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2014-06-03T17:42:11.996Z,1401817331.996 [SBIT](DEBUG): Construct Startup Built In Test.
2014-06-03T17:42:12.008Z,1401817332.008 [SBIT] Loaded
2014-06-03T17:42:12.008Z,1401817332.008 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2014-06-03T17:42:12.009Z,1401817332.009 [IBIT](DEBUG): Construct Initiated Built In Test.
2014-06-03T17:42:12.022Z,1401817332.022 [IBIT] Loaded
2014-06-03T17:42:12.022Z,1401817332.022 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2014-06-03T17:42:12.024Z,1401817332.024 [CBIT](DEBUG): Construct CBIT Built In Test.
2014-06-03T17:42:12.094Z,1401817332.094 [CBIT] Loaded
2014-06-03T17:42:12.094Z,1401817332.094 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2014-06-03T17:42:12.095Z,1401817332.095 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2014-06-03T17:42:12.096Z,1401817332.096 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2014-06-03T17:42:17.850Z,1401817337.850 [HFRadarModelCalc] Loaded
2014-06-03T17:42:17.851Z,1401817337.851 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2014-06-03T17:42:21.334Z,1401817341.334 [HFRadarCompactModelForecaster] Loaded
2014-06-03T17:42:21.334Z,1401817341.334 [ComponentRegistry](DEBUG): SyncComponent "HFRadarCompactModelForecaster" handled in the control thread.
2014-06-03T17:42:22.247Z,1401817342.247 [HFRCMSpaceInterpolator] Loaded
2014-06-03T17:42:22.247Z,1401817342.247 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSpaceInterpolator" handled in the control thread.
2014-06-03T17:42:22.249Z,1401817342.249 [HFRCMTimeInterpolator] Loaded
2014-06-03T17:42:22.249Z,1401817342.249 [ComponentRegistry](DEBUG): SyncComponent "HFRCMTimeInterpolator" handled in the control thread.
2014-06-03T17:42:22.261Z,1401817342.261 [HFRCMSurfaceCurrentAtVehicleLocation] Loaded
2014-06-03T17:42:22.262Z,1401817342.262 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSurfaceCurrentAtVehicleLocation" handled in the control thread.
2014-06-03T17:42:22.289Z,1401817342.289 [HFRCMVirtualSurfaceDrifter] Loaded
2014-06-03T17:42:22.289Z,1401817342.289 [ComponentRegistry](DEBUG): SyncComponent "HFRCMVirtualSurfaceDrifter" handled in the control thread.
2014-06-03T17:42:22.290Z,1401817342.290 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2014-06-03T17:42:22.291Z,1401817342.291 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2014-06-03T17:42:22.417Z,1401817342.417 [BuoyancyServo] Loaded
2014-06-03T17:42:22.417Z,1401817342.417 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2014-06-03T17:42:22.429Z,1401817342.429 [ElevatorServo] Loaded
2014-06-03T17:42:22.430Z,1401817342.430 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2014-06-03T17:42:22.441Z,1401817342.441 [MassServo] Loaded
2014-06-03T17:42:22.442Z,1401817342.442 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2014-06-03T17:42:22.453Z,1401817342.453 [RudderServo] Loaded
2014-06-03T17:42:22.454Z,1401817342.454 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2014-06-03T17:42:22.465Z,1401817342.465 [ThrusterServo] Loaded
2014-06-03T17:42:22.466Z,1401817342.466 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2014-06-03T17:42:22.466Z,1401817342.466 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2014-06-03T17:42:22.467Z,1401817342.467 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2014-06-03T17:42:22.506Z,1401817342.506 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2014-06-03T17:42:22.508Z,1401817342.508 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2014-06-03T17:42:22.509Z,1401817342.509 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2014-06-03T17:42:22.515Z,1401817342.515 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2014-06-03T17:42:22.516Z,1401817342.516 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A544E0
2014-06-03T17:42:22.517Z,1401817342.517 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 865
2014-06-03T17:42:22.521Z,1401817342.521 [Supervisor](INFO): Main Thread ID is 771
2014-06-03T17:42:22.522Z,1401817342.522 [Supervisor](DEBUG): Running supervisor.
2014-06-03T17:42:22.522Z,1401817342.522 [CommandLine ThreadHandler](INFO): Handler Thread ID is 866
2014-06-03T17:42:22.526Z,1401817342.526 [controlThread ThreadHandler](INFO): Handler Thread ID is 867
2014-06-03T17:42:22.527Z,1401817342.527 [controlThread](DEBUG): Initializing ControlThread
2014-06-03T17:42:22.530Z,1401817342.530 [logger ThreadHandler](INFO): Handler Thread ID is 868
2014-06-03T17:42:22.556Z,1401817342.556 [Radio_Freewave ThreadHandler](INFO): Handler Thread ID is 869
2014-06-03T17:42:22.568Z,1401817342.568 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 870
2014-06-03T17:42:22.569Z,1401817342.569 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2014-06-03T17:42:22.572Z,1401817342.572 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2014-06-03T17:42:22.574Z,1401817342.574 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 872
2014-06-03T17:42:22.575Z,1401817342.575 [WetLabsBB2FL](INFO): Powering down
2014-06-03T17:42:22.608Z,1401817342.608 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 873
2014-06-03T17:42:22.619Z,1401817342.619 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2014-06-03T17:42:22.620Z,1401817342.620 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2014-06-03T17:42:22.620Z,1401817342.620 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2014-06-03T17:42:22.620Z,1401817342.620 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2014-06-03T17:42:22.621Z,1401817342.621 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2014-06-03T17:42:22.621Z,1401817342.621 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2014-06-03T17:42:22.621Z,1401817342.621 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2014-06-03T17:42:22.621Z,1401817342.621 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2014-06-03T17:42:22.622Z,1401817342.622 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2014-06-03T17:42:23.987Z,1401817343.987 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2014-06-03T17:42:24.017Z,1401817344.017 [InternalSim](DEBUG): InternalSim initializing...
2014-06-03T17:42:24.334Z,1401817344.334 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2014-06-03T17:42:24.335Z,1401817344.335 [DeadReckonWithRespectToWater](DEBUG): Initializing DeadReckonWithRespectToWater component.
2014-06-03T17:42:24.335Z,1401817344.335 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component.
2014-06-03T17:42:24.336Z,1401817344.336 [DeadReckonUsingDVLWaterTrack](DEBUG): Initializing DeadReckonUsingDVLWaterTrack component.
2014-06-03T17:42:24.336Z,1401817344.336 [DeadReckonUsingCompactModelForecast](DEBUG): Initializing DeadReckonUsingCompactModelForecast component.
2014-06-03T17:42:24.336Z,1401817344.336 [NavChart](DEBUG): Initialize NavChart Navigation.
2014-06-03T17:42:24.337Z,1401817344.337 [UniversalFixResidualReporter](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2014-06-03T17:42:24.337Z,1401817344.337 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2014-06-03T17:42:24.354Z,1401817344.354 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2014-06-03T17:42:24.355Z,1401817344.355 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2014-06-03T17:42:24.355Z,1401817344.355 [LoopControl](DEBUG): Initialize LoopControlComponent.
2014-06-03T17:42:24.356Z,1401817344.356 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2014-06-03T17:42:24.356Z,1401817344.356 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2014-06-03T17:42:24.357Z,1401817344.357 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2014-06-03T17:42:24.357Z,1401817344.357 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2014-06-03T17:42:24.358Z,1401817344.358 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2014-06-03T17:42:24.359Z,1401817344.359 [SBIT](INFO): Initialize SBIT Component.
2014-06-03T17:42:24.360Z,1401817344.360 [SBIT](IMPORTANT): Tethys CM Info:
$Rev:11349
2014-06-03T17:42:24.360Z,1401817344.360 [SBIT](IMPORTANT): Kernel Release:2.6.27.8
2014-06-03T17:42:24.360Z,1401817344.360 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2014-06-03T17:42:24.361Z,1401817344.361 [IBIT](INFO): Initialize IBIT Component.
2014-06-03T17:42:24.362Z,1401817344.362 [CBIT](DEBUG): Initialize CBIT Component.
2014-06-03T17:42:24.366Z,1401817344.366 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2014-06-03T17:42:24.401Z,1401817344.401 [HFRadarCompactModelForecaster](DEBUG): Found new ECs!
2014-06-03T17:42:24.840Z,1401817344.840 [Radio_Freewave](INFO): Powering up
2014-06-03T17:42:25.649Z,1401817345.649 [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-06-03T17:42:33.688Z,1401817353.688 [HFRadarCompactModelForecaster](IMPORTANT): forecast time 201406031400: published 50 modes in rows, 61 hours in columns
2014-06-03T17:42:33.697Z,1401817353.697 [HFRCMSpaceInterpolator](DEBUG): Initializing HFRCMSpaceInterpolator component with verbosity level 0.
2014-06-03T17:42:33.699Z,1401817353.699 [HFRCMSpaceInterpolator](INFO): gridIdxRev_: 541 by 1, [25.000000, 718.000000]
2014-06-03T17:42:33.700Z,1401817353.700 [HFRCMSpaceInterpolator](INFO): gridIdx_: 25 by 29, [nan, nan]
2014-06-03T17:42:33.709Z,1401817353.709 [HFRCMSpaceInterpolator](INFO): longitude grid: 25 by 29, [-122.743156, -121.797913]
2014-06-03T17:42:33.710Z,1401817353.710 [HFRCMSpaceInterpolator](INFO): latitude grid: 25 by 29, [36.341251, 36.990059]
2014-06-03T17:42:33.710Z,1401817353.710 [HFRCMTimeInterpolator](DEBUG): Initializing HFRCMTimeInterpolator component.
2014-06-03T17:42:33.711Z,1401817353.711 [HFRCMSurfaceCurrentAtVehicleLocation](DEBUG): Initializing HFRCMSurfaceCurrentAtVehicleLocation component.
2014-06-03T17:42:33.711Z,1401817353.711 [HFRCMVirtualSurfaceDrifter](DEBUG): Initializing HFRCMVirtualSurfaceDrifter component.
2014-06-03T17:42:33.714Z,1401817353.714 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2014-06-03T17:42:33.752Z,1401817353.752 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2014-06-03T17:42:33.785Z,1401817353.785 [MissionManager](DEBUG):
2014-06-03T17:42:33.786Z,1401817353.786 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2014-06-03T17:42:33.847Z,1401817353.847 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2014-06-03T17:42:33.874Z,1401817353.874 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2014-06-03T17:42:33.877Z,1401817353.877 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-06-03T17:42:33.890Z,1401817353.890 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2014-06-03T17:42:33.913Z,1401817353.913 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-06-03T17:42:33.938Z,1401817353.938 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2014-06-03T17:42:33.968Z,1401817353.968 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Construct.
2014-06-03T17:42:33.971Z,1401817353.971 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-06-03T17:42:33.995Z,1401817353.995 [MissionManager](DEBUG):
400
400
Burn 300
Dropped drop weight due to communications timeout
5.0
1.0
5
2014-06-03T17:42:34.011Z,1401817354.011 [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-06-03T17:42:34.108Z,1401817354.108 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2014-06-03T17:42:34.949Z,1401817354.949 [DVL_micro](INFO): Initializing
2014-06-03T17:42:34.977Z,1401817354.977 [NAL9602](INFO): Powering up NAL9602
2014-06-03T17:42:35.798Z,1401817355.798 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2014-06-03T17:42:35.804Z,1401817355.804 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2014-06-03T17:42:35.834Z,1401817355.834 [ElevatorServo](DEBUG): Initializing EZServoServo.
2014-06-03T17:42:35.840Z,1401817355.840 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2014-06-03T17:42:35.862Z,1401817355.862 [MassServo](DEBUG): Initializing EZServoServo.
2014-06-03T17:42:35.868Z,1401817355.868 [MassServo](DEBUG): Initializing MassServo.
2014-06-03T17:42:35.874Z,1401817355.874 [RudderServo](DEBUG): Initializing EZServoServo.
2014-06-03T17:42:35.880Z,1401817355.880 [RudderServo](DEBUG): Initializing RudderServo.
2014-06-03T17:42:35.902Z,1401817355.902 [ThrusterServo](DEBUG): Initializing EZServoServo.
2014-06-03T17:42:35.908Z,1401817355.908 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2014-06-03T17:42:40.256Z,1401817360.256 [SBIT](IMPORTANT): Beginning Startup BIT
2014-06-03T17:42:40.258Z,1401817360.258 [CBIT](IMPORTANT): Beginning GF scan
2014-06-03T17:42:45.940Z,1401817365.940 [NAL9602](INFO): NAL9602 initialized
2014-06-03T17:42:46.224Z,1401817366.224 [CommandLine](IMPORTANT): got command quit
2014-06-03T17:42:47.233Z,1401817367.233 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2014-06-03T17:42:47.233Z,1401817367.233 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:42:47.290Z,1401817367.290 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2014-06-03T17:42:47.290Z,1401817367.290 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:42:47.290Z,1401817367.290 [CommandLine](INFO): Join timeout helper Thread ID is 885
2014-06-03T17:42:47.298Z,1401817367.298 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2014-06-03T17:42:47.298Z,1401817367.298 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:42:47.299Z,1401817367.299 [NavChartDb](INFO): Join timeout helper Thread ID is 886
2014-06-03T17:42:48.134Z,1401817368.134 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2014-06-03T17:42:48.135Z,1401817368.135 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:42:48.143Z,1401817368.143 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2014-06-03T17:42:48.143Z,1401817368.143 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:42:48.144Z,1401817368.144 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 887
2014-06-03T17:42:48.520Z,1401817368.520 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2014-06-03T17:42:48.520Z,1401817368.520 [WetLabsBB2FL](INFO): Powering down
2014-06-03T17:42:48.521Z,1401817368.521 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:42:48.524Z,1401817368.524 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2014-06-03T17:42:48.524Z,1401817368.524 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:42:48.524Z,1401817368.524 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 888
2014-06-03T17:42:48.580Z,1401817368.580 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2014-06-03T17:42:48.580Z,1401817368.580 [CTD_NeilBrown](INFO): Powering down
2014-06-03T17:42:48.581Z,1401817368.581 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:42:48.584Z,1401817368.584 [ComponentRegistry](INFO): Shutting down Radio_Freewave ThreadHandler
2014-06-03T17:42:48.584Z,1401817368.584 [Radio_Freewave ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:42:48.584Z,1401817368.584 [Radio_Freewave](INFO): Join timeout helper Thread ID is 889
2014-06-03T17:42:48.961Z,1401817368.961 [Radio_Freewave ThreadHandler](INFO): Uninitializing protected caller thread.
2014-06-03T17:42:49.127Z,1401817369.127 [Radio_Freewave](INFO): Powering down
2014-06-03T17:42:49.529Z,1401817369.529 [Radio_Freewave ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:42:49.546Z,1401817369.546 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2014-06-03T17:42:49.546Z,1401817369.546 [logger ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:42:49.547Z,1401817369.547 [logger](INFO): Join timeout helper Thread ID is 891
2014-06-03T17:42:49.557Z,1401817369.557 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2014-06-03T17:42:49.558Z,1401817369.558 [logger ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:42:49.566Z,1401817369.566 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2014-06-03T17:42:49.566Z,1401817369.566 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:42:49.566Z,1401817369.566 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2014-06-03T17:42:49.566Z,1401817369.566 [controlThread ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:42:49.567Z,1401817369.567 [controlThread](INFO): Join timeout helper Thread ID is 892
2014-06-03T17:42:49.639Z,1401817369.639 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2014-06-03T17:42:49.640Z,1401817369.640 [controlThread](DEBUG): Uninitializing ControlThread
2014-06-03T17:42:49.640Z,1401817369.640 [AHRS_sp3003D](INFO): Powering down
2014-06-03T17:42:49.798Z,1401817369.798 [DVL_micro](INFO): uninitialize:Powering down
2014-06-03T17:42:49.799Z,1401817369.799 [NAL9602](INFO): Powering down
2014-06-03T17:42:49.802Z,1401817369.802 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2014-06-03T17:42:49.805Z,1401817369.805 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2014-06-03T17:42:49.810Z,1401817369.810 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2014-06-03T17:42:49.811Z,1401817369.811 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2014-06-03T17:42:49.811Z,1401817369.811 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2014-06-03T17:42:49.811Z,1401817369.811 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2014-06-03T17:42:49.811Z,1401817369.811 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2014-06-03T17:42:49.812Z,1401817369.812 [BuoyancyServo](INFO): Powering down
2014-06-03T17:42:49.826Z,1401817369.826 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2014-06-03T17:42:49.826Z,1401817369.826 [ElevatorServo](INFO): Powering down
2014-06-03T17:42:49.827Z,1401817369.827 [MassServo](DEBUG): Uninitialize Mass Servo.
2014-06-03T17:42:49.827Z,1401817369.827 [MassServo](INFO): Powering down
2014-06-03T17:42:49.828Z,1401817369.828 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2014-06-03T17:42:49.828Z,1401817369.828 [RudderServo](INFO): Powering down
2014-06-03T17:42:49.829Z,1401817369.829 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2014-06-03T17:42:49.829Z,1401817369.829 [ThrusterServo](INFO): Powering down
2014-06-03T17:42:49.830Z,1401817369.830 [SBIT](DEBUG): Uninitialize SBIT Component.
2014-06-03T17:42:49.830Z,1401817369.830 [IBIT](DEBUG): Uninitialize IBIT Component.
2014-06-03T17:42:49.830Z,1401817369.830 [CBIT](DEBUG): Uninitialize CBIT Component.
2014-06-03T17:42:49.875Z,1401817369.875 [controlThread ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:42:49.891Z,1401817369.891 [Radio_Freewave ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:42:49.963Z,1401817369.963 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:42:49.967Z,1401817369.967 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:42:50.131Z,1401817370.131 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:42:50.165Z,1401817370.165 [logger ThreadHandler](INFO): Thread cancelled.