2014-05-22T02:04:17.906Z,1400724257.906 [Supervisor](DEBUG): Initializing supervisor.
2014-05-22T02:04:17.909Z,1400724257.909 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0
2014-05-22T02:04:17.910Z,1400724257.910 [SyncHandler](INFO): Protected caller Thread ID is 776
2014-05-22T02:04:17.911Z,1400724257.911 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2014-05-22T02:04:17.914Z,1400724257.914 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0
2014-05-22T02:04:17.915Z,1400724257.915 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 777
2014-05-22T02:04:17.917Z,1400724257.917 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2014-05-22T02:04:17.929Z,1400724257.929 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2014-05-22T02:04:17.934Z,1400724257.934 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0
2014-05-22T02:04:17.935Z,1400724257.935 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 778
2014-05-22T02:04:17.936Z,1400724257.936 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2014-05-22T02:04:17.938Z,1400724257.938 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0
2014-05-22T02:04:17.939Z,1400724257.939 [logger ThreadHandler](INFO): Protected caller Thread ID is 779
2014-05-22T02:04:17.941Z,1400724257.941 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2014-05-22T02:04:17.941Z,1400724257.941 [Supervisor](INFO): Looking for Config files in directory: Config/
2014-05-22T02:04:17.946Z,1400724257.946 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2014-05-22T02:04:18.361Z,1400724258.361 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2014-05-22T02:04:18.361Z,1400724258.361 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2014-05-22T02:04:18.687Z,1400724258.687 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2014-05-22T02:04:18.688Z,1400724258.688 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2014-05-22T02:04:18.787Z,1400724258.787 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2014-05-22T02:04:18.789Z,1400724258.789 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2014-05-22T02:04:19.005Z,1400724259.005 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2014-05-22T02:04:19.006Z,1400724259.006 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2014-05-22T02:04:19.189Z,1400724259.189 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2014-05-22T02:04:19.191Z,1400724259.191 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2014-05-22T02:04:19.546Z,1400724259.546 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2014-05-22T02:04:19.547Z,1400724259.547 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2014-05-22T02:04:19.754Z,1400724259.754 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2014-05-22T02:04:19.755Z,1400724259.755 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2014-05-22T02:04:20.151Z,1400724260.151 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2014-05-22T02:04:20.153Z,1400724260.153 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2014-05-22T02:04:20.279Z,1400724260.279 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2014-05-22T02:04:20.279Z,1400724260.279 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2014-05-22T02:04:20.884Z,1400724260.884 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2014-05-22T02:04:20.884Z,1400724260.884 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2014-05-22T02:04:23.006Z,1400724263.006 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2014-05-22T02:04:23.006Z,1400724263.006 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2014-05-22T02:04:23.107Z,1400724263.107 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2014-05-22T02:04:23.235Z,1400724263.235 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2014-05-22T02:04:23.236Z,1400724263.236 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2014-05-22T02:04:23.356Z,1400724263.356 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2014-05-22T02:04:23.356Z,1400724263.356 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2014-05-22T02:04:23.512Z,1400724263.512 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2014-05-22T02:04:23.514Z,1400724263.514 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2014-05-22T02:04:23.518Z,1400724263.518 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2014-05-22T02:04:23.640Z,1400724263.640 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2014-05-22T02:04:23.793Z,1400724263.793 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2014-05-22T02:04:23.905Z,1400724263.905 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2014-05-22T02:04:24.013Z,1400724264.013 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2014-05-22T02:04:24.187Z,1400724264.187 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2014-05-22T02:04:24.327Z,1400724264.327 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2014-05-22T02:04:24.424Z,1400724264.424 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2014-05-22T02:04:24.543Z,1400724264.543 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2014-05-22T02:04:24.658Z,1400724264.658 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2014-05-22T02:04:24.770Z,1400724264.770 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2014-05-22T02:04:24.871Z,1400724264.871 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Estimation.cfg
2014-05-22T02:04:24.983Z,1400724264.983 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2014-05-22T02:04:24.986Z,1400724264.986 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2014-05-22T02:04:25.615Z,1400724265.615 [AHRS_sp3003D] Loaded
2014-05-22T02:04:25.615Z,1400724265.615 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2014-05-22T02:04:25.954Z,1400724265.954 [Batt_Ocean_Server] Loaded
2014-05-22T02:04:25.955Z,1400724265.955 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2014-05-22T02:04:25.969Z,1400724265.969 [Depth_Keller] Loaded
2014-05-22T02:04:25.969Z,1400724265.969 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2014-05-22T02:04:25.975Z,1400724265.975 [DropWeight] Loaded
2014-05-22T02:04:25.975Z,1400724265.975 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2014-05-22T02:04:26.138Z,1400724266.138 [DVL_micro] Loaded
2014-05-22T02:04:26.138Z,1400724266.138 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2014-05-22T02:04:26.261Z,1400724266.261 [NAL9602] Loaded
2014-05-22T02:04:26.261Z,1400724266.261 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2014-05-22T02:04:26.321Z,1400724266.321 [Onboard] Loaded
2014-05-22T02:04:26.322Z,1400724266.322 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2014-05-22T02:04:26.329Z,1400724266.329 [Radio_Freewave] Loaded
2014-05-22T02:04:26.330Z,1400724266.330 [ComponentRegistry](DEBUG): Component "Radio_Freewave" handled in its own thread.
2014-05-22T02:04:26.331Z,1400724266.331 [Radio_Freewave ThreadHandler](DEBUG): Created PCaller Thread at 4060F4E0
2014-05-22T02:04:26.332Z,1400724266.332 [Radio_Freewave ThreadHandler](INFO): Protected caller Thread ID is 861
2014-05-22T02:04:26.339Z,1400724266.339 [SCPI] Loaded
2014-05-22T02:04:26.339Z,1400724266.339 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread.
2014-05-22T02:04:26.340Z,1400724266.340 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2014-05-22T02:04:26.341Z,1400724266.341 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2014-05-22T02:04:28.372Z,1400724268.372 [InternalSim] Loaded
2014-05-22T02:04:28.372Z,1400724268.372 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2014-05-22T02:04:28.373Z,1400724268.373 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2014-05-22T02:04:28.374Z,1400724268.374 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2014-05-22T02:04:28.692Z,1400724268.692 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2014-05-22T02:04:28.694Z,1400724268.694 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2014-05-22T02:04:28.702Z,1400724268.702 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2014-05-22T02:04:28.703Z,1400724268.703 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2014-05-22T02:04:28.809Z,1400724268.809 [DeadReckonUsingMultipleVelocitySources] Loaded
2014-05-22T02:04:28.809Z,1400724268.809 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2014-05-22T02:04:28.865Z,1400724268.865 [DeadReckonWithRespectToWater] Loaded
2014-05-22T02:04:28.866Z,1400724268.866 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToWater" handled in the control thread.
2014-05-22T02:04:28.918Z,1400724268.918 [DeadReckonWithRespectToSeafloor] Loaded
2014-05-22T02:04:28.918Z,1400724268.918 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToSeafloor" handled in the control thread.
2014-05-22T02:04:28.976Z,1400724268.976 [DeadReckonUsingDVLWaterTrack] Loaded
2014-05-22T02:04:28.977Z,1400724268.977 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingDVLWaterTrack" handled in the control thread.
2014-05-22T02:04:29.030Z,1400724269.030 [DeadReckonUsingCompactModelForecast] Loaded
2014-05-22T02:04:29.031Z,1400724269.031 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingCompactModelForecast" handled in the control thread.
2014-05-22T02:04:29.047Z,1400724269.047 [NavChart] Loaded
2014-05-22T02:04:29.048Z,1400724269.048 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2014-05-22T02:04:29.052Z,1400724269.052 [UniversalFixResidualReporter] Loaded
2014-05-22T02:04:29.052Z,1400724269.052 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2014-05-22T02:04:29.053Z,1400724269.053 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2014-05-22T02:04:29.056Z,1400724269.056 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2014-05-22T02:04:29.131Z,1400724269.131 [VerticalControl](DEBUG): Construct VerticalControl.
2014-05-22T02:04:29.266Z,1400724269.266 [VerticalControl] Loaded
2014-05-22T02:04:29.266Z,1400724269.266 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2014-05-22T02:04:29.267Z,1400724269.267 [HorizontalControl](DEBUG): Construct HorizontalControl.
2014-05-22T02:04:29.343Z,1400724269.343 [HorizontalControl] Loaded
2014-05-22T02:04:29.343Z,1400724269.343 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2014-05-22T02:04:29.344Z,1400724269.344 [SpeedControl](DEBUG): Construct SpeedControl.
2014-05-22T02:04:29.346Z,1400724269.346 [SpeedControl] Loaded
2014-05-22T02:04:29.346Z,1400724269.346 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2014-05-22T02:04:29.347Z,1400724269.347 [LoopControl](DEBUG): Construct LoopControl.
2014-05-22T02:04:29.352Z,1400724269.352 [LoopControl] Loaded
2014-05-22T02:04:29.352Z,1400724269.352 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2014-05-22T02:04:29.353Z,1400724269.353 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2014-05-22T02:04:29.355Z,1400724269.355 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2014-05-22T02:04:29.387Z,1400724269.387 [DepthRateCalculator] Loaded
2014-05-22T02:04:29.388Z,1400724269.388 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2014-05-22T02:04:29.393Z,1400724269.393 [PitchRateCalculator] Loaded
2014-05-22T02:04:29.394Z,1400724269.394 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2014-05-22T02:04:29.401Z,1400724269.401 [SpeedCalculator] Loaded
2014-05-22T02:04:29.402Z,1400724269.402 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2014-05-22T02:04:29.423Z,1400724269.423 [TempGradientCalculator] Loaded
2014-05-22T02:04:29.424Z,1400724269.424 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2014-05-22T02:04:29.429Z,1400724269.429 [YawRateCalculator] Loaded
2014-05-22T02:04:29.430Z,1400724269.430 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2014-05-22T02:04:29.430Z,1400724269.430 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2014-05-22T02:04:29.431Z,1400724269.431 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2014-05-22T02:04:29.576Z,1400724269.576 [CTD_NeilBrown] Loaded
2014-05-22T02:04:29.577Z,1400724269.577 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2014-05-22T02:04:29.580Z,1400724269.580 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4075E4E0
2014-05-22T02:04:29.581Z,1400724269.581 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 862
2014-05-22T02:04:29.595Z,1400724269.595 [ISUS] Loaded
2014-05-22T02:04:29.595Z,1400724269.595 [ComponentRegistry](DEBUG): SyncComponent "ISUS" handled in the control thread.
2014-05-22T02:04:29.615Z,1400724269.615 [PAR_Licor] Loaded
2014-05-22T02:04:29.615Z,1400724269.615 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2014-05-22T02:04:29.656Z,1400724269.656 [WetLabsBB2FL] Loaded
2014-05-22T02:04:29.656Z,1400724269.656 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2014-05-22T02:04:29.660Z,1400724269.660 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4078E4E0
2014-05-22T02:04:29.661Z,1400724269.661 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 863
2014-05-22T02:04:29.661Z,1400724269.661 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2014-05-22T02:04:29.662Z,1400724269.662 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2014-05-22T02:04:29.796Z,1400724269.796 [SBIT](DEBUG): Construct Startup Built In Test.
2014-05-22T02:04:29.809Z,1400724269.809 [SBIT] Loaded
2014-05-22T02:04:29.809Z,1400724269.809 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2014-05-22T02:04:29.810Z,1400724269.810 [IBIT](DEBUG): Construct Initiated Built In Test.
2014-05-22T02:04:29.824Z,1400724269.824 [IBIT] Loaded
2014-05-22T02:04:29.824Z,1400724269.824 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2014-05-22T02:04:29.826Z,1400724269.826 [CBIT](DEBUG): Construct CBIT Built In Test.
2014-05-22T02:04:29.907Z,1400724269.907 [CBIT] Loaded
2014-05-22T02:04:29.907Z,1400724269.907 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2014-05-22T02:04:29.908Z,1400724269.908 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2014-05-22T02:04:29.909Z,1400724269.909 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2014-05-22T02:04:34.983Z,1400724274.983 [HFRadarModelCalc] Loaded
2014-05-22T02:04:34.983Z,1400724274.983 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2014-05-22T02:04:38.777Z,1400724278.777 [HFRadarCompactModelForecaster] Loaded
2014-05-22T02:04:38.778Z,1400724278.778 [ComponentRegistry](DEBUG): SyncComponent "HFRadarCompactModelForecaster" handled in the control thread.
2014-05-22T02:04:39.826Z,1400724279.826 [HFRCMSpaceInterpolator] Loaded
2014-05-22T02:04:39.826Z,1400724279.826 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSpaceInterpolator" handled in the control thread.
2014-05-22T02:04:39.828Z,1400724279.828 [HFRCMTimeInterpolator] Loaded
2014-05-22T02:04:39.829Z,1400724279.829 [ComponentRegistry](DEBUG): SyncComponent "HFRCMTimeInterpolator" handled in the control thread.
2014-05-22T02:04:39.842Z,1400724279.842 [HFRCMSurfaceCurrentAtVehicleLocation] Loaded
2014-05-22T02:04:39.842Z,1400724279.842 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSurfaceCurrentAtVehicleLocation" handled in the control thread.
2014-05-22T02:04:39.871Z,1400724279.871 [HFRCMVirtualSurfaceDrifter] Loaded
2014-05-22T02:04:39.871Z,1400724279.871 [ComponentRegistry](DEBUG): SyncComponent "HFRCMVirtualSurfaceDrifter" handled in the control thread.
2014-05-22T02:04:39.872Z,1400724279.872 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2014-05-22T02:04:39.873Z,1400724279.873 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2014-05-22T02:04:39.000Z,1400724280.000 [BuoyancyServo] Loaded
2014-05-22T02:04:40.000Z,1400724280.000 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2014-05-22T02:04:40.013Z,1400724280.013 [ElevatorServo] Loaded
2014-05-22T02:04:40.013Z,1400724280.013 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2014-05-22T02:04:40.026Z,1400724280.026 [MassServo] Loaded
2014-05-22T02:04:40.026Z,1400724280.026 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2014-05-22T02:04:40.038Z,1400724280.038 [RudderServo] Loaded
2014-05-22T02:04:40.039Z,1400724280.039 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2014-05-22T02:04:40.051Z,1400724280.051 [ThrusterServo] Loaded
2014-05-22T02:04:40.051Z,1400724280.051 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2014-05-22T02:04:40.052Z,1400724280.052 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2014-05-22T02:04:40.053Z,1400724280.053 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2014-05-22T02:04:40.093Z,1400724280.093 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2014-05-22T02:04:40.095Z,1400724280.095 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2014-05-22T02:04:40.096Z,1400724280.096 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2014-05-22T02:04:40.103Z,1400724280.103 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2014-05-22T02:04:40.104Z,1400724280.104 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A4F4E0
2014-05-22T02:04:40.104Z,1400724280.104 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 864
2014-05-22T02:04:40.109Z,1400724280.109 [Supervisor](INFO): Main Thread ID is 767
2014-05-22T02:04:40.109Z,1400724280.109 [Supervisor](DEBUG): Running supervisor.
2014-05-22T02:04:40.110Z,1400724280.110 [CommandLine ThreadHandler](INFO): Handler Thread ID is 865
2014-05-22T02:04:40.113Z,1400724280.113 [controlThread ThreadHandler](INFO): Handler Thread ID is 866
2014-05-22T02:04:40.113Z,1400724280.113 [controlThread](DEBUG): Initializing ControlThread
2014-05-22T02:04:40.116Z,1400724280.116 [logger ThreadHandler](INFO): Handler Thread ID is 867
2014-05-22T02:04:40.137Z,1400724280.137 [Radio_Freewave ThreadHandler](INFO): Handler Thread ID is 868
2014-05-22T02:04:40.153Z,1400724280.153 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 869
2014-05-22T02:04:40.154Z,1400724280.154 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2014-05-22T02:04:40.157Z,1400724280.157 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2014-05-22T02:04:40.167Z,1400724280.167 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 871
2014-05-22T02:04:40.168Z,1400724280.168 [WetLabsBB2FL](INFO): Powering down
2014-05-22T02:04:40.196Z,1400724280.196 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 872
2014-05-22T02:04:40.214Z,1400724280.214 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2014-05-22T02:04:40.215Z,1400724280.215 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2014-05-22T02:04:40.216Z,1400724280.216 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2014-05-22T02:04:40.216Z,1400724280.216 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2014-05-22T02:04:40.216Z,1400724280.216 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2014-05-22T02:04:40.216Z,1400724280.216 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2014-05-22T02:04:40.216Z,1400724280.216 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2014-05-22T02:04:40.217Z,1400724280.217 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2014-05-22T02:04:40.217Z,1400724280.217 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2014-05-22T02:04:42.023Z,1400724282.023 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2014-05-22T02:04:42.054Z,1400724282.054 [InternalSim](DEBUG): InternalSim initializing...
2014-05-22T02:04:42.361Z,1400724282.361 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2014-05-22T02:04:42.361Z,1400724282.361 [DeadReckonWithRespectToWater](DEBUG): Initializing DeadReckonWithRespectToWater component.
2014-05-22T02:04:42.361Z,1400724282.361 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component.
2014-05-22T02:04:42.362Z,1400724282.362 [DeadReckonUsingDVLWaterTrack](DEBUG): Initializing DeadReckonUsingDVLWaterTrack component.
2014-05-22T02:04:42.362Z,1400724282.362 [DeadReckonUsingCompactModelForecast](DEBUG): Initializing DeadReckonUsingCompactModelForecast component.
2014-05-22T02:04:42.363Z,1400724282.363 [NavChart](DEBUG): Initialize NavChart Navigation.
2014-05-22T02:04:42.363Z,1400724282.363 [UniversalFixResidualReporter](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2014-05-22T02:04:42.363Z,1400724282.363 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2014-05-22T02:04:42.380Z,1400724282.380 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2014-05-22T02:04:42.381Z,1400724282.381 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2014-05-22T02:04:42.382Z,1400724282.382 [LoopControl](DEBUG): Initialize LoopControlComponent.
2014-05-22T02:04:42.382Z,1400724282.382 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2014-05-22T02:04:42.382Z,1400724282.382 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2014-05-22T02:04:42.383Z,1400724282.383 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2014-05-22T02:04:42.383Z,1400724282.383 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2014-05-22T02:04:42.384Z,1400724282.384 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2014-05-22T02:04:42.396Z,1400724282.396 [SBIT](INFO): Initialize SBIT Component.
2014-05-22T02:04:42.397Z,1400724282.397 [SBIT](IMPORTANT): Tethys CM Info:
$Rev:11330
2014-05-22T02:04:42.397Z,1400724282.397 [SBIT](IMPORTANT): Kernel Release:2.6.27.8
2014-05-22T02:04:42.398Z,1400724282.398 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2014-05-22T02:04:42.398Z,1400724282.398 [IBIT](INFO): Initialize IBIT Component.
2014-05-22T02:04:42.399Z,1400724282.399 [CBIT](DEBUG): Initialize CBIT Component.
2014-05-22T02:04:42.399Z,1400724282.399 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2014-05-22T02:04:42.439Z,1400724282.439 [HFRadarCompactModelForecaster](DEBUG): Found new ECs!
2014-05-22T02:04:42.439Z,1400724282.439 [HFRadarCompactModelForecaster](ERROR): Most recent ECs are more than six hours old.
2014-05-22T02:04:42.866Z,1400724282.866 [Radio_Freewave](INFO): Powering up
2014-05-22T02:04:43.675Z,1400724283.675 [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-22T02:04:51.797Z,1400724291.797 [HFRadarCompactModelForecaster](IMPORTANT): Forecast time 201405212000: published 50 modes in rows, 61 hours in columns, 3050 elements.
2014-05-22T02:04:51.817Z,1400724291.817 [HFRCMSpaceInterpolator](DEBUG): Initializing HFRCMSpaceInterpolator component.
2014-05-22T02:04:51.818Z,1400724291.818 [HFRCMTimeInterpolator](DEBUG): Initializing HFRCMTimeInterpolator component.
2014-05-22T02:04:51.818Z,1400724291.818 [HFRCMSurfaceCurrentAtVehicleLocation](DEBUG): Initializing HFRCMSurfaceCurrentAtVehicleLocation component.
2014-05-22T02:04:51.827Z,1400724291.827 [HFRCMVirtualSurfaceDrifter](DEBUG): Initializing HFRCMVirtualSurfaceDrifter component.
2014-05-22T02:04:51.829Z,1400724291.829 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2014-05-22T02:04:51.875Z,1400724291.875 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2014-05-22T02:04:51.884Z,1400724291.884 [MissionManager](DEBUG):
2014-05-22T02:04:51.884Z,1400724291.884 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2014-05-22T02:04:51.946Z,1400724291.946 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2014-05-22T02:04:51.956Z,1400724291.956 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2014-05-22T02:04:51.976Z,1400724291.976 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-05-22T02:04:51.993Z,1400724291.993 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2014-05-22T02:04:51.996Z,1400724291.996 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-05-22T02:04:52.032Z,1400724292.032 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2014-05-22T02:04:52.058Z,1400724292.058 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Construct.
2014-05-22T02:04:52.061Z,1400724292.061 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-05-22T02:04:52.078Z,1400724292.078 [MissionManager](DEBUG):
400
400
Burn 300
Dropped drop weight due to communications timeout
5.0
1.0
5
2014-05-22T02:04:52.098Z,1400724292.098 [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-22T02:04:52.260Z,1400724292.260 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2014-05-22T02:04:53.088Z,1400724293.088 [DVL_micro](INFO): Initializing
2014-05-22T02:04:53.128Z,1400724293.128 [NAL9602](INFO): Powering up NAL9602
2014-05-22T02:04:53.801Z,1400724293.801 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2014-05-22T02:04:53.802Z,1400724293.802 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2014-05-22T02:04:53.834Z,1400724293.834 [ElevatorServo](DEBUG): Initializing EZServoServo.
2014-05-22T02:04:53.843Z,1400724293.843 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2014-05-22T02:04:53.858Z,1400724293.858 [MassServo](DEBUG): Initializing EZServoServo.
2014-05-22T02:04:53.866Z,1400724293.866 [MassServo](DEBUG): Initializing MassServo.
2014-05-22T02:04:53.888Z,1400724293.888 [RudderServo](DEBUG): Initializing EZServoServo.
2014-05-22T02:04:53.894Z,1400724293.894 [RudderServo](DEBUG): Initializing RudderServo.
2014-05-22T02:04:53.908Z,1400724293.908 [ThrusterServo](DEBUG): Initializing EZServoServo.
2014-05-22T02:04:53.914Z,1400724293.914 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2014-05-22T02:04:54.683Z,1400724294.683 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2014-05-22T02:04:54.683Z,1400724294.683 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2014-05-22T02:04:54.684Z,1400724294.684 [BuoyancyServo] Communications Fault, FailCount= 1
2014-05-22T02:04:54.684Z,1400724294.684 [BuoyancyServo](ERROR): Communications Fault
2014-05-22T02:04:54.927Z,1400724294.927 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2014-05-22T02:04:55.362Z,1400724295.362 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2014-05-22T02:04:55.362Z,1400724295.362 [BuoyancyServo](INFO): Powering down
2014-05-22T02:04:57.611Z,1400724297.611 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2014-05-22T02:04:57.611Z,1400724297.611 [BuoyancyServo] No Fault, FailCount= 1
2014-05-22T02:04:58.132Z,1400724298.132 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2014-05-22T02:04:58.250Z,1400724298.250 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2014-05-22T02:04:58.615Z,1400724298.615 [SBIT](IMPORTANT): Beginning Startup BIT
2014-05-22T02:04:58.617Z,1400724298.617 [CBIT](IMPORTANT): Beginning GF scan
2014-05-22T02:05:04.459Z,1400724304.459 [NAL9602](INFO): NAL9602 initialized
2014-05-22T02:05:07.256Z,1400724307.256 [CommandLine](IMPORTANT): got command quit
2014-05-22T02:05:08.263Z,1400724308.263 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-22T02:05:08.264Z,1400724308.264 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-05-22T02:05:08.280Z,1400724308.280 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2014-05-22T02:05:08.281Z,1400724308.281 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-05-22T02:05:08.281Z,1400724308.281 [CommandLine](INFO): Join timeout helper Thread ID is 888
2014-05-22T02:05:08.293Z,1400724308.293 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2014-05-22T02:05:08.293Z,1400724308.293 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-05-22T02:05:08.293Z,1400724308.293 [NavChartDb](INFO): Join timeout helper Thread ID is 889
2014-05-22T02:05:09.144Z,1400724309.144 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-22T02:05:09.144Z,1400724309.144 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-05-22T02:05:09.154Z,1400724309.154 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2014-05-22T02:05:09.154Z,1400724309.154 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-05-22T02:05:09.154Z,1400724309.154 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 890
2014-05-22T02:05:09.386Z,1400724309.386 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-22T02:05:09.387Z,1400724309.387 [WetLabsBB2FL](INFO): Powering down
2014-05-22T02:05:09.387Z,1400724309.387 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-05-22T02:05:09.388Z,1400724309.388 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2014-05-22T02:05:09.388Z,1400724309.388 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-05-22T02:05:09.389Z,1400724309.389 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 891
2014-05-22T02:05:09.391Z,1400724309.391 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-22T02:05:09.391Z,1400724309.391 [CTD_NeilBrown](INFO): Powering down
2014-05-22T02:05:09.392Z,1400724309.392 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-05-22T02:05:09.410Z,1400724309.410 [ComponentRegistry](INFO): Shutting down Radio_Freewave ThreadHandler
2014-05-22T02:05:09.410Z,1400724309.410 [Radio_Freewave ThreadHandler](INFO): Thread cancelled.
2014-05-22T02:05:09.411Z,1400724309.411 [Radio_Freewave](INFO): Join timeout helper Thread ID is 892
2014-05-22T02:05:09.791Z,1400724309.791 [Radio_Freewave ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-22T02:05:09.889Z,1400724309.889 [Radio_Freewave](INFO): Powering down
2014-05-22T02:05:10.292Z,1400724310.292 [Radio_Freewave ThreadHandler](INFO): Thread cancelled.
2014-05-22T02:05:10.307Z,1400724310.307 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2014-05-22T02:05:10.307Z,1400724310.307 [logger ThreadHandler](INFO): Thread cancelled.
2014-05-22T02:05:10.307Z,1400724310.307 [logger](INFO): Join timeout helper Thread ID is 894
2014-05-22T02:05:10.308Z,1400724310.308 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-22T02:05:10.308Z,1400724310.308 [logger ThreadHandler](INFO): Thread cancelled.
2014-05-22T02:05:10.309Z,1400724310.309 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2014-05-22T02:05:10.309Z,1400724310.309 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-05-22T02:05:10.310Z,1400724310.310 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2014-05-22T02:05:10.310Z,1400724310.310 [controlThread ThreadHandler](INFO): Thread cancelled.
2014-05-22T02:05:10.310Z,1400724310.310 [controlThread](INFO): Join timeout helper Thread ID is 895
2014-05-22T02:05:10.470Z,1400724310.470 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-22T02:05:10.470Z,1400724310.470 [controlThread](DEBUG): Uninitializing ControlThread
2014-05-22T02:05:10.470Z,1400724310.470 [AHRS_sp3003D](INFO): Powering down
2014-05-22T02:05:10.628Z,1400724310.628 [DVL_micro](INFO): uninitialize:Powering down
2014-05-22T02:05:10.629Z,1400724310.629 [NAL9602](INFO): Powering down
2014-05-22T02:05:10.632Z,1400724310.632 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2014-05-22T02:05:10.635Z,1400724310.635 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2014-05-22T02:05:10.641Z,1400724310.641 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2014-05-22T02:05:10.641Z,1400724310.641 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2014-05-22T02:05:10.641Z,1400724310.641 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2014-05-22T02:05:10.641Z,1400724310.641 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2014-05-22T02:05:10.642Z,1400724310.642 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2014-05-22T02:05:10.642Z,1400724310.642 [BuoyancyServo](INFO): Powering down
2014-05-22T02:05:10.656Z,1400724310.656 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2014-05-22T02:05:10.656Z,1400724310.656 [ElevatorServo](INFO): Powering down
2014-05-22T02:05:10.657Z,1400724310.657 [MassServo](DEBUG): Uninitialize Mass Servo.
2014-05-22T02:05:10.657Z,1400724310.657 [MassServo](INFO): Powering down
2014-05-22T02:05:10.658Z,1400724310.658 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2014-05-22T02:05:10.658Z,1400724310.658 [RudderServo](INFO): Powering down
2014-05-22T02:05:10.659Z,1400724310.659 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2014-05-22T02:05:10.659Z,1400724310.659 [ThrusterServo](INFO): Powering down
2014-05-22T02:05:10.660Z,1400724310.660 [SBIT](DEBUG): Uninitialize SBIT Component.
2014-05-22T02:05:10.661Z,1400724310.661 [IBIT](DEBUG): Uninitialize IBIT Component.
2014-05-22T02:05:10.661Z,1400724310.661 [CBIT](DEBUG): Uninitialize CBIT Component.
2014-05-22T02:05:10.704Z,1400724310.704 [controlThread ThreadHandler](INFO): Thread cancelled.
2014-05-22T02:05:10.707Z,1400724310.707 [Radio_Freewave ThreadHandler](INFO): Thread cancelled.
2014-05-22T02:05:10.787Z,1400724310.787 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-05-22T02:05:10.790Z,1400724310.790 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-05-22T02:05:10.839Z,1400724310.839 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-05-22T02:05:10.872Z,1400724310.872 [logger ThreadHandler](INFO): Thread cancelled.