2013-05-07T16:23:00.082Z,1367943780.082 [Supervisor](DEBUG): Initializing supervisor. 2013-05-07T16:23:00.084Z,1367943780.084 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0 2013-05-07T16:23:00.085Z,1367943780.085 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2013-05-07T16:23:00.086Z,1367943780.086 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0 2013-05-07T16:23:00.090Z,1367943780.090 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2013-05-07T16:23:00.101Z,1367943780.101 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2013-05-07T16:23:00.102Z,1367943780.102 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0 2013-05-07T16:23:00.102Z,1367943780.102 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2013-05-07T16:23:00.104Z,1367943780.103 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0 2013-05-07T16:23:00.104Z,1367943780.104 [Supervisor](INFO): Looking for Config files in directory: Config/ 2013-05-07T16:23:00.105Z,1367943780.105 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2013-05-07T16:23:00.395Z,1367943780.395 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2013-05-07T16:23:00.396Z,1367943780.396 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2013-05-07T16:23:00.585Z,1367943780.585 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2013-05-07T16:23:00.586Z,1367943780.586 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2013-05-07T16:23:00.670Z,1367943780.670 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2013-05-07T16:23:00.670Z,1367943780.670 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2013-05-07T16:23:00.870Z,1367943780.870 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2013-05-07T16:23:00.871Z,1367943780.871 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2013-05-07T16:23:01.007Z,1367943781.007 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2013-05-07T16:23:01.008Z,1367943781.008 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2013-05-07T16:23:01.240Z,1367943781.240 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2013-05-07T16:23:01.241Z,1367943781.241 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2013-05-07T16:23:01.412Z,1367943781.412 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2013-05-07T16:23:01.412Z,1367943781.412 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2013-05-07T16:23:01.663Z,1367943781.663 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2013-05-07T16:23:01.663Z,1367943781.663 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2013-05-07T16:23:01.761Z,1367943781.761 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2013-05-07T16:23:01.762Z,1367943781.762 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2013-05-07T16:23:02.165Z,1367943782.165 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2013-05-07T16:23:02.166Z,1367943782.165 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2013-05-07T16:23:02.280Z,1367943782.280 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2013-05-07T16:23:02.281Z,1367943782.281 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2013-05-07T16:23:02.366Z,1367943782.366 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2013-05-07T16:23:02.367Z,1367943782.367 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2013-05-07T16:23:02.471Z,1367943782.471 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2013-05-07T16:23:02.599Z,1367943782.599 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2013-05-07T16:23:02.684Z,1367943782.684 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2013-05-07T16:23:02.789Z,1367943782.789 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2013-05-07T16:23:02.891Z,1367943782.891 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2013-05-07T16:23:03.011Z,1367943783.011 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2013-05-07T16:23:03.107Z,1367943783.107 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2013-05-07T16:23:03.193Z,1367943783.193 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2013-05-07T16:23:03.218Z,1367943783.218 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2013-05-07T16:23:03.374Z,1367943783.374 [InternalSim] Loaded 2013-05-07T16:23:03.374Z,1367943783.374 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread. 2013-05-07T16:23:03.375Z,1367943783.375 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2013-05-07T16:23:03.376Z,1367943783.376 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2013-05-07T16:23:03.437Z,1367943783.437 [SBIT](DEBUG): Construct Startup Built In Test. 2013-05-07T16:23:03.466Z,1367943783.466 [SBIT] Loaded 2013-05-07T16:23:03.467Z,1367943783.467 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2013-05-07T16:23:03.468Z,1367943783.468 [IBIT](DEBUG): Construct Initiated Built In Test. 2013-05-07T16:23:03.498Z,1367943783.498 [IBIT] Loaded 2013-05-07T16:23:03.498Z,1367943783.499 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2013-05-07T16:23:03.502Z,1367943783.502 [CBIT](DEBUG): Construct CBIT Built In Test. 2013-05-07T16:23:03.626Z,1367943783.625 [CBIT] Loaded 2013-05-07T16:23:03.626Z,1367943783.626 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2013-05-07T16:23:03.626Z,1367943783.626 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2013-05-07T16:23:03.627Z,1367943783.627 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2013-05-07T16:23:03.779Z,1367943783.779 [BuoyancyServo] Loaded 2013-05-07T16:23:03.780Z,1367943783.780 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2013-05-07T16:23:03.792Z,1367943783.792 [ElevatorServo] Loaded 2013-05-07T16:23:03.793Z,1367943783.793 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2013-05-07T16:23:03.805Z,1367943783.805 [MassServo] Loaded 2013-05-07T16:23:03.806Z,1367943783.806 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2013-05-07T16:23:03.818Z,1367943783.818 [RudderServo] Loaded 2013-05-07T16:23:03.818Z,1367943783.819 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2013-05-07T16:23:03.831Z,1367943783.831 [ThrusterServo] Loaded 2013-05-07T16:23:03.831Z,1367943783.831 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2013-05-07T16:23:03.831Z,1367943783.831 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2013-05-07T16:23:03.832Z,1367943783.832 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2013-05-07T16:23:03.900Z,1367943783.900 [DepthRateCalculator] Loaded 2013-05-07T16:23:03.900Z,1367943783.901 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2013-05-07T16:23:06.895Z,1367943786.895 [HFRadarModelCalc] Loaded 2013-05-07T16:23:06.896Z,1367943786.896 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread. 2013-05-07T16:23:06.912Z,1367943786.912 [NavChart] Loaded 2013-05-07T16:23:06.913Z,1367943786.913 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2013-05-07T16:23:06.919Z,1367943786.919 [PitchRateCalculator] Loaded 2013-05-07T16:23:06.919Z,1367943786.919 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2013-05-07T16:23:06.930Z,1367943786.930 [SpeedCalculator] Loaded 2013-05-07T16:23:06.931Z,1367943786.931 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2013-05-07T16:23:06.947Z,1367943786.947 [TempGradientCalculator] Loaded 2013-05-07T16:23:06.947Z,1367943786.947 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2013-05-07T16:23:06.953Z,1367943786.953 [YawRateCalculator] Loaded 2013-05-07T16:23:06.954Z,1367943786.954 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2013-05-07T16:23:07.002Z,1367943787.003 [Navigation] Loaded 2013-05-07T16:23:07.003Z,1367943787.003 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread. 2013-05-07T16:23:07.003Z,1367943787.003 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2013-05-07T16:23:07.004Z,1367943787.004 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2013-05-07T16:23:07.225Z,1367943787.225 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2013-05-07T16:23:07.226Z,1367943787.226 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2013-05-07T16:23:07.248Z,1367943787.248 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2013-05-07T16:23:07.249Z,1367943787.249 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2013-05-07T16:23:07.291Z,1367943787.291 [VerticalControl](DEBUG): Construct VerticalControl. 2013-05-07T16:23:07.388Z,1367943787.388 [VerticalControl] Loaded 2013-05-07T16:23:07.388Z,1367943787.388 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2013-05-07T16:23:07.389Z,1367943787.389 [HorizontalControl](DEBUG): Construct HorizontalControl. 2013-05-07T16:23:07.448Z,1367943787.448 [HorizontalControl] Loaded 2013-05-07T16:23:07.448Z,1367943787.448 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2013-05-07T16:23:07.449Z,1367943787.449 [SpeedControl](DEBUG): Construct SpeedControl. 2013-05-07T16:23:07.451Z,1367943787.451 [SpeedControl] Loaded 2013-05-07T16:23:07.451Z,1367943787.451 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2013-05-07T16:23:07.452Z,1367943787.452 [LoopControl](DEBUG): Construct LoopControl. 2013-05-07T16:23:07.453Z,1367943787.453 [LoopControl] Loaded 2013-05-07T16:23:07.453Z,1367943787.453 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2013-05-07T16:23:07.454Z,1367943787.454 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2013-05-07T16:23:07.454Z,1367943787.454 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2013-05-07T16:23:07.460Z,1367943787.460 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator. 2013-05-07T16:23:07.465Z,1367943787.465 [AsyncPiEstimator] Loaded 2013-05-07T16:23:07.465Z,1367943787.465 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread. 2013-05-07T16:23:07.467Z,1367943787.467 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 4063B4E0 2013-05-07T16:23:07.467Z,1367943787.467 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2013-05-07T16:23:07.468Z,1367943787.468 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2013-05-07T16:23:07.596Z,1367943787.596 [AHRS_sp3003D] Loaded 2013-05-07T16:23:07.597Z,1367943787.597 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread. 2013-05-07T16:23:07.867Z,1367943787.867 [Batt_Ocean_Server] Loaded 2013-05-07T16:23:07.867Z,1367943787.867 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread. 2013-05-07T16:23:07.882Z,1367943787.882 [Depth_Keller] Loaded 2013-05-07T16:23:07.882Z,1367943787.882 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2013-05-07T16:23:07.888Z,1367943787.888 [DropWeight] Loaded 2013-05-07T16:23:07.888Z,1367943787.888 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2013-05-07T16:23:08.068Z,1367943788.068 [DVL_micro] Loaded 2013-05-07T16:23:08.068Z,1367943788.068 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread. 2013-05-07T16:23:08.069Z,1367943788.069 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 406C04E0 2013-05-07T16:23:08.155Z,1367943788.155 [NAL9602] Loaded 2013-05-07T16:23:08.155Z,1367943788.155 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2013-05-07T16:23:08.208Z,1367943788.208 [Onboard] Loaded 2013-05-07T16:23:08.209Z,1367943788.209 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2013-05-07T16:23:08.216Z,1367943788.216 [Radio_Freewave] Loaded 2013-05-07T16:23:08.216Z,1367943788.216 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread. 2013-05-07T16:23:08.217Z,1367943788.217 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2013-05-07T16:23:08.217Z,1367943788.217 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2013-05-07T16:23:08.291Z,1367943788.291 [CTD_NeilBrown] Loaded 2013-05-07T16:23:08.291Z,1367943788.291 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2013-05-07T16:23:08.292Z,1367943788.292 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 407124E0 2013-05-07T16:23:08.325Z,1367943788.325 [WetLabsBB2FL] Loaded 2013-05-07T16:23:08.326Z,1367943788.326 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2013-05-07T16:23:08.327Z,1367943788.327 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407424E0 2013-05-07T16:23:08.327Z,1367943788.328 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2013-05-07T16:23:08.330Z,1367943788.330 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2013-05-07T16:23:08.331Z,1367943788.331 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2013-05-07T16:23:08.338Z,1367943788.338 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2013-05-07T16:23:08.339Z,1367943788.339 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 407724E0 2013-05-07T16:23:08.343Z,1367943788.343 [Supervisor](DEBUG): Running supervisor. 2013-05-07T16:23:08.344Z,1367943788.344 [CommandLine](INFO): Thread ID is 1434 2013-05-07T16:23:08.347Z,1367943788.347 [controlThread](INFO): Thread ID is 1433 2013-05-07T16:23:08.347Z,1367943788.347 [controlThread](DEBUG): Initializing ControlThread 2013-05-07T16:23:08.347Z,1367943788.347 [CycleStarter](INFO): Thread ID is 1432 2013-05-07T16:23:08.348Z,1367943788.348 [InternalSim](DEBUG): InternalSim initializing... 2013-05-07T16:23:08.382Z,1367943788.382 [logger](INFO): Thread ID is 1435 2013-05-07T16:23:08.399Z,1367943788.399 [SBIT](INFO): Initialize SBIT Component. 2013-05-07T16:23:08.399Z,1367943788.399 [SBIT](IMPORTANT): Tethys CM Info: $Rev:10327 2013-05-07T16:23:08.400Z,1367943788.399 [SBIT](IMPORTANT): Kernel Release:2.6.27.8 2013-05-07T16:23:08.400Z,1367943788.400 [SBIT](IMPORTANT): Kernel Version:#634 PREEMPT Wed Feb 13 10:21:48 PST 2013 2013-05-07T16:23:08.400Z,1367943788.400 [IBIT](INFO): Initialize IBIT Component. 2013-05-07T16:23:08.401Z,1367943788.401 [CBIT](DEBUG): Initialize CBIT Component. 2013-05-07T16:23:08.402Z,1367943788.402 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL. 2013-05-07T16:23:08.402Z,1367943788.402 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2013-05-07T16:23:08.410Z,1367943788.410 [AsyncPiEstimator](INFO): Thread ID is 1498 2013-05-07T16:23:08.410Z,1367943788.410 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator. 2013-05-07T16:23:08.431Z,1367943788.431 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2013-05-07T16:23:08.431Z,1367943788.431 [NavChart](DEBUG): Initialize NavChart Derivation. 2013-05-07T16:23:08.431Z,1367943788.431 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2013-05-07T16:23:08.432Z,1367943788.432 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2013-05-07T16:23:08.432Z,1367943788.432 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2013-05-07T16:23:08.434Z,1367943788.434 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2013-05-07T16:23:08.434Z,1367943788.434 [Navigation](DEBUG): Initializing Navigation. 2013-05-07T16:23:08.435Z,1367943788.435 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2013-05-07T16:23:08.437Z,1367943788.437 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2013-05-07T16:23:08.437Z,1367943788.437 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2013-05-07T16:23:08.438Z,1367943788.438 [LoopControl](DEBUG): Initialize LoopControlComponent. 2013-05-07T16:23:08.441Z,1367943788.441 [DVL_micro](INFO): Thread ID is 1499 2013-05-07T16:23:08.450Z,1367943788.450 [DVL_micro](INFO): Initializing 2013-05-07T16:23:08.450Z,1367943788.450 [DVL_micro](INFO): start:Powering up 2013-05-07T16:23:08.451Z,1367943788.451 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-05-07T16:23:08.452Z,1367943788.452 [DVL_micro](INFO): Cycling power to configure device. 2013-05-07T16:23:08.474Z,1367943788.474 [CTD_NeilBrown](INFO): Thread ID is 1500 2013-05-07T16:23:08.475Z,1367943788.475 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown. 2013-05-07T16:23:08.478Z,1367943788.478 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4 2013-05-07T16:23:08.502Z,1367943788.502 [WetLabsBB2FL](INFO): Thread ID is 1501 2013-05-07T16:23:08.502Z,1367943788.503 [WetLabsBB2FL](INFO): Powering down 2013-05-07T16:23:08.526Z,1367943788.526 [NavChartDb](INFO): Thread ID is 1502 2013-05-07T16:23:08.529Z,1367943788.529 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources 2013-05-07T16:23:08.530Z,1367943788.530 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2013-05-07T16:23:08.530Z,1367943788.530 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2013-05-07T16:23:08.530Z,1367943788.530 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2013-05-07T16:23:08.530Z,1367943788.530 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2013-05-07T16:23:08.530Z,1367943788.530 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2013-05-07T16:23:08.531Z,1367943788.531 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2013-05-07T16:23:08.531Z,1367943788.531 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2013-05-07T16:23:08.531Z,1367943788.531 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2013-05-07T16:23:09.863Z,1367943789.864 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized 2013-05-07T16:23:09.907Z,1367943789.907 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2013-05-07T16:23:09.935Z,1367943789.935 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2013-05-07T16:23:09.953Z,1367943789.953 [MissionManager](DEBUG): 2013-05-07T16:23:09.966Z,1367943789.966 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2013-05-07T16:23:10.041Z,1367943790.041 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool 2013-05-07T16:23:10.043Z,1367943790.043 [Default:GPS:A.SetSpeed](DEBUG): Construct. 2013-05-07T16:23:10.058Z,1367943790.058 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface. 2013-05-07T16:23:10.066Z,1367943790.066 [Default:Iridium:A.SetSpeed](DEBUG): Construct. 2013-05-07T16:23:10.074Z,1367943790.074 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface. 2013-05-07T16:23:10.105Z,1367943790.105 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2013-05-07T16:23:10.129Z,1367943790.129 [Default:D.SetSpeed](DEBUG): Construct. 2013-05-07T16:23:10.132Z,1367943790.132 [Default:E.GoToSurface](DEBUG): Construct GoToSurface. 2013-05-07T16:23:10.149Z,1367943790.149 [Default:F.Wait](DEBUG): Construct Wait. 2013-05-07T16:23:10.153Z,1367943790.153 [MissionManager](DEBUG): 400 400 Burn 300 Dropped drop weight due to communications timeout 5.0 1.0 5 2013-05-07T16:23:10.169Z,1367943790.169 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,NAL9602,Onboard,Radio_Freewave,Depth_Keller,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter, 2013-05-07T16:23:10.221Z,1367943790.221 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2013-05-07T16:23:10.270Z,1367943790.270 [Depth_Keller](ERROR): Pressure reading out of range: 1831.078247 decibar 2013-05-07T16:23:10.349Z,1367943790.349 [Radio_Freewave](INFO): Powering up 2013-05-07T16:23:10.482Z,1367943790.482 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-05-07T16:23:10.482Z,1367943790.482 [DVL_micro](INFO): Querying output modes 2013-05-07T16:23:10.482Z,1367943790.482 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606 2013-05-07T16:23:10.493Z,1367943790.493 [DVL_micro](DEBUG): cmdResponse: 01 2013-05-07T16:23:10.494Z,1367943790.494 [DVL_micro](INFO): NQ1 output enabled 2013-05-07T16:23:10.494Z,1367943790.494 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525 2013-05-07T16:23:10.506Z,1367943790.506 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 2013-05-07T16:23:10.511Z,1367943790.510 [DVL_micro](INFO): pause:Powering down 2013-05-07T16:23:10.603Z,1367943790.603 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2013-05-07T16:23:10.610Z,1367943790.610 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2013-05-07T16:23:10.632Z,1367943790.632 [ElevatorServo](DEBUG): Initializing EZServoServo. 2013-05-07T16:23:10.637Z,1367943790.638 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2013-05-07T16:23:10.649Z,1367943790.649 [MassServo](DEBUG): Initializing EZServoServo. 2013-05-07T16:23:10.658Z,1367943790.658 [MassServo](DEBUG): Initializing MassServo. 2013-05-07T16:23:10.663Z,1367943790.663 [RudderServo](DEBUG): Initializing EZServoServo. 2013-05-07T16:23:10.669Z,1367943790.670 [RudderServo](DEBUG): Initializing RudderServo. 2013-05-07T16:23:10.675Z,1367943790.675 [ThrusterServo](DEBUG): Initializing EZServoServo. 2013-05-07T16:23:10.682Z,1367943790.682 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2013-05-07T16:23:13.476Z,1367943793.476 [NAL9602](INFO): Powering up NAL9602 2013-05-07T16:23:23.810Z,1367943803.810 [SBIT](IMPORTANT): Beginning Startup BIT 2013-05-07T16:23:23.812Z,1367943803.812 [CBIT](IMPORTANT): Beginning GF scan 2013-05-07T16:23:24.202Z,1367943804.202 [NAL9602](INFO): NAL9602 initialized 2013-05-07T16:23:50.666Z,1367943830.666 [CBIT](IMPORTANT): No ground fault detected 2013-05-07T16:23:54.234Z,1367943834.234 [CommandLine](IMPORTANT): got command get platform_battery_voltage 2013-05-07T16:23:54.234Z,1367943834.234 [CommandLine](FAULT): Element has no intrinsic unit 2013-05-07T16:24:14.641Z,1367943854.641 [CommandLine](IMPORTANT): got command failComponent 2013-05-07T16:24:14.642Z,1367943854.642 [CommandLine](IMPORTANT): Failed components: 2013-05-07T16:24:14.642Z,1367943854.642 [CommandLine](IMPORTANT): No failed Components. 2013-05-07T16:24:17.627Z,1367943857.627 [SBIT](IMPORTANT): SBIT PASSED 2013-05-07T16:24:18.034Z,1367943858.034 [MissionManager](IMPORTANT): Started mission Startup 2013-05-07T16:24:18.034Z,1367943858.034 [Startup] Running Loop=1 2013-05-07T16:24:18.034Z,1367943858.034 [Startup](INFO): Aggregate::initialize Startup 2013-05-07T16:24:18.034Z,1367943858.034 [Startup:A.GoToSurface] Running Loop=1 2013-05-07T16:24:18.034Z,1367943858.034 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-05-07T16:24:18.040Z,1367943858.040 [Startup:StartupSatComms] Running Loop=1 2013-05-07T16:24:18.040Z,1367943858.040 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms 2013-05-07T16:24:18.041Z,1367943858.040 [Startup:StartupSatComms:A] Running Loop=1 2013-05-07T16:24:18.436Z,1367943858.436 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2013-05-07T16:24:19.121Z,1367943859.121 [CommandLine](INFO): End of History 2013-05-07T16:24:23.802Z,1367943863.802 [CommandLine](IMPORTANT): got command get platform_battery_voltage 2013-05-07T16:24:23.802Z,1367943863.802 [CommandLine](FAULT): Element has no intrinsic unit 2013-05-07T16:24:45.122Z,1367943885.122 [CommandLine](IMPORTANT): got command ibit 2013-05-07T16:24:45.259Z,1367943885.259 [IBIT](IMPORTANT): Beginning Initiated BIT 2013-05-07T16:24:45.259Z,1367943885.260 [IBIT](IMPORTANT): Beginning control surface checks. 2013-05-07T16:24:45.261Z,1367943885.261 [CBIT](IMPORTANT): Beginning GF scan 2013-05-07T16:24:46.036Z,1367943886.036 [Radio_Freewave](INFO): Powering down 2013-05-07T16:24:46.862Z,1367943886.862 [Radio_Freewave](INFO): Powering up 2013-05-07T16:25:11.784Z,1367943911.784 [CBIT](IMPORTANT): No ground fault detected 2013-05-07T16:26:36.182Z,1367943996.182 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired. 2013-05-07T16:26:36.576Z,1367943996.576 [IBIT](IMPORTANT): Battery Status: Battery Charge (AH): 235.210007 Voltage: 16.298500 2013-05-07T16:26:36.576Z,1367943996.576 [IBIT](IMPORTANT): batteryCapacityThreshold: 5.000000 Ah 2013-05-07T16:26:36.577Z,1367943996.577 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.500000 V 2013-05-07T16:26:37.014Z,1367943997.014 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2013-05-07T16:26:37.015Z,1367943997.015 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2013-05-07T16:26:37.015Z,1367943997.015 [IBIT](IMPORTANT): Pressure:18.168247 PSI 2013-05-07T16:26:37.015Z,1367943997.015 [IBIT](IMPORTANT): Humidity:27.762625 % 2013-05-07T16:26:37.403Z,1367943997.404 [IBIT](IMPORTANT): surfaceThreshold: 0.500000 m 2013-05-07T16:26:37.404Z,1367943997.404 [IBIT](IMPORTANT): buoyancyNeutral: 450.000000 cc 2013-05-07T16:26:37.404Z,1367943997.404 [IBIT](IMPORTANT): massDefault: 0.000000 cm 2013-05-07T16:26:37.404Z,1367943997.404 [IBIT](IMPORTANT): stopDepth: 60.000000 m 2013-05-07T16:26:37.405Z,1367943997.405 [IBIT](IMPORTANT): abortDepth: 70.000000 m 2013-05-07T16:26:37.405Z,1367943997.405 [IBIT](IMPORTANT): IBIT FAILED 2013-05-07T16:26:37.798Z,1367943997.798 [Startup:StartupSatComms:A](INFO): Timed out from 2013-05-07T16:24:18.0Z 2013-05-07T16:26:37.798Z,1367943997.798 [Startup:StartupSatComms:A:A_Timeout] Running Loop=1 2013-05-07T16:26:37.798Z,1367943997.798 [Startup:StartupSatComms:A:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:A:A_Timeout 2013-05-07T16:26:37.798Z,1367943997.798 [Startup:StartupSatComms:A:A_Timeout](INFO): Completed Startup:StartupSatComms:A:A_Timeout 2013-05-07T16:26:37.798Z,1367943997.798 [Startup:StartupSatComms:A] Stopped 2013-05-07T16:26:37.798Z,1367943997.798 [Startup:StartupSatComms:B] Running Loop=1 2013-05-07T16:26:38.254Z,1367943998.254 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications