2012-12-05T17:51:14.281Z,1354729874.281 [Supervisor](DEBUG): Initializing supervisor. 2012-12-05T17:51:14.283Z,1354729874.283 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0 2012-12-05T17:51:14.284Z,1354729874.284 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2012-12-05T17:51:14.285Z,1354729874.285 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0 2012-12-05T17:51:14.289Z,1354729874.289 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2012-12-05T17:51:14.299Z,1354729874.299 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2012-12-05T17:51:14.300Z,1354729874.300 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0 2012-12-05T17:51:14.301Z,1354729874.301 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2012-12-05T17:51:14.302Z,1354729874.302 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0 2012-12-05T17:51:14.303Z,1354729874.303 [Supervisor](INFO): Looking for Config files in directory: Config/ 2012-12-05T17:51:14.304Z,1354729874.304 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2012-12-05T17:51:14.577Z,1354729874.577 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2012-12-05T17:51:14.578Z,1354729874.578 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2012-12-05T17:51:14.762Z,1354729874.762 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2012-12-05T17:51:14.762Z,1354729874.762 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2012-12-05T17:51:14.846Z,1354729874.846 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2012-12-05T17:51:14.847Z,1354729874.847 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2012-12-05T17:51:15.039Z,1354729875.039 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2012-12-05T17:51:15.040Z,1354729875.040 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2012-12-05T17:51:15.170Z,1354729875.171 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2012-12-05T17:51:15.171Z,1354729875.171 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2012-12-05T17:51:15.396Z,1354729875.396 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2012-12-05T17:51:15.397Z,1354729875.397 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2012-12-05T17:51:15.565Z,1354729875.565 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2012-12-05T17:51:15.566Z,1354729875.566 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2012-12-05T17:51:15.813Z,1354729875.813 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2012-12-05T17:51:15.813Z,1354729875.813 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2012-12-05T17:51:15.910Z,1354729875.910 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2012-12-05T17:51:15.911Z,1354729875.911 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2012-12-05T17:51:16.303Z,1354729876.303 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2012-12-05T17:51:16.304Z,1354729876.304 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2012-12-05T17:51:16.417Z,1354729876.417 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2012-12-05T17:51:16.417Z,1354729876.417 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2012-12-05T17:51:16.502Z,1354729876.502 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2012-12-05T17:51:16.502Z,1354729876.503 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2012-12-05T17:51:16.602Z,1354729876.602 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2012-12-05T17:51:16.728Z,1354729876.728 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2012-12-05T17:51:16.812Z,1354729876.812 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2012-12-05T17:51:16.912Z,1354729876.912 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2012-12-05T17:51:17.011Z,1354729877.011 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2012-12-05T17:51:17.128Z,1354729877.128 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2012-12-05T17:51:17.219Z,1354729877.219 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2012-12-05T17:51:17.305Z,1354729877.305 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2012-12-05T17:51:17.342Z,1354729877.342 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2012-12-05T17:51:17.516Z,1354729877.516 [InternalSim] Loaded 2012-12-05T17:51:17.516Z,1354729877.516 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread. 2012-12-05T17:51:17.517Z,1354729877.517 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2012-12-05T17:51:17.518Z,1354729877.518 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2012-12-05T17:51:17.573Z,1354729877.573 [SBIT](DEBUG): Construct Startup Built In Test. 2012-12-05T17:51:17.601Z,1354729877.601 [SBIT] Loaded 2012-12-05T17:51:17.601Z,1354729877.601 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2012-12-05T17:51:17.603Z,1354729877.602 [IBIT](DEBUG): Construct Initiated Built In Test. 2012-12-05T17:51:17.631Z,1354729877.631 [IBIT] Loaded 2012-12-05T17:51:17.631Z,1354729877.631 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2012-12-05T17:51:17.634Z,1354729877.634 [CBIT](DEBUG): Construct CBIT Built In Test. 2012-12-05T17:51:17.752Z,1354729877.752 [CBIT] Loaded 2012-12-05T17:51:17.752Z,1354729877.752 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2012-12-05T17:51:17.752Z,1354729877.753 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2012-12-05T17:51:17.753Z,1354729877.753 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2012-12-05T17:51:17.899Z,1354729877.898 [BuoyancyServo] Loaded 2012-12-05T17:51:17.899Z,1354729877.899 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2012-12-05T17:51:17.911Z,1354729877.911 [ElevatorServo] Loaded 2012-12-05T17:51:17.911Z,1354729877.911 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2012-12-05T17:51:17.923Z,1354729877.923 [MassServo] Loaded 2012-12-05T17:51:17.923Z,1354729877.923 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2012-12-05T17:51:17.935Z,1354729877.935 [RudderServo] Loaded 2012-12-05T17:51:17.935Z,1354729877.935 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2012-12-05T17:51:17.947Z,1354729877.947 [ThrusterServo] Loaded 2012-12-05T17:51:17.947Z,1354729877.947 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2012-12-05T17:51:17.948Z,1354729877.948 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2012-12-05T17:51:17.948Z,1354729877.948 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2012-12-05T17:51:17.965Z,1354729877.965 [DepthRateCalculator] Loaded 2012-12-05T17:51:17.965Z,1354729877.965 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2012-12-05T17:51:21.018Z,1354729881.018 [HFRadarModelCalc] Loaded 2012-12-05T17:51:21.018Z,1354729881.018 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread. 2012-12-05T17:51:21.034Z,1354729881.034 [NavChart] Loaded 2012-12-05T17:51:21.034Z,1354729881.034 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2012-12-05T17:51:21.040Z,1354729881.040 [PitchRateCalculator] Loaded 2012-12-05T17:51:21.041Z,1354729881.041 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2012-12-05T17:51:21.047Z,1354729881.047 [SpeedCalculator] Loaded 2012-12-05T17:51:21.047Z,1354729881.047 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2012-12-05T17:51:21.062Z,1354729881.062 [TempGradientCalculator] Loaded 2012-12-05T17:51:21.062Z,1354729881.062 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2012-12-05T17:51:21.068Z,1354729881.068 [YawRateCalculator] Loaded 2012-12-05T17:51:21.068Z,1354729881.068 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2012-12-05T17:51:21.108Z,1354729881.108 [Navigation] Loaded 2012-12-05T17:51:21.108Z,1354729881.108 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread. 2012-12-05T17:51:21.108Z,1354729881.108 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2012-12-05T17:51:21.109Z,1354729881.109 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2012-12-05T17:51:21.322Z,1354729881.322 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2012-12-05T17:51:21.323Z,1354729881.323 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2012-12-05T17:51:21.344Z,1354729881.344 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2012-12-05T17:51:21.345Z,1354729881.345 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2012-12-05T17:51:21.384Z,1354729881.384 [VerticalControl](DEBUG): Construct VerticalControl. 2012-12-05T17:51:21.477Z,1354729881.477 [VerticalControl] Loaded 2012-12-05T17:51:21.477Z,1354729881.477 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2012-12-05T17:51:21.478Z,1354729881.478 [HorizontalControl](DEBUG): Construct HorizontalControl. 2012-12-05T17:51:21.534Z,1354729881.534 [HorizontalControl] Loaded 2012-12-05T17:51:21.534Z,1354729881.534 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2012-12-05T17:51:21.535Z,1354729881.535 [SpeedControl](DEBUG): Construct SpeedControl. 2012-12-05T17:51:21.537Z,1354729881.537 [SpeedControl] Loaded 2012-12-05T17:51:21.537Z,1354729881.537 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2012-12-05T17:51:21.538Z,1354729881.538 [LoopControl](DEBUG): Construct LoopControl. 2012-12-05T17:51:21.539Z,1354729881.539 [LoopControl] Loaded 2012-12-05T17:51:21.539Z,1354729881.539 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2012-12-05T17:51:21.539Z,1354729881.539 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2012-12-05T17:51:21.540Z,1354729881.540 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2012-12-05T17:51:21.545Z,1354729881.545 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator. 2012-12-05T17:51:21.550Z,1354729881.550 [AsyncPiEstimator] Loaded 2012-12-05T17:51:21.550Z,1354729881.550 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread. 2012-12-05T17:51:21.551Z,1354729881.551 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406A14E0 2012-12-05T17:51:21.552Z,1354729881.552 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2012-12-05T17:51:21.553Z,1354729881.553 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2012-12-05T17:51:21.675Z,1354729881.675 [AHRS_sp3003D] Loaded 2012-12-05T17:51:21.675Z,1354729881.675 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread. 2012-12-05T17:51:21.931Z,1354729881.931 [Batt_Ocean_Server] Loaded 2012-12-05T17:51:21.931Z,1354729881.931 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread. 2012-12-05T17:51:21.944Z,1354729881.944 [Depth_Keller] Loaded 2012-12-05T17:51:21.945Z,1354729881.944 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2012-12-05T17:51:21.950Z,1354729881.950 [DropWeight] Loaded 2012-12-05T17:51:21.950Z,1354729881.950 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2012-12-05T17:51:22.109Z,1354729882.109 [DVL_micro] Loaded 2012-12-05T17:51:22.109Z,1354729882.109 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread. 2012-12-05T17:51:22.111Z,1354729882.111 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 407234E0 2012-12-05T17:51:22.192Z,1354729882.192 [NAL9602] Loaded 2012-12-05T17:51:22.193Z,1354729882.193 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2012-12-05T17:51:22.242Z,1354729882.242 [Onboard] Loaded 2012-12-05T17:51:22.243Z,1354729882.243 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2012-12-05T17:51:22.249Z,1354729882.249 [Radio_Freewave] Loaded 2012-12-05T17:51:22.249Z,1354729882.249 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread. 2012-12-05T17:51:22.250Z,1354729882.250 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2012-12-05T17:51:22.251Z,1354729882.251 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2012-12-05T17:51:22.323Z,1354729882.323 [CTD_NeilBrown] Loaded 2012-12-05T17:51:22.323Z,1354729882.323 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2012-12-05T17:51:22.324Z,1354729882.324 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4077C4E0 2012-12-05T17:51:22.341Z,1354729882.341 [PAR_Licor] Loaded 2012-12-05T17:51:22.341Z,1354729882.341 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2012-12-05T17:51:22.393Z,1354729882.393 [Turbulence_NPS] Loaded 2012-12-05T17:51:22.393Z,1354729882.393 [ComponentRegistry](DEBUG): Component "Turbulence_NPS" handled in its own thread. 2012-12-05T17:51:22.394Z,1354729882.394 [Turbulence_NPS ThreadHandler](DEBUG): Created PCaller Thread at 407AC4E0 2012-12-05T17:51:22.424Z,1354729882.424 [WetLabsBB2FL] Loaded 2012-12-05T17:51:22.424Z,1354729882.424 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2012-12-05T17:51:22.425Z,1354729882.425 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407DC4E0 2012-12-05T17:51:22.426Z,1354729882.426 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2012-12-05T17:51:22.430Z,1354729882.430 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2012-12-05T17:51:22.433Z,1354729882.433 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2012-12-05T17:51:22.439Z,1354729882.439 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2012-12-05T17:51:22.440Z,1354729882.440 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 4080C4E0 2012-12-05T17:51:22.445Z,1354729882.445 [Supervisor](DEBUG): Running supervisor. 2012-12-05T17:51:22.446Z,1354729882.446 [CommandLine](INFO): Thread ID is 9810 2012-12-05T17:51:22.448Z,1354729882.448 [controlThread](INFO): Thread ID is 9809 2012-12-05T17:51:22.449Z,1354729882.448 [controlThread](DEBUG): Initializing ControlThread 2012-12-05T17:51:22.449Z,1354729882.449 [CycleStarter](INFO): Thread ID is 9808 2012-12-05T17:51:22.449Z,1354729882.450 [InternalSim](DEBUG): InternalSim initializing... 2012-12-05T17:51:22.483Z,1354729882.483 [logger](INFO): Thread ID is 9811 2012-12-05T17:51:22.510Z,1354729882.510 [SBIT](INFO): Initialize SBIT Component. 2012-12-05T17:51:22.510Z,1354729882.510 [SBIT](IMPORTANT): Tethys CM Info: $Rev: 10092 2012-12-05T17:51:22.511Z,1354729882.511 [IBIT](INFO): Initialize IBIT Component. 2012-12-05T17:51:22.512Z,1354729882.512 [CBIT](DEBUG): Initialize CBIT Component. 2012-12-05T17:51:22.512Z,1354729882.512 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2012-12-05T17:51:22.523Z,1354729882.523 [AsyncPiEstimator](INFO): Thread ID is 9872 2012-12-05T17:51:22.523Z,1354729882.523 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator. 2012-12-05T17:51:22.539Z,1354729882.539 [DVL_micro](INFO): Thread ID is 9873 2012-12-05T17:51:22.544Z,1354729882.544 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2012-12-05T17:51:22.544Z,1354729882.544 [NavChart](DEBUG): Initialize NavChart Derivation. 2012-12-05T17:51:22.545Z,1354729882.545 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2012-12-05T17:51:22.545Z,1354729882.545 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2012-12-05T17:51:22.545Z,1354729882.545 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2012-12-05T17:51:22.547Z,1354729882.547 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2012-12-05T17:51:22.548Z,1354729882.547 [Navigation](DEBUG): Initializing Navigation. 2012-12-05T17:51:22.548Z,1354729882.548 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2012-12-05T17:51:22.550Z,1354729882.550 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2012-12-05T17:51:22.550Z,1354729882.550 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2012-12-05T17:51:22.551Z,1354729882.551 [LoopControl](DEBUG): Initialize LoopControlComponent. 2012-12-05T17:51:22.559Z,1354729882.559 [DVL_micro](INFO): Initializing 2012-12-05T17:51:22.559Z,1354729882.559 [DVL_micro](INFO): start:Powering up 2012-12-05T17:51:22.560Z,1354729882.560 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2012-12-05T17:51:22.561Z,1354729882.561 [DVL_micro](INFO): Cycling power to configure device. 2012-12-05T17:51:22.580Z,1354729882.580 [CTD_NeilBrown](INFO): Thread ID is 9874 2012-12-05T17:51:22.580Z,1354729882.580 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown. 2012-12-05T17:51:22.583Z,1354729882.583 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4 2012-12-05T17:51:22.590Z,1354729882.590 [Turbulence_NPS](INFO): Thread ID is 9875 2012-12-05T17:51:22.590Z,1354729882.590 [Turbulence_NPS](DEBUG): Initializing Turbulence_NPS. 2012-12-05T17:51:22.591Z,1354729882.591 [Turbulence_NPS](INFO): Opening uart, block timeout 10ths=1 2012-12-05T17:51:22.620Z,1354729882.620 [WetLabsBB2FL](INFO): Thread ID is 9876 2012-12-05T17:51:22.620Z,1354729882.620 [WetLabsBB2FL](INFO): Powering down 2012-12-05T17:51:22.646Z,1354729882.645 [NavChartDb](INFO): Thread ID is 9877 2012-12-05T17:51:22.648Z,1354729882.648 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources 2012-12-05T17:51:22.648Z,1354729882.648 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2012-12-05T17:51:22.649Z,1354729882.649 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2012-12-05T17:51:22.649Z,1354729882.649 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2012-12-05T17:51:22.649Z,1354729882.649 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2012-12-05T17:51:22.687Z,1354729882.687 [Turbulence_NPS](INFO): Pause powering down 2012-12-05T17:51:24.346Z,1354729884.346 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized 2012-12-05T17:51:24.379Z,1354729884.379 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2012-12-05T17:51:24.410Z,1354729884.410 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2012-12-05T17:51:24.440Z,1354729884.440 [MissionManager](DEBUG): 2012-12-05T17:51:24.441Z,1354729884.441 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2012-12-05T17:51:24.518Z,1354729884.518 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool 2012-12-05T17:51:24.536Z,1354729884.536 [Default:GPS:A.SetSpeed](DEBUG): Construct. 2012-12-05T17:51:24.539Z,1354729884.539 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface. 2012-12-05T17:51:24.555Z,1354729884.555 [Default:Iridium:A.SetSpeed](DEBUG): Construct. 2012-12-05T17:51:24.558Z,1354729884.558 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface. 2012-12-05T17:51:24.576Z,1354729884.576 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2012-12-05T17:51:24.584Z,1354729884.584 [Default:D.SetSpeed](DEBUG): Construct. 2012-12-05T17:51:24.620Z,1354729884.620 [Default:E.GoToSurface](DEBUG): Construct GoToSurface. 2012-12-05T17:51:24.624Z,1354729884.624 [Default:F.Wait](DEBUG): Construct Wait. 2012-12-05T17:51:24.627Z,1354729884.627 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2012-12-05T17:51:24.627Z,1354729884.627 [DVL_micro](INFO): Querying output modes 2012-12-05T17:51:24.627Z,1354729884.628 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606 2012-12-05T17:51:24.638Z,1354729884.638 [DVL_micro](DEBUG): cmdResponse: 01 2012-12-05T17:51:24.639Z,1354729884.639 [DVL_micro](INFO): NQ1 output enabled 2012-12-05T17:51:24.639Z,1354729884.639 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525 2012-12-05T17:51:24.643Z,1354729884.643 [MissionManager](DEBUG): 400 400 Burn 300 Dropped drop weight due to communications timeout 5.0 1.0 5 2012-12-05T17:51:24.647Z,1354729884.647 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,NAL9602,Onboard,Radio_Freewave,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter, 2012-12-05T17:51:24.651Z,1354729884.651 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 2012-12-05T17:51:24.668Z,1354729884.668 [DVL_micro](INFO): pause:Powering down 2012-12-05T17:51:24.715Z,1354729884.715 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2012-12-05T17:51:24.919Z,1354729884.919 [Radio_Freewave](INFO): Powering up 2012-12-05T17:51:25.138Z,1354729885.138 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2012-12-05T17:51:25.147Z,1354729885.147 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2012-12-05T17:51:25.165Z,1354729885.165 [ElevatorServo](DEBUG): Initializing EZServoServo. 2012-12-05T17:51:25.171Z,1354729885.171 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2012-12-05T17:51:25.177Z,1354729885.177 [MassServo](DEBUG): Initializing EZServoServo. 2012-12-05T17:51:25.183Z,1354729885.183 [MassServo](DEBUG): Initializing MassServo. 2012-12-05T17:51:25.204Z,1354729885.204 [RudderServo](DEBUG): Initializing EZServoServo. 2012-12-05T17:51:25.211Z,1354729885.211 [RudderServo](DEBUG): Initializing RudderServo. 2012-12-05T17:51:25.225Z,1354729885.224 [ThrusterServo](DEBUG): Initializing EZServoServo. 2012-12-05T17:51:25.235Z,1354729885.235 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2012-12-05T17:51:25.431Z,1354729885.431 [AHRS_sp3003D](ERROR): readHeadingMagBin got 0x42360D0AA4 2012-12-05T17:51:25.431Z,1354729885.431 [AHRS_sp3003D](ERROR): SP3003D failed to initialize 2012-12-05T17:51:25.431Z,1354729885.431 [AHRS_sp3003D] Hardware Fault, FailCount= 1 2012-12-05T17:51:25.431Z,1354729885.431 [AHRS_sp3003D](ERROR): Hardware Fault 2012-12-05T17:51:25.476Z,1354729885.476 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2012-12-05T17:51:25.476Z,1354729885.476 [DVL_micro](INFO): resume:Powering up 2012-12-05T17:51:25.476Z,1354729885.476 [DVL_micro](INFO): Cycling power to configure device. 2012-12-05T17:51:25.540Z,1354729885.540 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D 2012-12-05T17:51:25.725Z,1354729885.725 [AHRS_sp3003D](INFO): Powering down 2012-12-05T17:51:26.141Z,1354729886.141 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D 2012-12-05T17:51:26.141Z,1354729886.141 [AHRS_sp3003D] No Fault, FailCount= 1 2012-12-05T17:51:26.958Z,1354729886.958 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2012-12-05T17:51:27.406Z,1354729887.406 [NAL9602](INFO): Powering up NAL9602 2012-12-05T17:51:27.483Z,1354729887.483 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2012-12-05T17:51:27.483Z,1354729887.483 [DVL_micro](INFO): Querying output modes 2012-12-05T17:51:27.483Z,1354729887.483 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606 2012-12-05T17:51:27.495Z,1354729887.495 [DVL_micro](DEBUG): cmdResponse: 01 2012-12-05T17:51:27.495Z,1354729887.495 [DVL_micro](INFO): NQ1 output enabled 2012-12-05T17:51:27.495Z,1354729887.495 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525 2012-12-05T17:51:27.507Z,1354729887.507 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 2012-12-05T17:51:27.509Z,1354729887.509 [DVL_micro](INFO): pause:Powering down 2012-12-05T17:51:37.947Z,1354729897.947 [NAL9602](INFO): NAL9602 initialized 2012-12-05T17:51:38.048Z,1354729898.048 [SBIT](IMPORTANT): Beginning Startup BIT 2012-12-05T17:51:38.051Z,1354729898.051 [CBIT](IMPORTANT): Beginning GF scan 2012-12-05T17:51:46.803Z,1354729906.803 [CommandLine](IMPORTANT): got command maintain control SpeedControl.propOmegaAction 640.000000 revolution_per_minute 2012-12-05T17:51:46.805Z,1354729906.805 [ComponentRegistry](DEBUG): SyncComponent "Maintain_SpeedControl.propOmegaAction" handled in the control thread. 2012-12-05T17:51:46.967Z,1354729906.967 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,NAL9602,Onboard,Radio_Freewave,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_SpeedControl.propOmegaAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter, 2012-12-05T17:51:57.179Z,1354729917.179 [ThrusterServo](FAULT): Overload Error 2012-12-05T17:51:57.179Z,1354729917.179 [ThrusterServo] Hardware Fault, FailCount= 1 2012-12-05T17:51:57.179Z,1354729917.179 [ThrusterServo](ERROR): Hardware Fault 2012-12-05T17:51:57.182Z,1354729917.182 [CBIT](ERROR): Hardware Fault in component: ThrusterServo 2012-12-05T17:51:57.551Z,1354729917.551 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2012-12-05T17:51:57.552Z,1354729917.552 [ThrusterServo](INFO): Powering down 2012-12-05T17:51:57.555Z,1354729917.555 [CBIT](INFO): Clearing failed state for component ThrusterServo 2012-12-05T17:51:57.555Z,1354729917.555 [ThrusterServo] No Fault, FailCount= 1 2012-12-05T17:51:58.363Z,1354729918.363 [ThrusterServo](DEBUG): Initializing EZServoServo. 2012-12-05T17:51:58.484Z,1354729918.484 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2012-12-05T17:52:02.590Z,1354729922.590 [CommandLine](IMPORTANT): got command maintain control SpeedControl.propOmegaAction 630.000000 revolution_per_minute 2012-12-05T17:52:04.846Z,1354729924.846 [CBIT](IMPORTANT): No ground fault detected 2012-12-05T17:52:18.667Z,1354729938.667 [CommandLine](IMPORTANT): got command maintain control SpeedControl.propOmegaAction 636.000000 revolution_per_minute 2012-12-05T17:52:25.511Z,1354729945.510 [ThrusterServo](FAULT): Overload Error 2012-12-05T17:52:25.511Z,1354729945.511 [ThrusterServo] Hardware Fault, FailCount= 1 2012-12-05T17:52:25.511Z,1354729945.511 [ThrusterServo](ERROR): Hardware Fault 2012-12-05T17:52:25.514Z,1354729945.514 [CBIT](ERROR): Hardware Fault in component: ThrusterServo 2012-12-05T17:52:25.916Z,1354729945.916 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2012-12-05T17:52:25.916Z,1354729945.916 [ThrusterServo](INFO): Powering down 2012-12-05T17:52:25.919Z,1354729945.919 [CBIT](INFO): Clearing failed state for component ThrusterServo 2012-12-05T17:52:25.919Z,1354729945.920 [ThrusterServo] No Fault, FailCount= 1 2012-12-05T17:52:26.636Z,1354729946.636 [ThrusterServo](DEBUG): Initializing EZServoServo. 2012-12-05T17:52:26.756Z,1354729946.756 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2012-12-05T17:52:31.867Z,1354729951.867 [SBIT](IMPORTANT): SBIT PASSED 2012-12-05T17:52:32.206Z,1354729952.206 [MissionManager](IMPORTANT): Started mission Startup 2012-12-05T17:52:32.207Z,1354729952.207 [Startup] Running Loop=1 2012-12-05T17:52:32.207Z,1354729952.207 [Startup](INFO): Aggregate::initialize Startup 2012-12-05T17:52:32.207Z,1354729952.207 [Startup:A.GoToSurface] Running Loop=1 2012-12-05T17:52:32.207Z,1354729952.207 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-12-05T17:52:32.213Z,1354729952.213 [Startup:StartupSatComms] Running Loop=1 2012-12-05T17:52:32.213Z,1354729952.213 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms 2012-12-05T17:52:32.213Z,1354729952.213 [Startup:StartupSatComms:A] Running Loop=1 2012-12-05T17:52:32.607Z,1354729952.607 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2012-12-05T17:52:37.547Z,1354729957.547 [CommandLine](IMPORTANT): got command show variable thruster 2012-12-05T17:52:37.557Z,1354729957.557 [CommandLine](INFO): Config/vehicle.ThrusterServo_card (none) 2012-12-05T17:52:37.558Z,1354729957.558 [CommandLine](INFO): Config/vehicle.ThrusterServo_uart (none) 2012-12-05T17:52:37.558Z,1354729957.558 [CommandLine](INFO): Config/vehicle.ThrusterServo_baud (bit_per_second) 2012-12-05T17:52:37.570Z,1354729957.569 [CommandLine](INFO): Config/Servo.ThrusterServo_enable (bool) 2012-12-05T17:52:37.570Z,1354729957.570 [CommandLine](INFO): Config/Servo.ThrusterServo_useHardware (bool) 2012-12-05T17:52:37.571Z,1354729957.571 [CommandLine](INFO): ThrusterServo.powerOnTimeout (second) 2012-12-05T17:52:37.572Z,1354729957.572 [CommandLine](INFO): ThrusterServo.currLimit (percent) 2012-12-05T17:52:37.572Z,1354729957.572 [CommandLine](INFO): ThrusterServo.pidW (count) 2012-12-05T17:52:37.572Z,1354729957.572 [CommandLine](INFO): ThrusterServo.pidX (count) 2012-12-05T17:52:37.573Z,1354729957.573 [CommandLine](INFO): ThrusterServo.pidY (count) 2012-12-05T17:52:37.573Z,1354729957.573 [CommandLine](INFO): ThrusterServo.overloadTimeout (millisecond) 2012-12-05T17:52:37.573Z,1354729957.573 [CommandLine](INFO): ThrusterServo.accel (none) 2012-12-05T17:52:37.574Z,1354729957.574 [CommandLine](INFO): ThrusterServo.encoderTks (count_per_second) 2012-12-05T17:52:37.574Z,1354729957.574 [CommandLine](INFO): ThrusterServo.tksPerRev (count_per_revolution) 2012-12-05T17:52:37.575Z,1354729957.575 [CommandLine](INFO): ThrusterServo.deviation (count) 2012-12-05T17:52:37.575Z,1354729957.575 [CommandLine](INFO): ThrusterServo.allowableBadVelocity (count) 2012-12-05T17:52:37.636Z,1354729957.636 [CommandLine](INFO): ThrusterServo.platform_propeller_rotation_rate (radian_per_second) 2012-12-05T17:52:37.662Z,1354729957.662 [CommandLine](INFO): ThrusterServo.durationOfLastRun (second) 2012-12-05T17:52:37.664Z,1354729957.664 [CommandLine](INFO): ThrusterServo.component_voltage (volt) 2012-12-05T17:52:37.664Z,1354729957.664 [CommandLine](INFO): ThrusterServo.component_avgVoltage (volt) 2012-12-05T17:52:37.665Z,1354729957.665 [CommandLine](INFO): ThrusterServo.component_current (milliampere) 2012-12-05T17:52:37.665Z,1354729957.665 [CommandLine](INFO): ThrusterServo.component_avgCurrent (milliampere) 2012-12-05T17:52:42.301Z,1354729962.300 [ThrusterServo](FAULT): Overload Error 2012-12-05T17:52:42.301Z,1354729962.301 [ThrusterServo] Hardware Fault, FailCount= 1 2012-12-05T17:52:42.301Z,1354729962.301 [ThrusterServo](ERROR): Hardware Fault 2012-12-05T17:52:42.303Z,1354729962.303 [CBIT](ERROR): Hardware Fault in component: ThrusterServo 2012-12-05T17:52:42.660Z,1354729962.660 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2012-12-05T17:52:42.660Z,1354729962.660 [ThrusterServo](INFO): Powering down 2012-12-05T17:52:42.663Z,1354729962.662 [CBIT](INFO): Clearing failed state for component ThrusterServo 2012-12-05T17:52:42.663Z,1354729962.663 [ThrusterServo] No Fault, FailCount= 1 2012-12-05T17:52:43.480Z,1354729963.480 [ThrusterServo](DEBUG): Initializing EZServoServo. 2012-12-05T17:52:43.597Z,1354729963.597 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2012-12-05T17:52:45.439Z,1354729965.439 [CommandLine](IMPORTANT): got command report mod ThrusterServo.component_current 2012-12-05T17:52:45.463Z,1354729965.463 [Reporter](INFO): ThrusterServo.component_current no_value 2012-12-05T17:52:46.347Z,1354729966.347 [Reporter](INFO): ThrusterServo.component_current 0.000000 mA 2012-12-05T17:52:47.504Z,1354729967.504 [Reporter](INFO): ThrusterServo.component_current 62.390000 mA 2012-12-05T17:52:49.903Z,1354729969.903 [Reporter](INFO): ThrusterServo.component_current 455.080003 mA 2012-12-05T17:52:52.274Z,1354729972.274 [Reporter](INFO): ThrusterServo.component_current 249.559999 mA 2012-12-05T17:52:54.650Z,1354729974.650 [Reporter](INFO): ThrusterServo.component_current 1291.840076 mA 2012-12-05T17:52:57.058Z,1354729977.059 [Reporter](INFO): ThrusterServo.component_current 341.309994 mA 2012-12-05T17:52:59.450Z,1354729979.450 [Reporter](INFO): ThrusterServo.component_current 1042.280078 mA 2012-12-05T17:53:01.071Z,1354729981.071 [ThrusterServo](FAULT): Overload Error 2012-12-05T17:53:01.071Z,1354729981.071 [ThrusterServo] Hardware Fault, FailCount= 1 2012-12-05T17:53:01.071Z,1354729981.071 [ThrusterServo](ERROR): Hardware Fault 2012-12-05T17:53:01.073Z,1354729981.073 [CBIT](ERROR): Hardware Fault in component: ThrusterServo 2012-12-05T17:53:01.074Z,1354729981.074 [Reporter](INFO): ThrusterServo.component_current no_value 2012-12-05T17:53:01.525Z,1354729981.525 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2012-12-05T17:53:01.525Z,1354729981.526 [ThrusterServo](INFO): Powering down 2012-12-05T17:53:01.531Z,1354729981.531 [CBIT](INFO): Clearing failed state for component ThrusterServo 2012-12-05T17:53:01.531Z,1354729981.531 [ThrusterServo] No Fault, FailCount= 1 2012-12-05T17:53:02.225Z,1354729982.225 [ThrusterServo](DEBUG): Initializing EZServoServo. 2012-12-05T17:53:02.339Z,1354729982.339 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2012-12-05T17:53:05.033Z,1354729985.033 [Reporter](INFO): ThrusterServo.component_current 0.000000 mA 2012-12-05T17:53:07.908Z,1354729987.908 [Reporter](INFO): ThrusterServo.component_current 278.920025 mA 2012-12-05T17:53:10.274Z,1354729990.274 [Reporter](INFO): ThrusterServo.component_current 550.499976 mA 2012-12-05T17:53:12.650Z,1354729992.650 [Reporter](INFO): ThrusterServo.component_current 1156.050086 mA 2012-12-05T17:53:15.051Z,1354729995.051 [Reporter](INFO): ThrusterServo.component_current 473.430037 mA 2012-12-05T17:53:17.504Z,1354729997.504 [Reporter](INFO): ThrusterServo.component_current 113.770001 mA 2012-12-05T17:53:19.863Z,1354729999.863 [ThrusterServo](FAULT): Overload Error 2012-12-05T17:53:19.863Z,1354729999.863 [ThrusterServo] Hardware Fault, FailCount= 1 2012-12-05T17:53:19.863Z,1354729999.863 [ThrusterServo](ERROR): Hardware Fault 2012-12-05T17:53:19.865Z,1354729999.865 [CBIT](ERROR): Hardware Fault in component: ThrusterServo 2012-12-05T17:53:19.866Z,1354729999.866 [Reporter](INFO): ThrusterServo.component_current no_value 2012-12-05T17:53:20.226Z,1354730000.226 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2012-12-05T17:53:20.226Z,1354730000.226 [ThrusterServo](INFO): Powering down 2012-12-05T17:53:20.228Z,1354730000.228 [CBIT](INFO): Clearing failed state for component ThrusterServo 2012-12-05T17:53:20.228Z,1354730000.228 [ThrusterServo] No Fault, FailCount= 1 2012-12-05T17:53:21.030Z,1354730001.030 [ThrusterServo](DEBUG): Initializing EZServoServo. 2012-12-05T17:53:21.143Z,1354730001.143 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2012-12-05T17:53:23.857Z,1354730003.856 [Reporter](INFO): ThrusterServo.component_current 0.000000 mA 2012-12-05T17:53:26.254Z,1354730006.254 [Reporter](INFO): ThrusterServo.component_current 128.449991 mA 2012-12-05T17:53:28.215Z,1354730008.215 [CommandLine](IMPORTANT): got command maintain control SpeedControl.propOmegaAction 635.000000 revolution_per_minute 2012-12-05T17:53:28.666Z,1354730008.666 [Reporter](INFO): ThrusterServo.component_current 113.770001 mA 2012-12-05T17:53:31.078Z,1354730011.078 [Reporter](INFO): ThrusterServo.component_current 722.989976 mA 2012-12-05T17:53:32.219Z,1354730012.219 [Startup:StartupSatComms:A](INFO): Timed out from 2012-12-05T17:52:32.2Z 2012-12-05T17:53:32.219Z,1354730012.219 [Startup:StartupSatComms:A:A_Timeout] Running Loop=1 2012-12-05T17:53:32.219Z,1354730012.219 [Startup:StartupSatComms:A:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:A:A_Timeout 2012-12-05T17:53:32.220Z,1354730012.220 [Startup:StartupSatComms:A:A_Timeout](INFO): Completed Startup:StartupSatComms:A:A_Timeout 2012-12-05T17:53:32.220Z,1354730012.220 [Startup:StartupSatComms:A] Stopped 2012-12-05T17:53:32.220Z,1354730012.220 [Startup:StartupSatComms:B] Running Loop=1 2012-12-05T17:53:32.663Z,1354730012.663 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2012-12-05T17:53:33.546Z,1354730013.546 [Reporter](INFO): ThrusterServo.component_current 392.690003 mA 2012-12-05T17:53:35.830Z,1354730015.830 [Reporter](INFO): ThrusterServo.component_current 1126.690030 mA 2012-12-05T17:53:37.846Z,1354730017.846 [ThrusterServo](FAULT): Overload Error 2012-12-05T17:53:37.847Z,1354730017.847 [ThrusterServo] Hardware Fault, FailCount= 1 2012-12-05T17:53:37.847Z,1354730017.847 [ThrusterServo](ERROR): Hardware Fault 2012-12-05T17:53:37.850Z,1354730017.849 [CBIT](ERROR): Hardware Fault in component: ThrusterServo 2012-12-05T17:53:37.850Z,1354730017.851 [Reporter](INFO): ThrusterServo.component_current no_value 2012-12-05T17:53:38.170Z,1354730018.170 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2012-12-05T17:53:38.170Z,1354730018.170 [ThrusterServo](INFO): Powering down 2012-12-05T17:53:38.173Z,1354730018.173 [CBIT](INFO): Clearing failed state for component ThrusterServo 2012-12-05T17:53:38.173Z,1354730018.173 [ThrusterServo] No Fault, FailCount= 1 2012-12-05T17:53:39.485Z,1354730019.485 [ThrusterServo](DEBUG): Initializing EZServoServo. 2012-12-05T17:53:39.603Z,1354730019.603 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2012-12-05T17:53:42.220Z,1354730022.220 [Reporter](INFO): ThrusterServo.component_current 0.000000 mA 2012-12-05T17:53:44.655Z,1354730024.655 [CommandLine](IMPORTANT): got command maintain control SpeedControl.propOmegaAction 625.000000 revolution_per_minute 2012-12-05T17:53:45.006Z,1354730025.006 [Reporter](INFO): ThrusterServo.component_current 99.090002 mA 2012-12-05T17:53:47.418Z,1354730027.418 [Reporter](INFO): ThrusterServo.component_current 40.370002 mA 2012-12-05T17:53:50.222Z,1354730030.222 [Reporter](INFO): ThrusterServo.component_current 1255.140066 mA 2012-12-05T17:53:52.714Z,1354730032.714 [Reporter](INFO): ThrusterServo.component_current 1156.050086 mA 2012-12-05T17:53:54.946Z,1354730034.946 [Reporter](INFO): ThrusterServo.component_current 278.920025 mA 2012-12-05T17:53:57.466Z,1354730037.466 [Reporter](INFO): ThrusterServo.component_current 311.949998 mA 2012-12-05T17:53:59.704Z,1354730039.704 [Reporter](INFO): ThrusterServo.component_current 14.680000 mA 2012-12-05T17:54:02.502Z,1354730042.503 [Reporter](INFO): ThrusterServo.component_current 627.570033 mA 2012-12-05T17:54:04.850Z,1354730044.850 [Reporter](INFO): ThrusterServo.component_current 1152.379990 mA 2012-12-05T17:54:07.602Z,1354730047.602 [Reporter](INFO): ThrusterServo.component_current 726.660013 mA 2012-12-05T17:54:09.879Z,1354730049.879 [CommandLine](IMPORTANT): got command maintain control SpeedControl.propOmegaAction 634.000000 revolution_per_minute 2012-12-05T17:54:09.983Z,1354730049.983 [Reporter](INFO): ThrusterServo.component_current 139.460012 mA 2012-12-05T17:54:12.754Z,1354730052.754 [Reporter](INFO): ThrusterServo.component_current 150.470003 mA 2012-12-05T17:54:15.246Z,1354730055.246 [Reporter](INFO): ThrusterServo.component_current 1060.629964 mA 2012-12-05T17:54:17.482Z,1354730057.482 [Reporter](INFO): ThrusterServo.component_current 436.729997 mA 2012-12-05T17:54:20.238Z,1354730060.239 [Reporter](INFO): ThrusterServo.component_current 201.850012 mA 2012-12-05T17:54:22.642Z,1354730062.642 [Reporter](INFO): ThrusterServo.component_current 102.760002 mA 2012-12-05T17:54:24.931Z,1354730064.931 [CommandLine](IMPORTANT): got command maintain control SpeedControl.propOmegaAction 300.000000 revolution_per_minute 2012-12-05T17:54:25.438Z,1354730065.438 [Reporter](INFO): ThrusterServo.component_current 47.709998 mA 2012-12-05T17:54:27.902Z,1354730067.902 [Reporter](INFO): ThrusterServo.component_current 231.210008 mA 2012-12-05T17:54:30.230Z,1354730070.230 [Reporter](INFO): ThrusterServo.component_current 80.740005 mA 2012-12-05T17:54:32.242Z,1354730072.242 [Startup:StartupSatComms:B](INFO): Timed out from 2012-12-05T17:53:32.2Z 2012-12-05T17:54:32.242Z,1354730072.242 [Startup:StartupSatComms:B:A_Timeout] Running Loop=1 2012-12-05T17:54:32.242Z,1354730072.242 [Startup:StartupSatComms:B:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:B:A_Timeout 2012-12-05T17:54:32.243Z,1354730072.243 [Startup:StartupSatComms:B:A_Timeout](INFO): Completed Startup:StartupSatComms:B:A_Timeout 2012-12-05T17:54:32.243Z,1354730072.243 [Startup:StartupSatComms:B] Stopped 2012-12-05T17:54:32.243Z,1354730072.243 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2012-12-05T17:54:32.243Z,1354730072.243 [Startup:StartupSatComms] Stopped 2012-12-05T17:54:32.243Z,1354730072.243 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms 2012-12-05T17:54:32.244Z,1354730072.244 [Startup](INFO): Completed Startup 2012-12-05T17:54:32.244Z,1354730072.244 [Startup] Stopped 2012-12-05T17:54:32.244Z,1354730072.244 [Startup](INFO): Aggregate::uninitialize Startup 2012-12-05T17:54:32.244Z,1354730072.244 [Startup:A.GoToSurface] Stopped 2012-12-05T17:54:32.244Z,1354730072.244 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-12-05T17:54:32.532Z,1354730072.532 [MissionManager](IMPORTANT): Started mission Default 2012-12-05T17:54:32.532Z,1354730072.532 [Default] Running Loop=1 2012-12-05T17:54:32.532Z,1354730072.532 [Default](INFO): Aggregate::initialize Default 2012-12-05T17:54:32.532Z,1354730072.532 [Default:D.SetSpeed] Running Loop=1 2012-12-05T17:54:32.533Z,1354730072.533 [Default:D.SetSpeed](DEBUG): Initialize. 2012-12-05T17:54:32.533Z,1354730072.533 [Default:E.GoToSurface] Running Loop=1 2012-12-05T17:54:32.533Z,1354730072.533 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-12-05T17:54:32.533Z,1354730072.533 [Default:Iridium] Running Loop=1 2012-12-05T17:54:32.533Z,1354730072.533 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2012-12-05T17:54:32.533Z,1354730072.533 [Default:Iridium:A.SetSpeed] Running Loop=1 2012-12-05T17:54:32.533Z,1354730072.533 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2012-12-05T17:54:32.534Z,1354730072.533 [Default:Iridium:B.GoToSurface] Running Loop=1 2012-12-05T17:54:32.534Z,1354730072.533 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-12-05T17:54:32.534Z,1354730072.534 [Default:E.GoToSurface] Running Loop=1 2012-12-05T17:54:32.539Z,1354730072.539 [Default:D.SetSpeed] Running Loop=1 2012-12-05T17:54:32.544Z,1354730072.544 [Default:CallIridium] Running Loop=1 2012-12-05T17:54:32.544Z,1354730072.544 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2012-12-05T17:54:32.545Z,1354730072.545 [Default:CallIridium:A] Running Loop=1 2012-12-05T17:54:32.547Z,1354730072.547 [Default:CallIridium:A] Stopped 2012-12-05T17:54:32.547Z,1354730072.547 [Default:CallIridium:B] Running Loop=1 2012-12-05T17:54:32.547Z,1354730072.547 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2012-12-05T17:54:32.552Z,1354730072.552 [Default:Iridium:B.GoToSurface] Stopped 2012-12-05T17:54:32.552Z,1354730072.552 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-12-05T17:54:32.553Z,1354730072.553 [Default:Iridium:Read_Iridium] Running Loop=1 2012-12-05T17:54:32.553Z,1354730072.553 [Default:Iridium:A.SetSpeed] Running Loop=1 2012-12-05T17:54:32.558Z,1354730072.557 [Default:GPS] Running Loop=1 2012-12-05T17:54:32.558Z,1354730072.558 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2012-12-05T17:54:32.558Z,1354730072.558 [Default:GPS:A.SetSpeed] Running Loop=1 2012-12-05T17:54:32.558Z,1354730072.558 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2012-12-05T17:54:32.558Z,1354730072.558 [Default:GPS:B.GoToSurface] Running Loop=1 2012-12-05T17:54:32.558Z,1354730072.558 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-12-05T17:54:32.564Z,1354730072.564 [Default:GPS:B.GoToSurface] Stopped 2012-12-05T17:54:32.564Z,1354730072.564 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-12-05T17:54:32.564Z,1354730072.564 [Default:GPS:Read_GPS] Running Loop=1 2012-12-05T17:54:32.564Z,1354730072.564 [Default:GPS:A.SetSpeed] Running Loop=1 2012-12-05T17:54:32.903Z,1354730072.903 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2012-12-05T17:54:32.906Z,1354730072.906 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2012-12-05T17:54:32.946Z,1354730072.946 [Reporter](INFO): ThrusterServo.component_current 99.090002 mA 2012-12-05T17:54:33.915Z,1354730073.915 [CommandLine](IMPORTANT): got command maintain control SpeedControl.propOmegaAction 634.000000 revolution_per_minute 2012-12-05T17:54:35.354Z,1354730075.354 [Reporter](INFO): ThrusterServo.component_current 95.419995 mA 2012-12-05T17:54:37.706Z,1354730077.706 [Reporter](INFO): ThrusterServo.component_current 161.480010 mA 2012-12-05T17:54:40.086Z,1354730080.086 [Reporter](INFO): ThrusterServo.component_current 572.520018 mA 2012-12-05T17:54:42.454Z,1354730082.454 [Reporter](INFO): ThrusterServo.component_current 55.050004 mA 2012-12-05T17:54:44.846Z,1354730084.846 [Reporter](INFO): ThrusterServo.component_current 194.510013 mA 2012-12-05T17:54:47.613Z,1354730087.614 [Reporter](INFO): ThrusterServo.component_current 220.200017 mA 2012-12-05T17:54:48.863Z,1354730088.863 [CommandLine](IMPORTANT): got command maintain control SpeedControl.propOmegaAction 300.000000 revolution_per_minute 2012-12-05T17:54:50.486Z,1354730090.486 [Reporter](INFO): ThrusterServo.component_current 1401.940107 mA 2012-12-05T17:54:52.738Z,1354730092.738 [Reporter](INFO): ThrusterServo.component_current 807.400048 mA 2012-12-05T17:54:55.470Z,1354730095.470 [Reporter](INFO): ThrusterServo.component_current 352.320015 mA 2012-12-05T17:54:56.301Z,1354730096.301 [ThrusterServo](FAULT): Overload Error 2012-12-05T17:54:56.301Z,1354730096.301 [ThrusterServo] Hardware Fault, FailCount= 1 2012-12-05T17:54:56.301Z,1354730096.301 [ThrusterServo](ERROR): Hardware Fault 2012-12-05T17:54:56.304Z,1354730096.304 [CBIT](ERROR): Hardware Fault in component: ThrusterServo 2012-12-05T17:54:56.305Z,1354730096.305 [Reporter](INFO): ThrusterServo.component_current no_value 2012-12-05T17:54:56.658Z,1354730096.658 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2012-12-05T17:54:56.658Z,1354730096.658 [ThrusterServo](INFO): Powering down 2012-12-05T17:54:56.661Z,1354730096.661 [CBIT](INFO): Clearing failed state for component ThrusterServo 2012-12-05T17:54:56.661Z,1354730096.661 [ThrusterServo] No Fault, FailCount= 1 2012-12-05T17:54:57.471Z,1354730097.471 [ThrusterServo](DEBUG): Initializing EZServoServo. 2012-12-05T17:54:57.589Z,1354730097.589 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2012-12-05T17:55:00.182Z,1354730100.181 [Reporter](INFO): ThrusterServo.component_current 0.000000 mA 2012-12-05T17:55:01.805Z,1354730101.806 [Reporter](INFO): ThrusterServo.component_current 58.720000 mA 2012-12-05T17:55:02.691Z,1354730102.691 [ThrusterServo](FAULT): getVelocity uart error serial timeout 2012-12-05T17:55:02.691Z,1354730102.691 [ThrusterServo](FAULT): Thruster uart error: serial timeout 2012-12-05T17:55:02.691Z,1354730102.691 [ThrusterServo] Communications Fault, FailCount= 2 2012-12-05T17:55:02.691Z,1354730102.691 [ThrusterServo](ERROR): Communications Fault 2012-12-05T17:55:02.693Z,1354730102.693 [CBIT](ERROR): Communications Fault in component: ThrusterServo 2012-12-05T17:55:02.694Z,1354730102.694 [Reporter](INFO): ThrusterServo.component_current no_value 2012-12-05T17:55:03.418Z,1354730103.418 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2012-12-05T17:55:03.418Z,1354730103.418 [ThrusterServo](INFO): Powering down 2012-12-05T17:55:03.421Z,1354730103.421 [CBIT](INFO): Clearing failed state for component ThrusterServo 2012-12-05T17:55:03.421Z,1354730103.421 [ThrusterServo] No Fault, FailCount= 2 2012-12-05T17:55:04.030Z,1354730104.030 [ThrusterServo](DEBUG): Initializing EZServoServo. 2012-12-05T17:55:04.147Z,1354730104.147 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2012-12-05T17:55:07.349Z,1354730107.349 [Reporter](INFO): ThrusterServo.component_current 0.000000 mA 2012-12-05T17:55:07.563Z,1354730107.563 [CommandLine](IMPORTANT): got command quit 2012-12-05T17:55:08.694Z,1354730108.694 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2012-12-05T17:55:08.695Z,1354730108.694 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2012-12-05T17:55:08.794Z,1354730108.794 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2012-12-05T17:55:08.803Z,1354730108.803 [Reporter](INFO): ThrusterServo.component_current 62.390000 mA 2012-12-05T17:55:09.019Z,1354730109.019 [WetLabsBB2FL](INFO): Powering down 2012-12-05T17:55:09.022Z,1354730109.022 [ComponentRegistry](INFO): Shutting down Turbulence_NPS ThreadHandler 2012-12-05T17:55:09.151Z,1354730109.151 [Turbulence_NPS](INFO): Uninitialize Powering down 2012-12-05T17:55:09.163Z,1354730109.163 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler 2012-12-05T17:55:09.243Z,1354730109.243 [CTD_NeilBrown](INFO): Powering down 2012-12-05T17:55:09.246Z,1354730109.246 [ComponentRegistry](INFO): Shutting down DVL_micro ThreadHandler 2012-12-05T17:55:09.443Z,1354730109.443 [DVL_micro](INFO): uninitialize:Powering down 2012-12-05T17:55:09.451Z,1354730109.451 [ComponentRegistry](INFO): Shutting down AsyncPiEstimator ThreadHandler 2012-12-05T17:55:09.535Z,1354730109.535 [AsyncPiEstimator](DEBUG): Uninitialize AsyncPiEstimator. 2012-12-05T17:55:09.555Z,1354730109.555 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2012-12-05T17:55:09.607Z,1354730109.607 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2012-12-05T17:55:09.615Z,1354730109.615 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2012-12-05T17:55:09.639Z,1354730109.639 [controlThread](DEBUG): Uninitializing ControlThread 2012-12-05T17:55:09.639Z,1354730109.639 [AHRS_sp3003D](INFO): Powering down 2012-12-05T17:55:09.728Z,1354730109.727 [NAL9602](INFO): Powering down 2012-12-05T17:55:09.729Z,1354730109.729 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2012-12-05T17:55:09.730Z,1354730109.730 [NavChart](DEBUG): Uninitialize NavChart Derivation. 2012-12-05T17:55:09.731Z,1354730109.731 [Default] Stopped 2012-12-05T17:55:09.731Z,1354730109.731 [Default](INFO): Aggregate::uninitialize Default 2012-12-05T17:55:09.731Z,1354730109.731 [Default:GPS] Stopped 2012-12-05T17:55:09.732Z,1354730109.731 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2012-12-05T17:55:09.732Z,1354730109.731 [Default:GPS:A.SetSpeed] Stopped 2012-12-05T17:55:09.732Z,1354730109.732 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2012-12-05T17:55:09.732Z,1354730109.732 [Default:GPS:Read_GPS] Stopped 2012-12-05T17:55:09.732Z,1354730109.732 [Default:Iridium] Stopped 2012-12-05T17:55:09.732Z,1354730109.732 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2012-12-05T17:55:09.732Z,1354730109.732 [Default:Iridium:A.SetSpeed] Stopped 2012-12-05T17:55:09.732Z,1354730109.732 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2012-12-05T17:55:09.732Z,1354730109.732 [Default:Iridium:Read_Iridium] Stopped 2012-12-05T17:55:09.732Z,1354730109.732 [Default:CallIridium] Stopped 2012-12-05T17:55:09.732Z,1354730109.732 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2012-12-05T17:55:09.732Z,1354730109.732 [Default:CallIridium:B] Stopped 2012-12-05T17:55:09.732Z,1354730109.732 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2012-12-05T17:55:09.733Z,1354730109.733 [Default:D.SetSpeed] Stopped 2012-12-05T17:55:09.733Z,1354730109.733 [Default:D.SetSpeed](DEBUG): Uninitialize. 2012-12-05T17:55:09.733Z,1354730109.733 [Default:E.GoToSurface] Stopped 2012-12-05T17:55:09.733Z,1354730109.733 [Default:E.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-12-05T17:55:09.737Z,1354730109.737 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2012-12-05T17:55:09.737Z,1354730109.737 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2012-12-05T17:55:09.738Z,1354730109.737 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2012-12-05T17:55:09.738Z,1354730109.738 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2012-12-05T17:55:09.738Z,1354730109.738 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2012-12-05T17:55:09.738Z,1354730109.738 [BuoyancyServo](INFO): Powering down 2012-12-05T17:55:09.751Z,1354730109.750 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2012-12-05T17:55:09.751Z,1354730109.751 [ElevatorServo](INFO): Powering down 2012-12-05T17:55:09.751Z,1354730109.751 [MassServo](DEBUG): Uninitialize Mass Servo. 2012-12-05T17:55:09.752Z,1354730109.751 [MassServo](INFO): Powering down 2012-12-05T17:55:09.752Z,1354730109.752 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2012-12-05T17:55:09.752Z,1354730109.752 [RudderServo](INFO): Powering down 2012-12-05T17:55:09.753Z,1354730109.753 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2012-12-05T17:55:09.753Z,1354730109.753 [ThrusterServo](INFO): Powering down 2012-12-05T17:55:09.754Z,1354730109.754 [SBIT](DEBUG): Uninitialize SBIT Component. 2012-12-05T17:55:09.755Z,1354730109.755 [IBIT](DEBUG): Uninitialize IBIT Component. 2012-12-05T17:55:09.755Z,1354730109.755 [CBIT](DEBUG): Uninitialize CBIT Component.