2012-10-08T17:54:32.955Z,1349718872.955 [Supervisor](DEBUG): Initializing supervisor. 2012-10-08T17:54:32.958Z,1349718872.958 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0 2012-10-08T17:54:32.958Z,1349718872.958 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2012-10-08T17:54:32.959Z,1349718872.959 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0 2012-10-08T17:54:32.963Z,1349718872.963 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2012-10-08T17:54:32.974Z,1349718872.974 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2012-10-08T17:54:32.975Z,1349718872.975 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0 2012-10-08T17:54:32.975Z,1349718872.976 [ComponentRegistry](DEBUG): SyncComponent "logger" handled in the control thread. 2012-10-08T17:54:32.976Z,1349718872.976 [Supervisor](INFO): Looking for Config files in directory: Config/ 2012-10-08T17:54:32.977Z,1349718872.977 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2012-10-08T17:54:33.252Z,1349718873.252 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2012-10-08T17:54:33.253Z,1349718873.253 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2012-10-08T17:54:33.436Z,1349718873.436 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2012-10-08T17:54:33.437Z,1349718873.437 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2012-10-08T17:54:33.527Z,1349718873.527 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2012-10-08T17:54:33.527Z,1349718873.527 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2012-10-08T17:54:33.727Z,1349718873.727 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2012-10-08T17:54:33.728Z,1349718873.728 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2012-10-08T17:54:33.861Z,1349718873.861 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2012-10-08T17:54:33.861Z,1349718873.861 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2012-10-08T17:54:34.096Z,1349718874.096 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2012-10-08T17:54:34.096Z,1349718874.096 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2012-10-08T17:54:34.301Z,1349718874.301 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2012-10-08T17:54:34.301Z,1349718874.301 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2012-10-08T17:54:34.545Z,1349718874.545 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2012-10-08T17:54:34.545Z,1349718874.545 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2012-10-08T17:54:34.648Z,1349718874.648 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2012-10-08T17:54:34.648Z,1349718874.648 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2012-10-08T17:54:35.049Z,1349718875.049 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2012-10-08T17:54:35.049Z,1349718875.049 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2012-10-08T17:54:35.164Z,1349718875.164 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2012-10-08T17:54:35.165Z,1349718875.165 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2012-10-08T17:54:35.340Z,1349718875.340 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2012-10-08T17:54:35.341Z,1349718875.341 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2012-10-08T17:54:35.443Z,1349718875.443 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2012-10-08T17:54:35.571Z,1349718875.571 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2012-10-08T17:54:35.657Z,1349718875.657 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2012-10-08T17:54:35.759Z,1349718875.759 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2012-10-08T17:54:35.885Z,1349718875.885 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2012-10-08T17:54:36.026Z,1349718876.026 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2012-10-08T17:54:36.118Z,1349718876.118 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2012-10-08T17:54:36.206Z,1349718876.206 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2012-10-08T17:54:36.235Z,1349718876.235 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2012-10-08T17:54:36.373Z,1349718876.372 [InternalSim] Loaded 2012-10-08T17:54:36.373Z,1349718876.373 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread. 2012-10-08T17:54:36.373Z,1349718876.374 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2012-10-08T17:54:36.374Z,1349718876.374 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2012-10-08T17:54:36.431Z,1349718876.431 [SBIT](DEBUG): Construct Startup Built In Test. 2012-10-08T17:54:36.444Z,1349718876.444 [SBIT] Loaded 2012-10-08T17:54:36.444Z,1349718876.444 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2012-10-08T17:54:36.445Z,1349718876.445 [IBIT](DEBUG): Construct Initiated Built In Test. 2012-10-08T17:54:36.472Z,1349718876.473 [IBIT] Loaded 2012-10-08T17:54:36.473Z,1349718876.473 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2012-10-08T17:54:36.476Z,1349718876.476 [CBIT](DEBUG): Construct CBIT Built In Test. 2012-10-08T17:54:36.592Z,1349718876.592 [CBIT] Loaded 2012-10-08T17:54:36.592Z,1349718876.592 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2012-10-08T17:54:36.593Z,1349718876.593 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2012-10-08T17:54:36.594Z,1349718876.593 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2012-10-08T17:54:36.736Z,1349718876.736 [BuoyancyServo] Loaded 2012-10-08T17:54:36.737Z,1349718876.737 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2012-10-08T17:54:36.745Z,1349718876.745 [ElevatorServo] Loaded 2012-10-08T17:54:36.746Z,1349718876.746 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2012-10-08T17:54:36.757Z,1349718876.757 [MassServo] Loaded 2012-10-08T17:54:36.757Z,1349718876.757 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2012-10-08T17:54:36.769Z,1349718876.769 [RudderServo] Loaded 2012-10-08T17:54:36.769Z,1349718876.769 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2012-10-08T17:54:36.781Z,1349718876.781 [ThrusterServo] Loaded 2012-10-08T17:54:36.781Z,1349718876.781 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2012-10-08T17:54:36.781Z,1349718876.782 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2012-10-08T17:54:36.782Z,1349718876.782 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2012-10-08T17:54:36.799Z,1349718876.799 [DepthRateCalculator] Loaded 2012-10-08T17:54:36.799Z,1349718876.799 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2012-10-08T17:54:40.606Z,1349718880.606 [HFRadarModelCalc] Loaded 2012-10-08T17:54:40.606Z,1349718880.606 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread. 2012-10-08T17:54:40.622Z,1349718880.622 [NavChart] Loaded 2012-10-08T17:54:40.622Z,1349718880.622 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2012-10-08T17:54:40.628Z,1349718880.628 [PitchRateCalculator] Loaded 2012-10-08T17:54:40.628Z,1349718880.628 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2012-10-08T17:54:40.635Z,1349718880.635 [SpeedCalculator] Loaded 2012-10-08T17:54:40.635Z,1349718880.635 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2012-10-08T17:54:40.649Z,1349718880.649 [TempGradientCalculator] Loaded 2012-10-08T17:54:40.650Z,1349718880.650 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2012-10-08T17:54:40.655Z,1349718880.655 [YawRateCalculator] Loaded 2012-10-08T17:54:40.656Z,1349718880.656 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2012-10-08T17:54:40.674Z,1349718880.674 [Navigation] Loaded 2012-10-08T17:54:40.675Z,1349718880.675 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread. 2012-10-08T17:54:40.675Z,1349718880.675 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2012-10-08T17:54:40.676Z,1349718880.676 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2012-10-08T17:54:41.157Z,1349718881.157 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2012-10-08T17:54:41.158Z,1349718881.158 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2012-10-08T17:54:41.189Z,1349718881.189 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2012-10-08T17:54:41.190Z,1349718881.190 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2012-10-08T17:54:41.255Z,1349718881.255 [VerticalControl](DEBUG): Construct VerticalControl. 2012-10-08T17:54:41.323Z,1349718881.323 [VerticalControl] Loaded 2012-10-08T17:54:41.323Z,1349718881.323 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2012-10-08T17:54:41.324Z,1349718881.324 [HorizontalControl](DEBUG): Construct HorizontalControl. 2012-10-08T17:54:41.353Z,1349718881.353 [HorizontalControl] Loaded 2012-10-08T17:54:41.353Z,1349718881.353 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2012-10-08T17:54:41.354Z,1349718881.354 [SpeedControl](DEBUG): Construct SpeedControl. 2012-10-08T17:54:41.356Z,1349718881.355 [SpeedControl] Loaded 2012-10-08T17:54:41.356Z,1349718881.356 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2012-10-08T17:54:41.357Z,1349718881.357 [LoopControl](DEBUG): Construct LoopControl. 2012-10-08T17:54:41.357Z,1349718881.357 [LoopControl] Loaded 2012-10-08T17:54:41.357Z,1349718881.357 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2012-10-08T17:54:41.358Z,1349718881.358 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2012-10-08T17:54:41.367Z,1349718881.367 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2012-10-08T17:54:41.372Z,1349718881.372 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator. 2012-10-08T17:54:41.377Z,1349718881.376 [AsyncPiEstimator] Loaded 2012-10-08T17:54:41.377Z,1349718881.377 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread. 2012-10-08T17:54:41.378Z,1349718881.378 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406724E0 2012-10-08T17:54:41.379Z,1349718881.379 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2012-10-08T17:54:41.379Z,1349718881.379 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2012-10-08T17:54:41.652Z,1349718881.652 [AHRS_sp3003D] Loaded 2012-10-08T17:54:41.652Z,1349718881.652 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread. 2012-10-08T17:54:41.678Z,1349718881.678 [Depth_Keller] Loaded 2012-10-08T17:54:41.678Z,1349718881.678 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2012-10-08T17:54:41.696Z,1349718881.696 [DropWeight] Loaded 2012-10-08T17:54:41.696Z,1349718881.696 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2012-10-08T17:54:41.938Z,1349718881.938 [DVL_micro] Loaded 2012-10-08T17:54:41.939Z,1349718881.939 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread. 2012-10-08T17:54:41.951Z,1349718881.951 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 406F34E0 2012-10-08T17:54:42.121Z,1349718882.121 [NAL9602] Loaded 2012-10-08T17:54:42.121Z,1349718882.121 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2012-10-08T17:54:42.231Z,1349718882.231 [Onboard] Loaded 2012-10-08T17:54:42.232Z,1349718882.232 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2012-10-08T17:54:42.242Z,1349718882.241 [Radio_Freewave] Loaded 2012-10-08T17:54:42.242Z,1349718882.242 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread. 2012-10-08T17:54:42.243Z,1349718882.243 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2012-10-08T17:54:42.259Z,1349718882.259 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2012-10-08T17:54:42.361Z,1349718882.361 [CTD_NeilBrown] Loaded 2012-10-08T17:54:42.361Z,1349718882.361 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2012-10-08T17:54:42.362Z,1349718882.362 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4074B4E0 2012-10-08T17:54:42.372Z,1349718882.372 [PAR_Licor] Loaded 2012-10-08T17:54:42.372Z,1349718882.372 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2012-10-08T17:54:42.441Z,1349718882.441 [Turbulence_NPS] Loaded 2012-10-08T17:54:42.441Z,1349718882.441 [ComponentRegistry](DEBUG): Component "Turbulence_NPS" handled in its own thread. 2012-10-08T17:54:42.464Z,1349718882.464 [Turbulence_NPS ThreadHandler](DEBUG): Created PCaller Thread at 4077B4E0 2012-10-08T17:54:42.519Z,1349718882.519 [WetLabsBB2FL] Loaded 2012-10-08T17:54:42.519Z,1349718882.519 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2012-10-08T17:54:42.527Z,1349718882.527 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407AB4E0 2012-10-08T17:54:42.527Z,1349718882.527 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2012-10-08T17:54:42.530Z,1349718882.530 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2012-10-08T17:54:42.530Z,1349718882.530 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2012-10-08T17:54:42.536Z,1349718882.536 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2012-10-08T17:54:42.543Z,1349718882.543 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 407DB4E0 2012-10-08T17:54:42.547Z,1349718882.547 [Supervisor](DEBUG): Running supervisor. 2012-10-08T17:54:42.555Z,1349718882.555 [CommandLine](INFO): Thread ID is 1095 2012-10-08T17:54:42.557Z,1349718882.557 [controlThread](INFO): Thread ID is 1094 2012-10-08T17:54:42.558Z,1349718882.557 [controlThread](DEBUG): Initializing ControlThread 2012-10-08T17:54:42.558Z,1349718882.558 [CycleStarter](INFO): Thread ID is 1093 2012-10-08T17:54:42.558Z,1349718882.559 [InternalSim](DEBUG): InternalSim initializing... 2012-10-08T17:54:42.599Z,1349718882.599 [AsyncPiEstimator](INFO): Thread ID is 1160 2012-10-08T17:54:42.599Z,1349718882.599 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator. 2012-10-08T17:54:42.617Z,1349718882.617 [DVL_micro](INFO): Thread ID is 1161 2012-10-08T17:54:42.626Z,1349718882.626 [DVL_micro](INFO): Initializing 2012-10-08T17:54:42.627Z,1349718882.626 [DVL_micro](INFO): start:Powering up 2012-10-08T17:54:42.627Z,1349718882.628 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2012-10-08T17:54:42.628Z,1349718882.628 [DVL_micro](INFO): Cycling power to configure device. 2012-10-08T17:54:42.635Z,1349718882.635 [SBIT](INFO): Initialize SBIT Component. 2012-10-08T17:54:42.635Z,1349718882.635 [SBIT](IMPORTANT): Tethys CM Info: $Rev: 9936 2012-10-08T17:54:42.636Z,1349718882.636 [IBIT](INFO): Initialize IBIT Component. 2012-10-08T17:54:42.637Z,1349718882.637 [CBIT](DEBUG): Initialize CBIT Component. 2012-10-08T17:54:42.637Z,1349718882.637 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2012-10-08T17:54:42.647Z,1349718882.647 [CTD_NeilBrown](INFO): Thread ID is 1162 2012-10-08T17:54:42.647Z,1349718882.648 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown. 2012-10-08T17:54:42.651Z,1349718882.651 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4 2012-10-08T17:54:42.664Z,1349718882.664 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2012-10-08T17:54:42.665Z,1349718882.665 [NavChart](DEBUG): Initialize NavChart Derivation. 2012-10-08T17:54:42.665Z,1349718882.665 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2012-10-08T17:54:42.665Z,1349718882.665 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2012-10-08T17:54:42.666Z,1349718882.666 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2012-10-08T17:54:42.672Z,1349718882.672 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2012-10-08T17:54:42.672Z,1349718882.672 [Navigation](DEBUG): Initializing Navigation. 2012-10-08T17:54:42.673Z,1349718882.673 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2012-10-08T17:54:42.675Z,1349718882.675 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2012-10-08T17:54:42.675Z,1349718882.675 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2012-10-08T17:54:42.676Z,1349718882.676 [LoopControl](DEBUG): Initialize LoopControlComponent. 2012-10-08T17:54:42.679Z,1349718882.679 [Turbulence_NPS](INFO): Thread ID is 1163 2012-10-08T17:54:42.680Z,1349718882.680 [Turbulence_NPS](DEBUG): Initializing Turbulence_NPS. 2012-10-08T17:54:42.680Z,1349718882.681 [Turbulence_NPS](INFO): Opening uart, block timeout 10ths=1 2012-10-08T17:54:42.698Z,1349718882.698 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2012-10-08T17:54:42.700Z,1349718882.700 [WetLabsBB2FL](INFO): Thread ID is 1166 2012-10-08T17:54:42.700Z,1349718882.700 [WetLabsBB2FL](INFO): Powering down 2012-10-08T17:54:42.751Z,1349718882.751 [Turbulence_NPS](INFO): Pause powering down 2012-10-08T17:54:42.767Z,1349718882.767 [NavChartDb](INFO): Thread ID is 1167 2012-10-08T17:54:42.769Z,1349718882.769 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources 2012-10-08T17:54:42.770Z,1349718882.770 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2012-10-08T17:54:42.770Z,1349718882.770 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2012-10-08T17:54:42.776Z,1349718882.776 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2012-10-08T17:54:42.819Z,1349718882.819 [MissionManager](DEBUG): 2012-10-08T17:54:42.820Z,1349718882.819 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2012-10-08T17:54:42.881Z,1349718882.881 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool 2012-10-08T17:54:42.891Z,1349718882.891 [Default:GPS:A.SetSpeed](DEBUG): Construct. 2012-10-08T17:54:42.894Z,1349718882.894 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface. 2012-10-08T17:54:42.926Z,1349718882.926 [Default:Iridium:A.SetSpeed](DEBUG): Construct. 2012-10-08T17:54:42.929Z,1349718882.929 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface. 2012-10-08T17:54:42.948Z,1349718882.948 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2012-10-08T17:54:42.957Z,1349718882.957 [Default:D.SetSpeed](DEBUG): Construct. 2012-10-08T17:54:42.960Z,1349718882.960 [Default:E.GoToSurface](DEBUG): Construct GoToSurface. 2012-10-08T17:54:42.965Z,1349718882.965 [Default:F.Wait](DEBUG): Construct Wait. 2012-10-08T17:54:42.993Z,1349718882.993 [MissionManager](DEBUG): 400 400 Burn 300 Dropped drop weight due to communications timeout 5.0 1.0 5 2012-10-08T17:54:42.997Z,1349718882.997 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,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,logger, 2012-10-08T17:54:43.046Z,1349718883.046 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2012-10-08T17:54:43.343Z,1349718883.342 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2012-10-08T17:54:43.343Z,1349718883.343 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2012-10-08T17:54:43.411Z,1349718883.411 [Radio_Freewave](INFO): Powering up 2012-10-08T17:54:43.831Z,1349718883.831 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2012-10-08T17:54:43.849Z,1349718883.849 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2012-10-08T17:54:43.867Z,1349718883.867 [ElevatorServo](DEBUG): Initializing EZServoServo. 2012-10-08T17:54:43.875Z,1349718883.875 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2012-10-08T17:54:43.881Z,1349718883.881 [MassServo](DEBUG): Initializing EZServoServo. 2012-10-08T17:54:43.887Z,1349718883.887 [MassServo](DEBUG): Initializing MassServo. 2012-10-08T17:54:43.893Z,1349718883.893 [RudderServo](DEBUG): Initializing EZServoServo. 2012-10-08T17:54:43.907Z,1349718883.907 [RudderServo](DEBUG): Initializing RudderServo. 2012-10-08T17:54:43.913Z,1349718883.913 [ThrusterServo](DEBUG): Initializing EZServoServo. 2012-10-08T17:54:43.919Z,1349718883.919 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2012-10-08T17:54:45.047Z,1349718885.047 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2012-10-08T17:54:45.047Z,1349718885.047 [DVL_micro](INFO): Querying output modes 2012-10-08T17:54:45.047Z,1349718885.047 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606 2012-10-08T17:54:45.051Z,1349718885.051 [DVL_micro](DEBUG): cmdResponse: 01 2012-10-08T17:54:45.051Z,1349718885.051 [DVL_micro](INFO): NQ1 output enabled 2012-10-08T17:54:45.051Z,1349718885.051 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525 2012-10-08T17:54:45.059Z,1349718885.059 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 2012-10-08T17:54:45.064Z,1349718885.064 [DVL_micro](INFO): pause:Powering down 2012-10-08T17:54:47.641Z,1349718887.641 [NAL9602](INFO): Powering up NAL9602 2012-10-08T17:54:58.791Z,1349718898.791 [NAL9602](INFO): NAL9602 initialized 2012-10-08T17:54:59.499Z,1349718899.499 [SBIT](IMPORTANT): Beginning Startup BIT 2012-10-08T17:54:59.501Z,1349718899.501 [CBIT](IMPORTANT): Beginning GF scan 2012-10-08T17:55:12.977Z,1349718912.977 [SBIT](FAULT): Mass: EXPECTED:0.005600 ACTUAL:0.005549 2012-10-08T17:55:27.311Z,1349718927.311 [CBIT](IMPORTANT): No ground fault detected 2012-10-08T17:55:54.476Z,1349718954.476 [SBIT](CRITICAL): SBIT FAILED 2012-10-08T17:55:54.873Z,1349718954.873 [MissionManager](IMPORTANT): Started mission Startup 2012-10-08T17:55:54.873Z,1349718954.874 [Startup] Running Loop=1 2012-10-08T17:55:54.874Z,1349718954.874 [Startup](INFO): Aggregate::initialize Startup 2012-10-08T17:55:54.874Z,1349718954.874 [Startup:A.GoToSurface] Running Loop=1 2012-10-08T17:55:54.874Z,1349718954.874 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-10-08T17:55:54.881Z,1349718954.881 [Startup:StartupSatComms] Running Loop=1 2012-10-08T17:55:54.881Z,1349718954.881 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms 2012-10-08T17:55:54.881Z,1349718954.881 [Startup:StartupSatComms:A] Running Loop=1 2012-10-08T17:55:55.278Z,1349718955.278 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2012-10-08T17:56:08.779Z,1349718968.779 [CommandLine](IMPORTANT): got command show variable defualt 2012-10-08T17:56:12.743Z,1349718972.743 [CommandLine](IMPORTANT): got command show variable default 2012-10-08T17:56:12.756Z,1349718972.756 [CommandLine](INFO): VerticalControl.buoyancyDefault (cubic_centimeter) 2012-10-08T17:56:12.758Z,1349718972.758 [CommandLine](INFO): VerticalControl.massDefault (centimeter) 2012-10-08T17:56:12.759Z,1349718972.759 [CommandLine](INFO): Config/workSite.defaultScript (none) 2012-10-08T17:56:12.762Z,1349718972.762 [CommandLine](INFO): Config/Simulator.defaultDensity (kilogram_per_cubic_meter) 2012-10-08T17:56:12.771Z,1349718972.771 [CommandLine](INFO): Default.NeedGPS (bool) 2012-10-08T17:56:21.051Z,1349718981.051 [CommandLine](IMPORTANT): got command get VerticalControl.massDefault 2012-10-08T17:56:21.052Z,1349718981.052 [CommandLine](IMPORTANT): VerticalControl.massDefault 0.000000 centimeter 2012-10-08T17:56:45.483Z,1349719005.483 [CommandLine](IMPORTANT): got command ibit 2012-10-08T17:56:45.688Z,1349719005.688 [IBIT](IMPORTANT): Beginning Initiated BIT 2012-10-08T17:56:45.688Z,1349719005.688 [IBIT](IMPORTANT): Beginning control surface checks. 2012-10-08T17:56:45.689Z,1349719005.689 [CBIT](IMPORTANT): Beginning GF scan 2012-10-08T17:56:46.460Z,1349719006.460 [Radio_Freewave](INFO): Powering down 2012-10-08T17:56:46.869Z,1349719006.869 [Radio_Freewave](INFO): Powering up 2012-10-08T17:57:12.184Z,1349719032.184 [CBIT](IMPORTANT): No ground fault detected 2012-10-08T17:58:36.609Z,1349719116.609 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired. 2012-10-08T17:58:37.013Z,1349719117.013 [IBIT](IMPORTANT): batteryCapacityThreshold: 5.000000 Ah 2012-10-08T17:58:37.013Z,1349719117.013 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.500000 V 2012-10-08T17:58:37.013Z,1349719117.013 [IBIT](FAULT): Battery Data not active 2012-10-08T17:58:37.415Z,1349719117.415 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2012-10-08T17:58:37.415Z,1349719117.415 [IBIT](IMPORTANT): bitPressureThreshold: 1.500000 psi 2012-10-08T17:58:37.416Z,1349719117.416 [IBIT](IMPORTANT): Pressure:7.548070 PSI 2012-10-08T17:58:37.416Z,1349719117.416 [IBIT](IMPORTANT): Humidity:37.015877 % 2012-10-08T17:58:37.815Z,1349719117.815 [IBIT](IMPORTANT): surfaceThreshold: 0.500000 m 2012-10-08T17:58:37.815Z,1349719117.815 [IBIT](IMPORTANT): buoyancyDefault: 945.000000 cc 2012-10-08T17:58:37.815Z,1349719117.815 [IBIT](IMPORTANT): stopDepth: 125.000000 m 2012-10-08T17:58:37.816Z,1349719117.816 [IBIT](IMPORTANT): abortDepth: 150.000000 m 2012-10-08T17:58:37.816Z,1349719117.816 [IBIT](IMPORTANT): IBIT FAILED 2012-10-08T17:58:38.204Z,1349719118.204 [Startup:StartupSatComms:A](INFO): Timed out from 2012-10-08T17:55:54.9Z 2012-10-08T17:58:38.204Z,1349719118.204 [Startup:StartupSatComms:A:A_Timeout] Running Loop=1 2012-10-08T17:58:38.204Z,1349719118.204 [Startup:StartupSatComms:A:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:A:A_Timeout 2012-10-08T17:58:38.205Z,1349719118.204 [Startup:StartupSatComms:A:A_Timeout](INFO): Completed Startup:StartupSatComms:A:A_Timeout 2012-10-08T17:58:38.205Z,1349719118.205 [Startup:StartupSatComms:A] Stopped 2012-10-08T17:58:38.205Z,1349719118.205 [Startup:StartupSatComms:B] Running Loop=1 2012-10-08T17:58:38.614Z,1349719118.614 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2012-10-08T17:59:38.288Z,1349719178.288 [Startup:StartupSatComms:B](INFO): Timed out from 2012-10-08T17:58:38.2Z 2012-10-08T17:59:38.288Z,1349719178.288 [Startup:StartupSatComms:B:A_Timeout] Running Loop=1 2012-10-08T17:59:38.288Z,1349719178.288 [Startup:StartupSatComms:B:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:B:A_Timeout 2012-10-08T17:59:38.289Z,1349719178.289 [Startup:StartupSatComms:B:A_Timeout](INFO): Completed Startup:StartupSatComms:B:A_Timeout 2012-10-08T17:59:38.289Z,1349719178.289 [Startup:StartupSatComms:B] Stopped 2012-10-08T17:59:38.289Z,1349719178.289 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2012-10-08T17:59:38.289Z,1349719178.289 [Startup:StartupSatComms] Stopped 2012-10-08T17:59:38.289Z,1349719178.289 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms 2012-10-08T17:59:38.290Z,1349719178.290 [Startup](INFO): Completed Startup 2012-10-08T17:59:38.290Z,1349719178.290 [Startup] Stopped 2012-10-08T17:59:38.290Z,1349719178.290 [Startup](INFO): Aggregate::uninitialize Startup 2012-10-08T17:59:38.291Z,1349719178.291 [Startup:A.GoToSurface] Stopped 2012-10-08T17:59:38.291Z,1349719178.291 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-10-08T17:59:38.687Z,1349719178.687 [MissionManager](IMPORTANT): Started mission Default 2012-10-08T17:59:38.687Z,1349719178.687 [Default] Running Loop=1 2012-10-08T17:59:38.688Z,1349719178.688 [Default](INFO): Aggregate::initialize Default 2012-10-08T17:59:38.688Z,1349719178.688 [Default:D.SetSpeed] Running Loop=1 2012-10-08T17:59:38.688Z,1349719178.688 [Default:D.SetSpeed](DEBUG): Initialize. 2012-10-08T17:59:38.688Z,1349719178.688 [Default:E.GoToSurface] Running Loop=1 2012-10-08T17:59:38.688Z,1349719178.688 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-10-08T17:59:38.688Z,1349719178.688 [Default:Iridium] Running Loop=1 2012-10-08T17:59:38.688Z,1349719178.688 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2012-10-08T17:59:38.688Z,1349719178.688 [Default:Iridium:A.SetSpeed] Running Loop=1 2012-10-08T17:59:38.688Z,1349719178.688 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2012-10-08T17:59:38.689Z,1349719178.689 [Default:Iridium:B.GoToSurface] Running Loop=1 2012-10-08T17:59:38.689Z,1349719178.689 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-10-08T17:59:38.689Z,1349719178.689 [Default:E.GoToSurface] Running Loop=1 2012-10-08T17:59:38.695Z,1349719178.695 [Default:D.SetSpeed] Running Loop=1 2012-10-08T17:59:38.700Z,1349719178.700 [Default:CallIridium] Running Loop=1 2012-10-08T17:59:38.700Z,1349719178.700 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2012-10-08T17:59:38.700Z,1349719178.700 [Default:CallIridium:A] Running Loop=1 2012-10-08T17:59:38.702Z,1349719178.702 [Default:CallIridium:A] Stopped 2012-10-08T17:59:38.702Z,1349719178.702 [Default:CallIridium:B] Running Loop=1 2012-10-08T17:59:38.702Z,1349719178.702 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2012-10-08T17:59:38.707Z,1349719178.707 [Default:Iridium:B.GoToSurface] Stopped 2012-10-08T17:59:38.707Z,1349719178.707 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-10-08T17:59:38.708Z,1349719178.708 [Default:Iridium:Read_Iridium] Running Loop=1 2012-10-08T17:59:38.708Z,1349719178.708 [Default:Iridium:A.SetSpeed] Running Loop=1 2012-10-08T17:59:38.712Z,1349719178.712 [Default:GPS] Running Loop=1 2012-10-08T17:59:38.712Z,1349719178.713 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2012-10-08T17:59:38.713Z,1349719178.713 [Default:GPS:A.SetSpeed] Running Loop=1 2012-10-08T17:59:38.713Z,1349719178.713 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2012-10-08T17:59:38.713Z,1349719178.713 [Default:GPS:B.GoToSurface] Running Loop=1 2012-10-08T17:59:38.713Z,1349719178.713 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-10-08T17:59:38.718Z,1349719178.718 [Default:GPS:B.GoToSurface] Stopped 2012-10-08T17:59:38.718Z,1349719178.718 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-10-08T17:59:38.718Z,1349719178.718 [Default:GPS:Read_GPS] Running Loop=1 2012-10-08T17:59:38.718Z,1349719178.718 [Default:GPS:A.SetSpeed] Running Loop=1 2012-10-08T17:59:39.085Z,1349719179.085 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2012-10-08T17:59:39.088Z,1349719179.088 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2012-10-08T18:05:01.728Z,1349719501.728 [NAL9602](FAULT): GPS failed to acquire within timeout. 2012-10-08T18:05:01.728Z,1349719501.728 [NAL9602] Data Fault, FailCount= 1 2012-10-08T18:05:01.729Z,1349719501.728 [NAL9602](ERROR): Data Fault 2012-10-08T18:05:01.752Z,1349719501.752 [CBIT](ERROR): Data Fault in component: NAL9602 2012-10-08T18:05:02.124Z,1349719502.124 [NAL9602](INFO): Powering down 2012-10-08T18:05:02.148Z,1349719502.148 [CBIT](INFO): Clearing failed state for component NAL9602 2012-10-08T18:05:02.148Z,1349719502.148 [NAL9602] No Fault, FailCount= 1 2012-10-08T18:05:07.319Z,1349719507.319 [NAL9602](INFO): Powering up NAL9602 2012-10-08T18:05:18.147Z,1349719518.147 [NAL9602](INFO): NAL9602 initialized 2012-10-08T18:15:21.462Z,1349720121.462 [NAL9602](FAULT): GPS failed to acquire within timeout. 2012-10-08T18:15:21.462Z,1349720121.462 [NAL9602] Data Fault, FailCount= 2 2012-10-08T18:15:21.462Z,1349720121.462 [NAL9602](ERROR): Data Fault 2012-10-08T18:15:21.486Z,1349720121.486 [CBIT](ERROR): Data Fault in component: NAL9602 2012-10-08T18:15:21.486Z,1349720121.486 [CBIT](CRITICAL): Data Fault in component: NAL9602 2012-10-08T18:15:21.868Z,1349720121.868 [NAL9602](INFO): Powering down 2012-10-08T18:17:21.485Z,1349720241.485 [CBIT](INFO): Clearing failed count for component NAL9602 2012-10-08T18:17:21.486Z,1349720241.486 [NAL9602] No Fault, FailCount= 2 2012-10-08T18:17:21.869Z,1349720241.869 [NAL9602](INFO): Powering up NAL9602 2012-10-08T18:17:32.691Z,1349720252.691 [NAL9602](INFO): NAL9602 initialized 2012-10-08T18:18:16.927Z,1349720296.927 [CommandLine](IMPORTANT): got command load 2012-10-08T18:18:16.927Z,1349720296.927 [CommandLine](FAULT): Incomplete syntax. Try: help load 2012-10-08T18:18:28.727Z,1349720308.727 [CommandLine](IMPORTANT): got command ibit 2012-10-08T18:18:28.964Z,1349720308.964 [IBIT](IMPORTANT): Beginning Initiated BIT 2012-10-08T18:18:28.964Z,1349720308.964 [IBIT](IMPORTANT): Beginning control surface checks. 2012-10-08T18:18:28.966Z,1349720308.966 [CBIT](IMPORTANT): Beginning GF scan 2012-10-08T18:18:29.183Z,1349720309.183 [IBIT](IMPORTANT): Beginning Initiated BIT 2012-10-08T18:18:29.184Z,1349720309.184 [IBIT](IMPORTANT): Beginning control surface checks. 2012-10-08T18:18:29.565Z,1349720309.565 [Radio_Freewave](INFO): Powering down 2012-10-08T18:18:29.968Z,1349720309.968 [Radio_Freewave](INFO): Powering up 2012-10-08T18:18:33.335Z,1349720313.335 [RudderServo](FAULT): Overload Error 2012-10-08T18:18:33.335Z,1349720313.335 [RudderServo] Hardware Fault, FailCount= 1 2012-10-08T18:18:33.335Z,1349720313.335 [RudderServo](ERROR): Hardware Fault 2012-10-08T18:18:33.366Z,1349720313.365 [CBIT](ERROR): Hardware Fault in component: RudderServo 2012-10-08T18:18:33.616Z,1349720313.616 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2012-10-08T18:18:33.616Z,1349720313.616 [RudderServo](INFO): Powering down 2012-10-08T18:18:33.620Z,1349720313.620 [CBIT](INFO): Clearing failed state for component RudderServo 2012-10-08T18:18:33.620Z,1349720313.620 [RudderServo] No Fault, FailCount= 1 2012-10-08T18:18:34.408Z,1349720314.408 [RudderServo](DEBUG): Initializing EZServoServo. 2012-10-08T18:18:34.528Z,1349720314.528 [RudderServo](DEBUG): Initialization error opening port: port not yet opened 2012-10-08T18:18:34.528Z,1349720314.528 [RudderServo](DEBUG): Initializing RudderServo. 2012-10-08T18:18:39.571Z,1349720319.571 [RudderServo](FAULT): Overload Error 2012-10-08T18:18:39.571Z,1349720319.571 [RudderServo] Hardware Fault, FailCount= 2 2012-10-08T18:18:39.571Z,1349720319.571 [RudderServo](ERROR): Hardware Fault 2012-10-08T18:18:39.604Z,1349720319.604 [CBIT](ERROR): Hardware Fault in component: RudderServo 2012-10-08T18:18:39.920Z,1349720319.920 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2012-10-08T18:18:39.920Z,1349720319.921 [RudderServo](INFO): Powering down 2012-10-08T18:18:39.928Z,1349720319.928 [CBIT](INFO): Clearing failed state for component RudderServo 2012-10-08T18:18:39.928Z,1349720319.928 [RudderServo] No Fault, FailCount= 2 2012-10-08T18:18:40.718Z,1349720320.718 [RudderServo](DEBUG): Initializing EZServoServo. 2012-10-08T18:18:40.836Z,1349720320.836 [RudderServo](DEBUG): Initialization error opening port: port not yet opened 2012-10-08T18:18:40.836Z,1349720320.836 [RudderServo](DEBUG): Initializing RudderServo. 2012-10-08T18:18:44.389Z,1349720324.389 [IBIT](FAULT): Rudder: EXPECTED:15.000000 ACTUAL:17.612930 2012-10-08T18:18:44.389Z,1349720324.389 [IBIT](FAULT): Control surface position failure. 2012-10-08T18:18:46.006Z,1349720326.006 [RudderServo](FAULT): Overload Error 2012-10-08T18:18:46.007Z,1349720326.007 [RudderServo] Hardware Fault, FailCount= 3 2012-10-08T18:18:46.007Z,1349720326.007 [RudderServo](ERROR): Hardware Fault 2012-10-08T18:18:46.034Z,1349720326.034 [CBIT](ERROR): Hardware Fault in component: RudderServo 2012-10-08T18:18:46.034Z,1349720326.034 [CBIT](CRITICAL): Hardware Fault in component: RudderServo 2012-10-08T18:18:46.250Z,1349720326.250 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2012-10-08T18:18:46.250Z,1349720326.250 [RudderServo](INFO): Powering down 2012-10-08T18:18:54.889Z,1349720334.889 [CBIT](IMPORTANT): No ground fault detected 2012-10-08T18:20:20.279Z,1349720420.279 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired. 2012-10-08T18:20:20.678Z,1349720420.678 [IBIT](IMPORTANT): batteryCapacityThreshold: 5.000000 Ah 2012-10-08T18:20:20.678Z,1349720420.678 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.500000 V 2012-10-08T18:20:20.678Z,1349720420.678 [IBIT](FAULT): Battery Data not active 2012-10-08T18:20:21.074Z,1349720421.074 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2012-10-08T18:20:21.074Z,1349720421.074 [IBIT](IMPORTANT): bitPressureThreshold: 1.500000 psi 2012-10-08T18:20:21.075Z,1349720421.075 [IBIT](IMPORTANT): Pressure:8.079079 PSI 2012-10-08T18:20:21.075Z,1349720421.075 [IBIT](IMPORTANT): Humidity:37.744759 % 2012-10-08T18:20:21.978Z,1349720421.977 [IBIT](IMPORTANT): surfaceThreshold: 0.500000 m 2012-10-08T18:20:21.978Z,1349720421.978 [IBIT](IMPORTANT): buoyancyDefault: 945.000000 cc 2012-10-08T18:20:21.978Z,1349720421.978 [IBIT](IMPORTANT): stopDepth: 125.000000 m 2012-10-08T18:20:21.979Z,1349720421.978 [IBIT](IMPORTANT): abortDepth: 150.000000 m 2012-10-08T18:20:21.979Z,1349720421.979 [IBIT](IMPORTANT): IBIT FAILED 2012-10-08T18:27:33.784Z,1349720853.784 [NAL9602](FAULT): GPS failed to acquire within timeout. 2012-10-08T18:27:33.784Z,1349720853.784 [NAL9602] Data Fault, FailCount= 1 2012-10-08T18:27:33.784Z,1349720853.784 [NAL9602](ERROR): Data Fault 2012-10-08T18:27:33.807Z,1349720853.807 [CBIT](ERROR): Data Fault in component: NAL9602 2012-10-08T18:27:34.178Z,1349720854.178 [NAL9602](INFO): Powering down 2012-10-08T18:27:34.202Z,1349720854.202 [CBIT](INFO): Clearing failed state for component NAL9602 2012-10-08T18:27:34.202Z,1349720854.202 [NAL9602] No Fault, FailCount= 1 2012-10-08T18:27:39.397Z,1349720859.397 [NAL9602](INFO): Powering up NAL9602 2012-10-08T18:27:50.207Z,1349720870.207 [NAL9602](INFO): NAL9602 initialized 2012-10-08T18:33:46.317Z,1349721226.317 [CBIT](INFO): Clearing failed count for component RudderServo 2012-10-08T18:33:46.317Z,1349721226.317 [RudderServo] No Fault, FailCount= 3 2012-10-08T18:33:46.930Z,1349721226.930 [RudderServo](DEBUG): Initializing EZServoServo. 2012-10-08T18:33:47.047Z,1349721227.047 [RudderServo](DEBUG): Initialization error opening port: port not yet opened 2012-10-08T18:33:47.047Z,1349721227.047 [RudderServo](DEBUG): Initializing RudderServo. 2012-10-08T18:33:51.687Z,1349721231.687 [RudderServo](FAULT): Overload Error 2012-10-08T18:33:51.687Z,1349721231.687 [RudderServo] Hardware Fault, FailCount= 1 2012-10-08T18:33:51.687Z,1349721231.687 [RudderServo](ERROR): Hardware Fault 2012-10-08T18:33:51.714Z,1349721231.714 [CBIT](ERROR): Hardware Fault in component: RudderServo 2012-10-08T18:33:52.067Z,1349721232.067 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2012-10-08T18:33:52.067Z,1349721232.067 [RudderServo](INFO): Powering down 2012-10-08T18:33:52.070Z,1349721232.070 [CBIT](INFO): Clearing failed state for component RudderServo 2012-10-08T18:33:52.070Z,1349721232.070 [RudderServo] No Fault, FailCount= 1 2012-10-08T18:33:52.864Z,1349721232.864 [RudderServo](DEBUG): Initializing EZServoServo. 2012-10-08T18:33:52.984Z,1349721232.984 [RudderServo](DEBUG): Initialization error opening port: port not yet opened 2012-10-08T18:33:52.984Z,1349721232.984 [RudderServo](DEBUG): Initializing RudderServo. 2012-10-08T18:33:57.990Z,1349721237.990 [RudderServo](FAULT): Overload Error 2012-10-08T18:33:57.991Z,1349721237.991 [RudderServo] Hardware Fault, FailCount= 2 2012-10-08T18:33:57.991Z,1349721237.991 [RudderServo](ERROR): Hardware Fault 2012-10-08T18:33:58.017Z,1349721238.017 [CBIT](ERROR): Hardware Fault in component: RudderServo 2012-10-08T18:33:58.370Z,1349721238.370 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2012-10-08T18:33:58.370Z,1349721238.370 [RudderServo](INFO): Powering down 2012-10-08T18:33:58.373Z,1349721238.373 [CBIT](INFO): Clearing failed state for component RudderServo 2012-10-08T18:33:58.373Z,1349721238.373 [RudderServo] No Fault, FailCount= 2 2012-10-08T18:33:59.667Z,1349721239.667 [RudderServo](DEBUG): Initializing EZServoServo. 2012-10-08T18:33:59.787Z,1349721239.787 [RudderServo](DEBUG): Initialization error opening port: port not yet opened 2012-10-08T18:33:59.788Z,1349721239.788 [RudderServo](DEBUG): Initializing RudderServo. 2012-10-08T18:34:04.359Z,1349721244.359 [RudderServo](FAULT): Overload Error 2012-10-08T18:34:04.359Z,1349721244.359 [RudderServo] Hardware Fault, FailCount= 3 2012-10-08T18:34:04.359Z,1349721244.359 [RudderServo](ERROR): Hardware Fault 2012-10-08T18:34:04.385Z,1349721244.385 [CBIT](ERROR): Hardware Fault in component: RudderServo 2012-10-08T18:34:04.386Z,1349721244.386 [CBIT](CRITICAL): Hardware Fault in component: RudderServo 2012-10-08T18:34:04.737Z,1349721244.737 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2012-10-08T18:34:04.737Z,1349721244.737 [RudderServo](INFO): Powering down 2012-10-08T18:37:53.590Z,1349721473.590 [NAL9602](FAULT): GPS failed to acquire within timeout. 2012-10-08T18:37:53.590Z,1349721473.590 [NAL9602] Data Fault, FailCount= 2 2012-10-08T18:37:53.590Z,1349721473.590 [NAL9602](ERROR): Data Fault 2012-10-08T18:37:53.616Z,1349721473.616 [CBIT](ERROR): Data Fault in component: NAL9602 2012-10-08T18:37:53.617Z,1349721473.616 [CBIT](CRITICAL): Data Fault in component: NAL9602 2012-10-08T18:37:54.000Z,1349721474.000 [NAL9602](INFO): Powering down 2012-10-08T18:39:53.615Z,1349721593.615 [CBIT](INFO): Clearing failed count for component NAL9602 2012-10-08T18:39:53.615Z,1349721593.615 [NAL9602] No Fault, FailCount= 2 2012-10-08T18:39:53.997Z,1349721593.997 [NAL9602](INFO): Powering up NAL9602 2012-10-08T18:40:04.819Z,1349721604.819 [NAL9602](INFO): NAL9602 initialized 2012-10-08T18:49:04.730Z,1349722144.730 [CBIT](INFO): Clearing failed count for component RudderServo 2012-10-08T18:49:04.730Z,1349722144.730 [RudderServo] No Fault, FailCount= 3 2012-10-08T18:49:06.031Z,1349722146.031 [RudderServo](DEBUG): Initializing EZServoServo. 2012-10-08T18:49:06.152Z,1349722146.151 [RudderServo](DEBUG): Initialization error opening port: port not yet opened 2012-10-08T18:49:06.152Z,1349722146.152 [RudderServo](DEBUG): Initializing RudderServo. 2012-10-08T18:49:10.723Z,1349722150.723 [RudderServo](FAULT): Overload Error 2012-10-08T18:49:10.723Z,1349722150.723 [RudderServo] Hardware Fault, FailCount= 1 2012-10-08T18:49:10.723Z,1349722150.723 [RudderServo](ERROR): Hardware Fault 2012-10-08T18:49:10.749Z,1349722150.750 [CBIT](ERROR): Hardware Fault in component: RudderServo 2012-10-08T18:49:11.105Z,1349722151.105 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2012-10-08T18:49:11.105Z,1349722151.105 [RudderServo](INFO): Powering down 2012-10-08T18:49:11.108Z,1349722151.108 [CBIT](INFO): Clearing failed state for component RudderServo 2012-10-08T18:49:11.108Z,1349722151.108 [RudderServo] No Fault, FailCount= 1 2012-10-08T18:49:11.909Z,1349722151.909 [RudderServo](DEBUG): Initializing EZServoServo. 2012-10-08T18:49:12.028Z,1349722152.028 [RudderServo](DEBUG): Initialization error opening port: port not yet opened 2012-10-08T18:49:12.028Z,1349722152.028 [RudderServo](DEBUG): Initializing RudderServo. 2012-10-08T18:49:16.627Z,1349722156.626 [RudderServo](FAULT): Overload Error 2012-10-08T18:49:16.627Z,1349722156.627 [RudderServo] Hardware Fault, FailCount= 2 2012-10-08T18:49:16.627Z,1349722156.627 [RudderServo](ERROR): Hardware Fault 2012-10-08T18:49:16.657Z,1349722156.657 [CBIT](ERROR): Hardware Fault in component: RudderServo 2012-10-08T18:49:17.004Z,1349722157.004 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2012-10-08T18:49:17.004Z,1349722157.004 [RudderServo](INFO): Powering down 2012-10-08T18:49:17.007Z,1349722157.007 [CBIT](INFO): Clearing failed state for component RudderServo 2012-10-08T18:49:17.008Z,1349722157.008 [RudderServo] No Fault, FailCount= 2 2012-10-08T18:49:18.303Z,1349722158.303 [RudderServo](DEBUG): Initializing EZServoServo. 2012-10-08T18:49:18.424Z,1349722158.424 [RudderServo](DEBUG): Initialization error opening port: port not yet opened 2012-10-08T18:49:18.424Z,1349722158.424 [RudderServo](DEBUG): Initializing RudderServo. 2012-10-08T18:49:22.990Z,1349722162.990 [RudderServo](FAULT): Overload Error 2012-10-08T18:49:22.991Z,1349722162.991 [RudderServo] Hardware Fault, FailCount= 3 2012-10-08T18:49:22.991Z,1349722162.991 [RudderServo](ERROR): Hardware Fault 2012-10-08T18:49:23.018Z,1349722163.017 [CBIT](ERROR): Hardware Fault in component: RudderServo 2012-10-08T18:49:23.018Z,1349722163.018 [CBIT](CRITICAL): Hardware Fault in component: RudderServo 2012-10-08T18:49:23.367Z,1349722163.367 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2012-10-08T18:49:23.367Z,1349722163.367 [RudderServo](INFO): Powering down 2012-10-08T18:50:06.184Z,1349722206.184 [NAL9602](FAULT): GPS failed to acquire within timeout. 2012-10-08T18:50:06.184Z,1349722206.184 [NAL9602] Data Fault, FailCount= 1 2012-10-08T18:50:06.184Z,1349722206.184 [NAL9602](ERROR): Data Fault 2012-10-08T18:50:06.207Z,1349722206.207 [CBIT](ERROR): Data Fault in component: NAL9602 2012-10-08T18:50:06.578Z,1349722206.578 [NAL9602](INFO): Powering down 2012-10-08T18:50:06.604Z,1349722206.605 [CBIT](INFO): Clearing failed state for component NAL9602 2012-10-08T18:50:06.605Z,1349722206.605 [NAL9602] No Fault, FailCount= 1 2012-10-08T18:50:11.785Z,1349722211.785 [NAL9602](INFO): Powering up NAL9602 2012-10-08T18:50:22.607Z,1349722222.607 [NAL9602](INFO): NAL9602 initialized 2012-10-08T19:00:27.012Z,1349722827.012 [NAL9602](FAULT): GPS failed to acquire within timeout. 2012-10-08T19:00:27.012Z,1349722827.012 [NAL9602] Data Fault, FailCount= 2 2012-10-08T19:00:27.012Z,1349722827.012 [NAL9602](ERROR): Data Fault 2012-10-08T19:00:27.036Z,1349722827.036 [CBIT](ERROR): Data Fault in component: NAL9602 2012-10-08T19:00:27.036Z,1349722827.036 [CBIT](CRITICAL): Data Fault in component: NAL9602 2012-10-08T19:00:27.408Z,1349722827.408 [NAL9602](INFO): Powering down 2012-10-08T19:02:27.031Z,1349722947.031 [CBIT](INFO): Clearing failed count for component NAL9602 2012-10-08T19:02:27.031Z,1349722947.031 [NAL9602] No Fault, FailCount= 2 2012-10-08T19:02:27.409Z,1349722947.409 [NAL9602](INFO): Powering up NAL9602 2012-10-08T19:02:38.227Z,1349722958.227 [NAL9602](INFO): NAL9602 initialized 2012-10-08T19:04:23.125Z,1349723063.125 [CBIT](INFO): Clearing failed count for component RudderServo 2012-10-08T19:04:23.125Z,1349723063.125 [RudderServo] No Fault, FailCount= 3 2012-10-08T19:04:23.915Z,1349723063.915 [RudderServo](DEBUG): Initializing EZServoServo. 2012-10-08T19:04:24.036Z,1349723064.036 [RudderServo](DEBUG): Initialization error opening port: port not yet opened 2012-10-08T19:04:24.036Z,1349723064.036 [RudderServo](DEBUG): Initializing RudderServo. 2012-10-08T19:04:29.054Z,1349723069.055 [RudderServo](FAULT): Overload Error 2012-10-08T19:04:29.055Z,1349723069.055 [RudderServo] Hardware Fault, FailCount= 1 2012-10-08T19:04:29.055Z,1349723069.055 [RudderServo](ERROR): Hardware Fault 2012-10-08T19:04:29.081Z,1349723069.081 [CBIT](ERROR): Hardware Fault in component: RudderServo 2012-10-08T19:04:29.431Z,1349723069.431 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2012-10-08T19:04:29.431Z,1349723069.431 [RudderServo](INFO): Powering down 2012-10-08T19:04:29.435Z,1349723069.434 [CBIT](INFO): Clearing failed state for component RudderServo 2012-10-08T19:04:29.435Z,1349723069.435 [RudderServo] No Fault, FailCount= 1 2012-10-08T19:04:30.732Z,1349723070.732 [RudderServo](DEBUG): Initializing EZServoServo. 2012-10-08T19:04:30.852Z,1349723070.852 [RudderServo](DEBUG): Initialization error opening port: port not yet opened 2012-10-08T19:04:30.852Z,1349723070.852 [RudderServo](DEBUG): Initializing RudderServo. 2012-10-08T19:04:35.611Z,1349723075.611 [RudderServo](FAULT): Overload Error 2012-10-08T19:04:35.611Z,1349723075.611 [RudderServo] Hardware Fault, FailCount= 2 2012-10-08T19:04:35.611Z,1349723075.611 [RudderServo](ERROR): Hardware Fault 2012-10-08T19:04:35.638Z,1349723075.638 [CBIT](ERROR): Hardware Fault in component: RudderServo 2012-10-08T19:04:35.933Z,1349723075.933 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2012-10-08T19:04:35.933Z,1349723075.933 [RudderServo](INFO): Powering down 2012-10-08T19:04:35.940Z,1349723075.940 [CBIT](INFO): Clearing failed state for component RudderServo 2012-10-08T19:04:35.941Z,1349723075.941 [RudderServo] No Fault, FailCount= 2 2012-10-08T19:04:36.722Z,1349723076.722 [RudderServo](DEBUG): Initializing EZServoServo. 2012-10-08T19:04:36.840Z,1349723076.840 [RudderServo](DEBUG): Initialization error opening port: port not yet opened 2012-10-08T19:04:36.840Z,1349723076.840 [RudderServo](DEBUG): Initializing RudderServo. 2012-10-08T19:04:41.943Z,1349723081.943 [RudderServo](FAULT): Overload Error 2012-10-08T19:04:41.943Z,1349723081.943 [RudderServo] Hardware Fault, FailCount= 3 2012-10-08T19:04:41.943Z,1349723081.943 [RudderServo](ERROR): Hardware Fault 2012-10-08T19:04:41.973Z,1349723081.973 [CBIT](ERROR): Hardware Fault in component: RudderServo 2012-10-08T19:04:41.974Z,1349723081.974 [CBIT](CRITICAL): Hardware Fault in component: RudderServo 2012-10-08T19:04:42.290Z,1349723082.290 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2012-10-08T19:04:42.290Z,1349723082.290 [RudderServo](INFO): Powering down 2012-10-08T19:12:39.052Z,1349723559.052 [NAL9602](FAULT): GPS failed to acquire within timeout. 2012-10-08T19:12:39.052Z,1349723559.052 [NAL9602] Data Fault, FailCount= 1 2012-10-08T19:12:39.052Z,1349723559.052 [NAL9602](ERROR): Data Fault 2012-10-08T19:12:39.152Z,1349723559.152 [CBIT](ERROR): Data Fault in component: NAL9602 2012-10-08T19:12:39.456Z,1349723559.456 [NAL9602](INFO): Powering down 2012-10-08T19:12:39.513Z,1349723559.513 [CBIT](INFO): Clearing failed state for component NAL9602 2012-10-08T19:12:39.513Z,1349723559.513 [NAL9602] No Fault, FailCount= 1 2012-10-08T19:12:44.725Z,1349723564.725 [NAL9602](INFO): Powering up NAL9602 2012-10-08T19:12:55.155Z,1349723575.155 [NAL9602](INFO): NAL9602 initialized 2012-10-08T19:12:55.998Z,1349723575.998 [NAL9602](ERROR): getFix uart error: serial timeout 2012-10-08T19:19:41.988Z,1349723981.988 [CBIT](INFO): Clearing failed count for component RudderServo 2012-10-08T19:19:41.988Z,1349723981.988 [RudderServo] No Fault, FailCount= 3 2012-10-08T19:19:42.772Z,1349723982.772 [RudderServo](DEBUG): Initializing EZServoServo. 2012-10-08T19:19:42.892Z,1349723982.892 [RudderServo](DEBUG): Initialization error opening port: port not yet opened 2012-10-08T19:19:42.892Z,1349723982.892 [RudderServo](DEBUG): Initializing RudderServo. 2012-10-08T19:20:55.771Z,1349724055.771 [CommandLine](IMPORTANT): got command failComponent 2012-10-08T19:20:55.771Z,1349724055.771 [CommandLine](IMPORTANT): Failed components: 2012-10-08T19:20:55.771Z,1349724055.771 [CommandLine](IMPORTANT): No failed Components. 2012-10-08T19:21:00.155Z,1349724060.155 [CommandLine](IMPORTANT): got command ibit 2012-10-08T19:21:00.425Z,1349724060.425 [IBIT](IMPORTANT): Beginning Initiated BIT 2012-10-08T19:21:00.425Z,1349724060.425 [IBIT](IMPORTANT): Beginning control surface checks. 2012-10-08T19:21:00.426Z,1349724060.426 [CBIT](IMPORTANT): Beginning GF scan 2012-10-08T19:21:01.212Z,1349724061.212 [Radio_Freewave](INFO): Powering down 2012-10-08T19:21:01.610Z,1349724061.610 [Radio_Freewave](INFO): Powering up 2012-10-08T19:21:26.877Z,1349724086.877 [CBIT](IMPORTANT): No ground fault detected 2012-10-08T19:22:50.945Z,1349724170.945 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired. 2012-10-08T19:22:51.159Z,1349724171.159 [IBIT](IMPORTANT): batteryCapacityThreshold: 5.000000 Ah 2012-10-08T19:22:51.159Z,1349724171.159 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.500000 V 2012-10-08T19:22:51.159Z,1349724171.159 [IBIT](FAULT): Battery Data not active 2012-10-08T19:22:51.552Z,1349724171.552 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2012-10-08T19:22:51.552Z,1349724171.552 [IBIT](IMPORTANT): bitPressureThreshold: 1.500000 psi 2012-10-08T19:22:51.553Z,1349724171.553 [IBIT](IMPORTANT): Pressure:7.017062 PSI 2012-10-08T19:22:51.553Z,1349724171.553 [IBIT](IMPORTANT): Humidity:36.683674 % 2012-10-08T19:22:51.959Z,1349724171.958 [IBIT](IMPORTANT): surfaceThreshold: 0.500000 m 2012-10-08T19:22:51.959Z,1349724171.959 [IBIT](IMPORTANT): buoyancyDefault: 945.000000 cc 2012-10-08T19:22:51.959Z,1349724171.959 [IBIT](IMPORTANT): stopDepth: 125.000000 m 2012-10-08T19:22:51.960Z,1349724171.960 [IBIT](IMPORTANT): abortDepth: 150.000000 m 2012-10-08T19:22:51.960Z,1349724171.960 [IBIT](IMPORTANT): IBIT FAILED 2012-10-08T19:22:56.236Z,1349724176.236 [NAL9602](FAULT): GPS failed to acquire within timeout. 2012-10-08T19:22:56.236Z,1349724176.236 [NAL9602] Data Fault, FailCount= 2 2012-10-08T19:22:56.236Z,1349724176.236 [NAL9602](ERROR): Data Fault 2012-10-08T19:22:56.259Z,1349724176.260 [CBIT](ERROR): Data Fault in component: NAL9602 2012-10-08T19:22:56.260Z,1349724176.260 [CBIT](CRITICAL): Data Fault in component: NAL9602 2012-10-08T19:22:56.636Z,1349724176.636 [NAL9602](INFO): Powering down 2012-10-08T19:24:56.259Z,1349724296.259 [CBIT](INFO): Clearing failed count for component NAL9602 2012-10-08T19:24:56.259Z,1349724296.259 [NAL9602] No Fault, FailCount= 2 2012-10-08T19:24:56.631Z,1349724296.631 [NAL9602](INFO): Powering up NAL9602 2012-10-08T19:25:07.455Z,1349724307.455 [NAL9602](INFO): NAL9602 initialized 2012-10-08T19:25:08.302Z,1349724308.302 [NAL9602](ERROR): getFix uart error: serial timeout