2013-05-22T01:31:51.430Z,1369186311.430 [Supervisor](DEBUG): Initializing supervisor. 2013-05-22T01:31:51.438Z,1369186311.438 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0 2013-05-22T01:31:51.439Z,1369186311.439 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2013-05-22T01:31:51.442Z,1369186311.442 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0 2013-05-22T01:31:51.446Z,1369186311.446 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2013-05-22T01:31:51.457Z,1369186311.457 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2013-05-22T01:31:51.458Z,1369186311.458 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0 2013-05-22T01:31:51.459Z,1369186311.459 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2013-05-22T01:31:51.462Z,1369186311.462 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0 2013-05-22T01:31:51.463Z,1369186311.463 [Supervisor](INFO): Looking for Config files in directory: Config/ 2013-05-22T01:31:51.467Z,1369186311.467 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2013-05-22T01:31:51.809Z,1369186311.809 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2013-05-22T01:31:51.810Z,1369186311.810 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2013-05-22T01:31:52.035Z,1369186312.035 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2013-05-22T01:31:52.035Z,1369186312.035 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2013-05-22T01:31:52.133Z,1369186312.133 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2013-05-22T01:31:52.136Z,1369186312.136 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2013-05-22T01:31:52.379Z,1369186312.379 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2013-05-22T01:31:52.380Z,1369186312.380 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2013-05-22T01:31:52.539Z,1369186312.539 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2013-05-22T01:31:52.541Z,1369186312.541 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2013-05-22T01:31:52.827Z,1369186312.827 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2013-05-22T01:31:52.828Z,1369186312.828 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2013-05-22T01:31:53.027Z,1369186313.027 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2013-05-22T01:31:53.029Z,1369186313.029 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2013-05-22T01:31:53.343Z,1369186313.343 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2013-05-22T01:31:53.345Z,1369186313.345 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2013-05-22T01:31:53.463Z,1369186313.463 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2013-05-22T01:31:53.463Z,1369186313.464 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2013-05-22T01:31:53.948Z,1369186313.948 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2013-05-22T01:31:53.949Z,1369186313.949 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2013-05-22T01:31:54.123Z,1369186314.123 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2013-05-22T01:31:54.124Z,1369186314.124 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2013-05-22T01:31:54.228Z,1369186314.228 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2013-05-22T01:31:54.235Z,1369186314.235 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2013-05-22T01:31:54.355Z,1369186314.355 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2013-05-22T01:31:54.506Z,1369186314.506 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2013-05-22T01:31:54.683Z,1369186314.683 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2013-05-22T01:31:54.803Z,1369186314.803 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2013-05-22T01:31:54.919Z,1369186314.919 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2013-05-22T01:31:55.058Z,1369186315.058 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2013-05-22T01:31:55.167Z,1369186315.167 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2013-05-22T01:31:55.266Z,1369186315.266 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2013-05-22T01:31:55.303Z,1369186315.303 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2013-05-22T01:31:55.516Z,1369186315.516 [InternalSim] Loaded 2013-05-22T01:31:55.516Z,1369186315.516 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread. 2013-05-22T01:31:55.517Z,1369186315.517 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2013-05-22T01:31:55.518Z,1369186315.518 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2013-05-22T01:31:55.609Z,1369186315.609 [SBIT](DEBUG): Construct Startup Built In Test. 2013-05-22T01:31:55.644Z,1369186315.644 [SBIT] Loaded 2013-05-22T01:31:55.645Z,1369186315.645 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2013-05-22T01:31:55.646Z,1369186315.646 [IBIT](DEBUG): Construct Initiated Built In Test. 2013-05-22T01:31:55.681Z,1369186315.681 [IBIT] Loaded 2013-05-22T01:31:55.681Z,1369186315.681 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2013-05-22T01:31:55.684Z,1369186315.684 [CBIT](DEBUG): Construct CBIT Built In Test. 2013-05-22T01:31:55.822Z,1369186315.822 [CBIT] Loaded 2013-05-22T01:31:55.826Z,1369186315.826 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2013-05-22T01:31:55.827Z,1369186315.827 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2013-05-22T01:31:55.827Z,1369186315.827 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2013-05-22T01:31:56.009Z,1369186316.009 [BuoyancyServo] Loaded 2013-05-22T01:31:56.009Z,1369186316.009 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2013-05-22T01:31:56.026Z,1369186316.026 [ElevatorServo] Loaded 2013-05-22T01:31:56.026Z,1369186316.026 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2013-05-22T01:31:56.039Z,1369186316.039 [MassServo] Loaded 2013-05-22T01:31:56.039Z,1369186316.039 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2013-05-22T01:31:56.052Z,1369186316.052 [RudderServo] Loaded 2013-05-22T01:31:56.052Z,1369186316.052 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2013-05-22T01:31:56.069Z,1369186316.069 [ThrusterServo] Loaded 2013-05-22T01:31:56.069Z,1369186316.069 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2013-05-22T01:31:56.069Z,1369186316.069 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2013-05-22T01:31:56.070Z,1369186316.070 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2013-05-22T01:31:56.108Z,1369186316.108 [DepthRateCalculator] Loaded 2013-05-22T01:31:56.108Z,1369186316.108 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2013-05-22T01:32:00.104Z,1369186320.104 [HFRadarModelCalc] Loaded 2013-05-22T01:32:00.104Z,1369186320.104 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread. 2013-05-22T01:32:00.121Z,1369186320.121 [NavChart] Loaded 2013-05-22T01:32:00.122Z,1369186320.122 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2013-05-22T01:32:00.132Z,1369186320.132 [PitchRateCalculator] Loaded 2013-05-22T01:32:00.132Z,1369186320.132 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2013-05-22T01:32:00.144Z,1369186320.144 [SpeedCalculator] Loaded 2013-05-22T01:32:00.145Z,1369186320.145 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2013-05-22T01:32:00.161Z,1369186320.161 [TempGradientCalculator] Loaded 2013-05-22T01:32:00.161Z,1369186320.161 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2013-05-22T01:32:00.171Z,1369186320.171 [YawRateCalculator] Loaded 2013-05-22T01:32:00.171Z,1369186320.171 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2013-05-22T01:32:00.225Z,1369186320.225 [Navigation] Loaded 2013-05-22T01:32:00.225Z,1369186320.225 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread. 2013-05-22T01:32:00.226Z,1369186320.226 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2013-05-22T01:32:00.226Z,1369186320.226 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2013-05-22T01:32:00.527Z,1369186320.527 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2013-05-22T01:32:00.528Z,1369186320.528 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2013-05-22T01:32:00.567Z,1369186320.567 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2013-05-22T01:32:00.568Z,1369186320.568 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2013-05-22T01:32:00.636Z,1369186320.636 [VerticalControl](DEBUG): Construct VerticalControl. 2013-05-22T01:32:00.743Z,1369186320.743 [VerticalControl] Loaded 2013-05-22T01:32:00.743Z,1369186320.743 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2013-05-22T01:32:00.745Z,1369186320.745 [HorizontalControl](DEBUG): Construct HorizontalControl. 2013-05-22T01:32:00.812Z,1369186320.812 [HorizontalControl] Loaded 2013-05-22T01:32:00.813Z,1369186320.813 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2013-05-22T01:32:00.814Z,1369186320.814 [SpeedControl](DEBUG): Construct SpeedControl. 2013-05-22T01:32:00.815Z,1369186320.815 [SpeedControl] Loaded 2013-05-22T01:32:00.816Z,1369186320.816 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2013-05-22T01:32:00.817Z,1369186320.817 [LoopControl](DEBUG): Construct LoopControl. 2013-05-22T01:32:00.817Z,1369186320.817 [LoopControl] Loaded 2013-05-22T01:32:00.818Z,1369186320.818 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2013-05-22T01:32:00.822Z,1369186320.822 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2013-05-22T01:32:00.823Z,1369186320.823 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2013-05-22T01:32:00.831Z,1369186320.831 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator. 2013-05-22T01:32:00.836Z,1369186320.836 [AsyncPiEstimator] Loaded 2013-05-22T01:32:00.837Z,1369186320.837 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread. 2013-05-22T01:32:00.838Z,1369186320.838 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 4063B4E0 2013-05-22T01:32:00.839Z,1369186320.839 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2013-05-22T01:32:00.840Z,1369186320.839 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2013-05-22T01:32:01.032Z,1369186321.032 [AHRS_sp3003D] Loaded 2013-05-22T01:32:01.032Z,1369186321.032 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread. 2013-05-22T01:32:01.338Z,1369186321.339 [Batt_Ocean_Server] Loaded 2013-05-22T01:32:01.339Z,1369186321.339 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread. 2013-05-22T01:32:01.354Z,1369186321.354 [Depth_Keller] Loaded 2013-05-22T01:32:01.354Z,1369186321.354 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2013-05-22T01:32:01.360Z,1369186321.360 [DropWeight] Loaded 2013-05-22T01:32:01.361Z,1369186321.361 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2013-05-22T01:32:01.564Z,1369186321.564 [DVL_micro] Loaded 2013-05-22T01:32:01.565Z,1369186321.565 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread. 2013-05-22T01:32:01.566Z,1369186321.566 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 406B64E0 2013-05-22T01:32:01.664Z,1369186321.664 [NAL9602] Loaded 2013-05-22T01:32:01.664Z,1369186321.664 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2013-05-22T01:32:01.728Z,1369186321.728 [Onboard] Loaded 2013-05-22T01:32:01.728Z,1369186321.728 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2013-05-22T01:32:01.735Z,1369186321.735 [Radio_Freewave] Loaded 2013-05-22T01:32:01.735Z,1369186321.735 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread. 2013-05-22T01:32:01.919Z,1369186321.919 [DAT] Loaded 2013-05-22T01:32:01.919Z,1369186321.920 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2013-05-22T01:32:01.920Z,1369186321.920 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2013-05-22T01:32:01.921Z,1369186321.921 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2013-05-22T01:32:02.030Z,1369186322.030 [CTD_NeilBrown] Loaded 2013-05-22T01:32:02.030Z,1369186322.030 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2013-05-22T01:32:02.034Z,1369186322.034 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 407084E0 2013-05-22T01:32:02.071Z,1369186322.071 [WetLabsBB2FL] Loaded 2013-05-22T01:32:02.072Z,1369186322.072 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2013-05-22T01:32:02.074Z,1369186322.074 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407384E0 2013-05-22T01:32:02.075Z,1369186322.075 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2013-05-22T01:32:02.077Z,1369186322.077 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2013-05-22T01:32:02.078Z,1369186322.078 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2013-05-22T01:32:02.088Z,1369186322.088 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2013-05-22T01:32:02.090Z,1369186322.090 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 407684E0 2013-05-22T01:32:02.094Z,1369186322.095 [Supervisor](DEBUG): Running supervisor. 2013-05-22T01:32:02.096Z,1369186322.096 [CommandLine](INFO): Thread ID is 751 2013-05-22T01:32:02.099Z,1369186322.099 [controlThread](INFO): Thread ID is 750 2013-05-22T01:32:02.099Z,1369186322.099 [controlThread](DEBUG): Initializing ControlThread 2013-05-22T01:32:02.100Z,1369186322.099 [CycleStarter](INFO): Thread ID is 749 2013-05-22T01:32:02.100Z,1369186322.100 [InternalSim](DEBUG): InternalSim initializing... 2013-05-22T01:32:02.207Z,1369186322.207 [logger](INFO): Thread ID is 752 2013-05-22T01:32:02.315Z,1369186322.315 [AsyncPiEstimator](INFO): Thread ID is 813 2013-05-22T01:32:02.315Z,1369186322.315 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator. 2013-05-22T01:32:02.331Z,1369186322.331 [DVL_micro](INFO): Thread ID is 814 2013-05-22T01:32:02.465Z,1369186322.465 [DVL_micro](INFO): Initializing 2013-05-22T01:32:02.465Z,1369186322.465 [DVL_micro](INFO): start:Powering up 2013-05-22T01:32:02.466Z,1369186322.466 [CTD_NeilBrown](INFO): Thread ID is 815 2013-05-22T01:32:02.467Z,1369186322.467 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown. 2013-05-22T01:32:02.469Z,1369186322.469 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-05-22T01:32:02.471Z,1369186322.471 [WetLabsBB2FL](INFO): Thread ID is 816 2013-05-22T01:32:02.472Z,1369186322.471 [WetLabsBB2FL](INFO): Powering down 2013-05-22T01:32:02.495Z,1369186322.495 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4 2013-05-22T01:32:02.503Z,1369186322.503 [DVL_micro](INFO): Cycling power to configure device. 2013-05-22T01:32:02.507Z,1369186322.507 [NavChartDb](INFO): Thread ID is 817 2013-05-22T01:32:02.527Z,1369186322.527 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources 2013-05-22T01:32:02.527Z,1369186322.527 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2013-05-22T01:32:02.528Z,1369186322.528 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2013-05-22T01:32:02.528Z,1369186322.528 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2013-05-22T01:32:02.528Z,1369186322.528 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2013-05-22T01:32:02.529Z,1369186322.529 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2013-05-22T01:32:02.529Z,1369186322.529 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2013-05-22T01:32:02.529Z,1369186322.529 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2013-05-22T01:32:02.529Z,1369186322.529 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2013-05-22T01:32:02.548Z,1369186322.548 [SBIT](INFO): Initialize SBIT Component. 2013-05-22T01:32:02.548Z,1369186322.548 [SBIT](IMPORTANT): Tethys CM Info: $Rev:10376 2013-05-22T01:32:02.549Z,1369186322.549 [SBIT](IMPORTANT): Kernel Release:2.6.27.8 2013-05-22T01:32:02.549Z,1369186322.549 [SBIT](IMPORTANT): Kernel Version:#634 PREEMPT Wed Feb 13 10:21:48 PST 2013 2013-05-22T01:32:02.549Z,1369186322.549 [IBIT](INFO): Initialize IBIT Component. 2013-05-22T01:32:02.562Z,1369186322.562 [CBIT](DEBUG): Initialize CBIT Component. 2013-05-22T01:32:02.562Z,1369186322.562 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL. 2013-05-22T01:32:02.563Z,1369186322.563 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2013-05-22T01:32:02.587Z,1369186322.587 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2013-05-22T01:32:02.588Z,1369186322.588 [NavChart](DEBUG): Initialize NavChart Derivation. 2013-05-22T01:32:02.588Z,1369186322.588 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2013-05-22T01:32:02.589Z,1369186322.589 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2013-05-22T01:32:02.589Z,1369186322.589 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2013-05-22T01:32:02.591Z,1369186322.591 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2013-05-22T01:32:02.591Z,1369186322.591 [Navigation](DEBUG): Initializing Navigation. 2013-05-22T01:32:02.591Z,1369186322.591 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2013-05-22T01:32:02.593Z,1369186322.593 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2013-05-22T01:32:02.594Z,1369186322.594 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2013-05-22T01:32:02.595Z,1369186322.595 [LoopControl](DEBUG): Initialize LoopControlComponent. 2013-05-22T01:32:04.273Z,1369186324.273 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized 2013-05-22T01:32:04.303Z,1369186324.303 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2013-05-22T01:32:04.303Z,1369186324.303 [DropWeight] Hardware Fault, FailCount= 1 2013-05-22T01:32:04.303Z,1369186324.303 [DropWeight](ERROR): Hardware Fault 2013-05-22T01:32:04.305Z,1369186324.305 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2013-05-22T01:32:04.344Z,1369186324.344 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2013-05-22T01:32:04.366Z,1369186324.366 [MissionManager](DEBUG): 2013-05-22T01:32:04.379Z,1369186324.379 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2013-05-22T01:32:04.465Z,1369186324.465 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool 2013-05-22T01:32:04.468Z,1369186324.467 [Default:GPS:A.SetSpeed](DEBUG): Construct. 2013-05-22T01:32:04.482Z,1369186324.483 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface. 2013-05-22T01:32:04.490Z,1369186324.490 [Default:Iridium:A.SetSpeed](DEBUG): Construct. 2013-05-22T01:32:04.493Z,1369186324.493 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface. 2013-05-22T01:32:04.532Z,1369186324.532 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2013-05-22T01:32:04.556Z,1369186324.556 [Default:D.SetSpeed](DEBUG): Construct. 2013-05-22T01:32:04.571Z,1369186324.571 [Default:E.GoToSurface](DEBUG): Construct GoToSurface. 2013-05-22T01:32:04.576Z,1369186324.576 [Default:F.Wait](DEBUG): Construct Wait. 2013-05-22T01:32:04.579Z,1369186324.579 [MissionManager](DEBUG): 400 400 Burn 300 Dropped drop weight due to communications timeout 5.0 1.0 5 2013-05-22T01:32:04.590Z,1369186324.591 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-05-22T01:32:04.591Z,1369186324.591 [DVL_micro](INFO): Querying output modes 2013-05-22T01:32:04.591Z,1369186324.591 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606 2013-05-22T01:32:04.596Z,1369186324.596 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,NAL9602,Onboard,Radio_Freewave,DAT,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-22T01:32:04.602Z,1369186324.602 [DVL_micro](DEBUG): cmdResponse: 01 2013-05-22T01:32:04.603Z,1369186324.603 [DVL_micro](INFO): NQ1 output enabled 2013-05-22T01:32:04.603Z,1369186324.603 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525 2013-05-22T01:32:04.614Z,1369186324.614 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 2013-05-22T01:32:04.619Z,1369186324.619 [DVL_micro](INFO): pause:Powering down 2013-05-22T01:32:04.666Z,1369186324.666 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2013-05-22T01:32:04.944Z,1369186324.944 [Radio_Freewave](INFO): Powering up 2013-05-22T01:32:04.953Z,1369186324.953 [DAT](INFO): Powering up 2013-05-22T01:32:04.953Z,1369186324.953 [DAT](DEBUG): Initializing DAT. 2013-05-22T01:32:05.167Z,1369186325.167 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2013-05-22T01:32:05.175Z,1369186325.174 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2013-05-22T01:32:05.193Z,1369186325.193 [ElevatorServo](DEBUG): Initializing EZServoServo. 2013-05-22T01:32:05.194Z,1369186325.194 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2013-05-22T01:32:05.205Z,1369186325.205 [MassServo](DEBUG): Initializing EZServoServo. 2013-05-22T01:32:05.227Z,1369186325.227 [MassServo](DEBUG): Initializing MassServo. 2013-05-22T01:32:05.232Z,1369186325.232 [RudderServo](DEBUG): Initializing EZServoServo. 2013-05-22T01:32:05.243Z,1369186325.243 [RudderServo](DEBUG): Initializing RudderServo. 2013-05-22T01:32:05.257Z,1369186325.257 [ThrusterServo](DEBUG): Initializing EZServoServo. 2013-05-22T01:32:05.270Z,1369186325.270 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2013-05-22T01:32:05.296Z,1369186325.296 [CBIT](ERROR): Hardware Fault in component: DropWeight 2013-05-22T01:32:05.296Z,1369186325.296 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2013-05-22T01:32:06.862Z,1369186326.862 [NAL9602](INFO): Powering up NAL9602 2013-05-22T01:32:17.407Z,1369186337.407 [NAL9602](INFO): NAL9602 initialized 2013-05-22T01:32:18.271Z,1369186338.271 [SBIT](IMPORTANT): Beginning Startup BIT 2013-05-22T01:32:18.274Z,1369186338.274 [CBIT](IMPORTANT): Beginning GF scan 2013-05-22T01:32:24.934Z,1369186344.934 [DAT](INFO): Powering down 2013-05-22T01:32:44.979Z,1369186364.979 [CBIT](IMPORTANT): No ground fault detected 2013-05-22T01:33:12.251Z,1369186392.251 [SBIT](IMPORTANT): SBIT PASSED 2013-05-22T01:33:12.625Z,1369186392.625 [MissionManager](IMPORTANT): Started mission Startup 2013-05-22T01:33:12.625Z,1369186392.625 [Startup] Running Loop=1 2013-05-22T01:33:12.626Z,1369186392.625 [Startup](INFO): Aggregate::initialize Startup 2013-05-22T01:33:12.626Z,1369186392.626 [Startup:A.GoToSurface] Running Loop=1 2013-05-22T01:33:12.626Z,1369186392.626 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-05-22T01:33:12.632Z,1369186392.632 [Startup:StartupSatComms] Running Loop=1 2013-05-22T01:33:12.632Z,1369186392.632 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms 2013-05-22T01:33:12.632Z,1369186392.632 [Startup:StartupSatComms:A] Running Loop=1 2013-05-22T01:33:13.022Z,1369186393.022 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2013-05-22T01:34:12.641Z,1369186452.641 [Startup:StartupSatComms:A](INFO): Timed out from 2013-05-22T01:33:12.6Z 2013-05-22T01:34:12.641Z,1369186452.641 [Startup:StartupSatComms:A:A_Timeout] Running Loop=1 2013-05-22T01:34:12.641Z,1369186452.641 [Startup:StartupSatComms:A:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:A:A_Timeout 2013-05-22T01:34:12.641Z,1369186452.641 [Startup:StartupSatComms:A:A_Timeout](INFO): Completed Startup:StartupSatComms:A:A_Timeout 2013-05-22T01:34:12.641Z,1369186452.641 [Startup:StartupSatComms:A] Stopped 2013-05-22T01:34:12.641Z,1369186452.641 [Startup:StartupSatComms:B] Running Loop=1 2013-05-22T01:34:13.068Z,1369186453.068 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2013-05-22T01:34:23.234Z,1369186463.234 [CommandLine](IMPORTANT): got command ibit 2013-05-22T01:34:23.769Z,1369186463.769 [IBIT](IMPORTANT): Beginning Initiated BIT 2013-05-22T01:34:23.769Z,1369186463.769 [IBIT](IMPORTANT): Beginning control surface checks. 2013-05-22T01:34:23.771Z,1369186463.771 [CBIT](IMPORTANT): Beginning GF scan 2013-05-22T01:34:23.998Z,1369186463.998 [IBIT](IMPORTANT): Beginning Initiated BIT 2013-05-22T01:34:23.998Z,1369186463.999 [IBIT](IMPORTANT): Beginning control surface checks. 2013-05-22T01:34:24.361Z,1369186464.361 [Radio_Freewave](INFO): Powering down 2013-05-22T01:34:25.181Z,1369186465.181 [Radio_Freewave](INFO): Powering up 2013-05-22T01:34:50.001Z,1369186490.001 [CBIT](IMPORTANT): No ground fault detected 2013-05-22T01:35:50.114Z,1369186550.114 [CommandLine](IMPORTANT): got command failComponent 2013-05-22T01:35:50.115Z,1369186550.115 [CommandLine](IMPORTANT): Failed components: 2013-05-22T01:35:50.115Z,1369186550.115 [CommandLine](IMPORTANT): DropWeight: Hardware Fault 2013-05-22T01:36:14.692Z,1369186574.692 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired. 2013-05-22T01:36:15.148Z,1369186575.148 [IBIT](IMPORTANT): Battery Status: Battery Charge (AH): 239.880005 Voltage: 16.299438 2013-05-22T01:36:15.148Z,1369186575.148 [IBIT](IMPORTANT): batteryCapacityThreshold: 5.000000 Ah 2013-05-22T01:36:15.148Z,1369186575.148 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.500000 V 2013-05-22T01:36:15.491Z,1369186575.491 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2013-05-22T01:36:15.492Z,1369186575.492 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2013-05-22T01:36:15.492Z,1369186575.492 [IBIT](IMPORTANT): Pressure:17.637238 PSI 2013-05-22T01:36:15.492Z,1369186575.492 [IBIT](IMPORTANT): Humidity:26.202860 % 2013-05-22T01:36:15.908Z,1369186575.908 [IBIT](IMPORTANT): surfaceThreshold: 0.500000 m 2013-05-22T01:36:15.908Z,1369186575.908 [IBIT](IMPORTANT): buoyancyNeutral: 450.000000 cc 2013-05-22T01:36:15.909Z,1369186575.909 [IBIT](IMPORTANT): massDefault: 0.000000 cm 2013-05-22T01:36:15.909Z,1369186575.909 [IBIT](IMPORTANT): stopDepth: 60.000000 m 2013-05-22T01:36:15.909Z,1369186575.909 [IBIT](IMPORTANT): abortDepth: 70.000000 m 2013-05-22T01:36:15.909Z,1369186575.909 [IBIT](IMPORTANT): IBIT FAILED 2013-05-22T01:36:16.269Z,1369186576.269 [Startup:StartupSatComms:B](INFO): Timed out from 2013-05-22T01:34:12.6Z 2013-05-22T01:36:16.269Z,1369186576.270 [Startup:StartupSatComms:B:A_Timeout] Running Loop=1 2013-05-22T01:36:16.270Z,1369186576.270 [Startup:StartupSatComms:B:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:B:A_Timeout 2013-05-22T01:36:16.270Z,1369186576.270 [Startup:StartupSatComms:B:A_Timeout](INFO): Completed Startup:StartupSatComms:B:A_Timeout 2013-05-22T01:36:16.270Z,1369186576.270 [Startup:StartupSatComms:B] Stopped 2013-05-22T01:36:16.270Z,1369186576.270 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2013-05-22T01:36:16.271Z,1369186576.270 [Startup:StartupSatComms] Stopped 2013-05-22T01:36:16.271Z,1369186576.271 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms 2013-05-22T01:36:16.271Z,1369186576.272 [Startup](INFO): Completed Startup 2013-05-22T01:36:16.272Z,1369186576.272 [Startup] Stopped 2013-05-22T01:36:16.272Z,1369186576.272 [Startup](INFO): Aggregate::uninitialize Startup 2013-05-22T01:36:16.272Z,1369186576.272 [Startup:A.GoToSurface] Stopped 2013-05-22T01:36:16.272Z,1369186576.272 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-05-22T01:36:16.684Z,1369186576.684 [MissionManager](IMPORTANT): Started mission Default 2013-05-22T01:36:16.684Z,1369186576.684 [Default] Running Loop=1 2013-05-22T01:36:16.684Z,1369186576.684 [Default](INFO): Aggregate::initialize Default 2013-05-22T01:36:16.684Z,1369186576.684 [Default:D.SetSpeed] Running Loop=1 2013-05-22T01:36:16.684Z,1369186576.684 [Default:D.SetSpeed](DEBUG): Initialize. 2013-05-22T01:36:16.684Z,1369186576.684 [Default:E.GoToSurface] Running Loop=1 2013-05-22T01:36:16.685Z,1369186576.685 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-05-22T01:36:16.685Z,1369186576.685 [Default:Iridium] Running Loop=1 2013-05-22T01:36:16.685Z,1369186576.685 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2013-05-22T01:36:16.685Z,1369186576.685 [Default:Iridium:A.SetSpeed] Running Loop=1 2013-05-22T01:36:16.685Z,1369186576.685 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2013-05-22T01:36:16.685Z,1369186576.685 [Default:Iridium:B.GoToSurface] Running Loop=1 2013-05-22T01:36:16.686Z,1369186576.685 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-05-22T01:36:16.686Z,1369186576.686 [Default:E.GoToSurface] Running Loop=1 2013-05-22T01:36:16.691Z,1369186576.691 [Default:D.SetSpeed] Running Loop=1 2013-05-22T01:36:16.696Z,1369186576.696 [Default:CallIridium] Running Loop=1 2013-05-22T01:36:16.696Z,1369186576.696 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2013-05-22T01:36:16.696Z,1369186576.696 [Default:CallIridium:A] Running Loop=1 2013-05-22T01:36:16.698Z,1369186576.698 [Default:CallIridium:A] Stopped 2013-05-22T01:36:16.698Z,1369186576.698 [Default:CallIridium:B] Running Loop=1 2013-05-22T01:36:16.698Z,1369186576.698 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2013-05-22T01:36:16.703Z,1369186576.703 [Default:Iridium:B.GoToSurface] Stopped 2013-05-22T01:36:16.703Z,1369186576.703 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-05-22T01:36:16.703Z,1369186576.703 [Default:Iridium:Read_Iridium] Running Loop=1 2013-05-22T01:36:16.703Z,1369186576.704 [Default:Iridium:A.SetSpeed] Running Loop=1 2013-05-22T01:36:16.708Z,1369186576.708 [Default:GPS] Running Loop=1 2013-05-22T01:36:16.708Z,1369186576.708 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2013-05-22T01:36:16.708Z,1369186576.708 [Default:GPS:A.SetSpeed] Running Loop=1 2013-05-22T01:36:16.709Z,1369186576.708 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2013-05-22T01:36:16.709Z,1369186576.709 [Default:GPS:B.GoToSurface] Running Loop=1 2013-05-22T01:36:16.709Z,1369186576.709 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-05-22T01:36:16.755Z,1369186576.755 [Default:GPS:B.GoToSurface] Stopped 2013-05-22T01:36:16.756Z,1369186576.756 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-05-22T01:36:16.758Z,1369186576.758 [Default:GPS:Read_GPS] Running Loop=1 2013-05-22T01:36:16.758Z,1369186576.758 [Default:GPS:A.SetSpeed] Running Loop=1 2013-05-22T01:36:17.573Z,1369186577.573 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2013-05-22T01:36:17.576Z,1369186577.576 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix