2013-03-03T21:54:08.723Z,1362347648.723 [Supervisor](DEBUG): Initializing supervisor. 2013-03-03T21:54:08.725Z,1362347648.725 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0 2013-03-03T21:54:08.726Z,1362347648.726 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2013-03-03T21:54:08.727Z,1362347648.727 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0 2013-03-03T21:54:08.731Z,1362347648.731 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2013-03-03T21:54:08.742Z,1362347648.742 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2013-03-03T21:54:08.743Z,1362347648.743 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0 2013-03-03T21:54:08.744Z,1362347648.744 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2013-03-03T21:54:08.745Z,1362347648.745 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0 2013-03-03T21:54:08.746Z,1362347648.746 [Supervisor](INFO): Looking for Config files in directory: Config/ 2013-03-03T21:54:08.747Z,1362347648.747 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2013-03-03T21:54:09.045Z,1362347649.046 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2013-03-03T21:54:09.046Z,1362347649.046 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2013-03-03T21:54:09.242Z,1362347649.242 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2013-03-03T21:54:09.243Z,1362347649.243 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2013-03-03T21:54:09.326Z,1362347649.326 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2013-03-03T21:54:09.327Z,1362347649.327 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2013-03-03T21:54:09.538Z,1362347649.538 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2013-03-03T21:54:09.539Z,1362347649.539 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2013-03-03T21:54:09.676Z,1362347649.676 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2013-03-03T21:54:09.677Z,1362347649.677 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2013-03-03T21:54:09.924Z,1362347649.924 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2013-03-03T21:54:09.924Z,1362347649.924 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2013-03-03T21:54:10.101Z,1362347650.101 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2013-03-03T21:54:10.101Z,1362347650.101 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2013-03-03T21:54:10.370Z,1362347650.370 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2013-03-03T21:54:10.370Z,1362347650.370 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2013-03-03T21:54:10.470Z,1362347650.470 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2013-03-03T21:54:10.470Z,1362347650.470 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2013-03-03T21:54:10.903Z,1362347650.903 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2013-03-03T21:54:10.904Z,1362347650.904 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2013-03-03T21:54:11.019Z,1362347651.019 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2013-03-03T21:54:11.020Z,1362347651.020 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2013-03-03T21:54:11.104Z,1362347651.104 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2013-03-03T21:54:11.105Z,1362347651.105 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2013-03-03T21:54:11.208Z,1362347651.208 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2013-03-03T21:54:11.341Z,1362347651.341 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2013-03-03T21:54:11.425Z,1362347651.425 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2013-03-03T21:54:11.529Z,1362347651.529 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2013-03-03T21:54:11.631Z,1362347651.631 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2013-03-03T21:54:11.753Z,1362347651.753 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2013-03-03T21:54:11.848Z,1362347651.848 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2013-03-03T21:54:11.935Z,1362347651.935 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2013-03-03T21:54:11.968Z,1362347651.968 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2013-03-03T21:54:12.133Z,1362347652.133 [InternalSim] Loaded 2013-03-03T21:54:12.133Z,1362347652.134 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread. 2013-03-03T21:54:12.134Z,1362347652.134 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2013-03-03T21:54:12.135Z,1362347652.135 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2013-03-03T21:54:12.197Z,1362347652.197 [SBIT](DEBUG): Construct Startup Built In Test. 2013-03-03T21:54:12.228Z,1362347652.228 [SBIT] Loaded 2013-03-03T21:54:12.228Z,1362347652.228 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2013-03-03T21:54:12.229Z,1362347652.229 [IBIT](DEBUG): Construct Initiated Built In Test. 2013-03-03T21:54:12.261Z,1362347652.260 [IBIT] Loaded 2013-03-03T21:54:12.261Z,1362347652.261 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2013-03-03T21:54:12.264Z,1362347652.264 [CBIT](DEBUG): Construct CBIT Built In Test. 2013-03-03T21:54:12.393Z,1362347652.393 [CBIT] Loaded 2013-03-03T21:54:12.394Z,1362347652.394 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2013-03-03T21:54:12.394Z,1362347652.394 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2013-03-03T21:54:12.395Z,1362347652.395 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2013-03-03T21:54:12.553Z,1362347652.553 [BuoyancyServo] Loaded 2013-03-03T21:54:12.554Z,1362347652.554 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2013-03-03T21:54:12.567Z,1362347652.567 [ElevatorServo] Loaded 2013-03-03T21:54:12.567Z,1362347652.567 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2013-03-03T21:54:12.580Z,1362347652.580 [MassServo] Loaded 2013-03-03T21:54:12.580Z,1362347652.580 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2013-03-03T21:54:12.593Z,1362347652.593 [RudderServo] Loaded 2013-03-03T21:54:12.594Z,1362347652.594 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2013-03-03T21:54:12.606Z,1362347652.606 [ThrusterServo] Loaded 2013-03-03T21:54:12.607Z,1362347652.607 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2013-03-03T21:54:12.607Z,1362347652.607 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2013-03-03T21:54:12.608Z,1362347652.608 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2013-03-03T21:54:12.625Z,1362347652.625 [DepthRateCalculator] Loaded 2013-03-03T21:54:12.625Z,1362347652.625 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2013-03-03T21:54:16.756Z,1362347656.756 [HFRadarModelCalc] Loaded 2013-03-03T21:54:16.757Z,1362347656.757 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread. 2013-03-03T21:54:16.774Z,1362347656.774 [NavChart] Loaded 2013-03-03T21:54:16.775Z,1362347656.775 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2013-03-03T21:54:16.781Z,1362347656.781 [PitchRateCalculator] Loaded 2013-03-03T21:54:16.781Z,1362347656.781 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2013-03-03T21:54:16.788Z,1362347656.788 [SpeedCalculator] Loaded 2013-03-03T21:54:16.789Z,1362347656.789 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2013-03-03T21:54:16.805Z,1362347656.805 [TempGradientCalculator] Loaded 2013-03-03T21:54:16.805Z,1362347656.805 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2013-03-03T21:54:16.812Z,1362347656.812 [YawRateCalculator] Loaded 2013-03-03T21:54:16.812Z,1362347656.812 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2013-03-03T21:54:16.856Z,1362347656.856 [Navigation] Loaded 2013-03-03T21:54:16.857Z,1362347656.856 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread. 2013-03-03T21:54:16.857Z,1362347656.857 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2013-03-03T21:54:16.858Z,1362347656.858 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2013-03-03T21:54:17.099Z,1362347657.099 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2013-03-03T21:54:17.100Z,1362347657.100 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2013-03-03T21:54:17.123Z,1362347657.123 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2013-03-03T21:54:17.123Z,1362347657.124 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2013-03-03T21:54:17.167Z,1362347657.167 [VerticalControl](DEBUG): Construct VerticalControl. 2013-03-03T21:54:17.268Z,1362347657.268 [VerticalControl] Loaded 2013-03-03T21:54:17.269Z,1362347657.269 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2013-03-03T21:54:17.269Z,1362347657.270 [HorizontalControl](DEBUG): Construct HorizontalControl. 2013-03-03T21:54:17.331Z,1362347657.331 [HorizontalControl] Loaded 2013-03-03T21:54:17.331Z,1362347657.331 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2013-03-03T21:54:17.332Z,1362347657.332 [SpeedControl](DEBUG): Construct SpeedControl. 2013-03-03T21:54:17.334Z,1362347657.334 [SpeedControl] Loaded 2013-03-03T21:54:17.335Z,1362347657.335 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2013-03-03T21:54:17.336Z,1362347657.336 [LoopControl](DEBUG): Construct LoopControl. 2013-03-03T21:54:17.336Z,1362347657.336 [LoopControl] Loaded 2013-03-03T21:54:17.336Z,1362347657.336 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2013-03-03T21:54:17.337Z,1362347657.337 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2013-03-03T21:54:17.337Z,1362347657.337 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2013-03-03T21:54:17.343Z,1362347657.343 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator. 2013-03-03T21:54:17.348Z,1362347657.348 [AsyncPiEstimator] Loaded 2013-03-03T21:54:17.348Z,1362347657.348 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread. 2013-03-03T21:54:17.350Z,1362347657.350 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406A44E0 2013-03-03T21:54:17.350Z,1362347657.350 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2013-03-03T21:54:17.351Z,1362347657.351 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2013-03-03T21:54:17.487Z,1362347657.487 [AHRS_sp3003D] Loaded 2013-03-03T21:54:17.487Z,1362347657.487 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread. 2013-03-03T21:54:17.797Z,1362347657.797 [Batt_Ocean_Server] Loaded 2013-03-03T21:54:17.797Z,1362347657.797 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread. 2013-03-03T21:54:17.813Z,1362347657.813 [Depth_Keller] Loaded 2013-03-03T21:54:17.813Z,1362347657.813 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2013-03-03T21:54:17.819Z,1362347657.819 [DropWeight] Loaded 2013-03-03T21:54:17.820Z,1362347657.819 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2013-03-03T21:54:18.009Z,1362347658.009 [DVL_micro] Loaded 2013-03-03T21:54:18.009Z,1362347658.009 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread. 2013-03-03T21:54:18.010Z,1362347658.010 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 407284E0 2013-03-03T21:54:18.101Z,1362347658.102 [NAL9602] Loaded 2013-03-03T21:54:18.102Z,1362347658.102 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2013-03-03T21:54:18.157Z,1362347658.157 [Onboard] Loaded 2013-03-03T21:54:18.157Z,1362347658.157 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2013-03-03T21:54:18.164Z,1362347658.164 [Radio_Freewave] Loaded 2013-03-03T21:54:18.165Z,1362347658.165 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread. 2013-03-03T21:54:18.166Z,1362347658.166 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2013-03-03T21:54:18.167Z,1362347658.167 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2013-03-03T21:54:18.230Z,1362347658.230 [Aanderaa_O2] Loaded 2013-03-03T21:54:18.231Z,1362347658.231 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread. 2013-03-03T21:54:18.267Z,1362347658.267 [CTD_NeilBrown] Loaded 2013-03-03T21:54:18.267Z,1362347658.267 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2013-03-03T21:54:18.268Z,1362347658.268 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4077A4E0 2013-03-03T21:54:18.282Z,1362347658.283 [ISUS] Loaded 2013-03-03T21:54:18.283Z,1362347658.283 [ComponentRegistry](DEBUG): SyncComponent "ISUS" handled in the control thread. 2013-03-03T21:54:18.300Z,1362347658.300 [PAR_Licor] Loaded 2013-03-03T21:54:18.300Z,1362347658.300 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2013-03-03T21:54:18.333Z,1362347658.333 [WetLabsBB2FL] Loaded 2013-03-03T21:54:18.333Z,1362347658.333 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2013-03-03T21:54:18.334Z,1362347658.334 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407AA4E0 2013-03-03T21:54:18.335Z,1362347658.335 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2013-03-03T21:54:18.337Z,1362347658.337 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2013-03-03T21:54:18.339Z,1362347658.339 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2013-03-03T21:54:18.345Z,1362347658.345 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2013-03-03T21:54:18.346Z,1362347658.346 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 407DA4E0 2013-03-03T21:54:18.351Z,1362347658.351 [Supervisor](DEBUG): Running supervisor. 2013-03-03T21:54:18.352Z,1362347658.352 [CommandLine](INFO): Thread ID is 1677 2013-03-03T21:54:18.355Z,1362347658.355 [controlThread](INFO): Thread ID is 1676 2013-03-03T21:54:18.355Z,1362347658.355 [controlThread](DEBUG): Initializing ControlThread 2013-03-03T21:54:18.356Z,1362347658.355 [CycleStarter](INFO): Thread ID is 1675 2013-03-03T21:54:18.356Z,1362347658.356 [InternalSim](DEBUG): InternalSim initializing... 2013-03-03T21:54:18.391Z,1362347658.391 [logger](INFO): Thread ID is 1678 2013-03-03T21:54:18.417Z,1362347658.417 [SBIT](INFO): Initialize SBIT Component. 2013-03-03T21:54:18.418Z,1362347658.418 [SBIT](IMPORTANT): Tethys CM Info: $Rev: 10204 2013-03-03T21:54:18.427Z,1362347658.427 [IBIT](INFO): Initialize IBIT Component. 2013-03-03T21:54:18.428Z,1362347658.428 [CBIT](DEBUG): Initialize CBIT Component. 2013-03-03T21:54:18.428Z,1362347658.428 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL. 2013-03-03T21:54:18.428Z,1362347658.428 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2013-03-03T21:54:18.429Z,1362347658.429 [AsyncPiEstimator](INFO): Thread ID is 1739 2013-03-03T21:54:18.429Z,1362347658.429 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator. 2013-03-03T21:54:18.446Z,1362347658.446 [DVL_micro](INFO): Thread ID is 1740 2013-03-03T21:54:18.452Z,1362347658.452 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2013-03-03T21:54:18.453Z,1362347658.453 [NavChart](DEBUG): Initialize NavChart Derivation. 2013-03-03T21:54:18.453Z,1362347658.453 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2013-03-03T21:54:18.453Z,1362347658.453 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2013-03-03T21:54:18.454Z,1362347658.454 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2013-03-03T21:54:18.455Z,1362347658.455 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2013-03-03T21:54:18.456Z,1362347658.455 [Navigation](DEBUG): Initializing Navigation. 2013-03-03T21:54:18.456Z,1362347658.456 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2013-03-03T21:54:18.458Z,1362347658.458 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2013-03-03T21:54:18.458Z,1362347658.458 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2013-03-03T21:54:18.464Z,1362347658.464 [DVL_micro](INFO): Initializing 2013-03-03T21:54:18.464Z,1362347658.464 [DVL_micro](INFO): start:Powering up 2013-03-03T21:54:18.465Z,1362347658.465 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-03-03T21:54:18.466Z,1362347658.466 [DVL_micro](INFO): Cycling power to configure device. 2013-03-03T21:54:18.467Z,1362347658.467 [LoopControl](DEBUG): Initialize LoopControlComponent. 2013-03-03T21:54:18.471Z,1362347658.471 [CTD_NeilBrown](INFO): Thread ID is 1741 2013-03-03T21:54:18.472Z,1362347658.472 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown. 2013-03-03T21:54:18.475Z,1362347658.476 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4 2013-03-03T21:54:18.483Z,1362347658.483 [WetLabsBB2FL](INFO): Thread ID is 1742 2013-03-03T21:54:18.484Z,1362347658.484 [WetLabsBB2FL](INFO): Powering down 2013-03-03T21:54:18.527Z,1362347658.527 [NavChartDb](INFO): Thread ID is 1743 2013-03-03T21:54:18.530Z,1362347658.530 [NavChartDb](FAULT): Change detected in ENC collection. Wiping NavChart Directory 2013-03-03T21:54:18.534Z,1362347658.534 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources 2013-03-03T21:54:18.536Z,1362347658.536 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA50M.000 2013-03-03T21:54:18.538Z,1362347658.537 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US2WC11M.000 2013-03-03T21:54:18.539Z,1362347658.539 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US1WC07M.000 2013-03-03T21:54:18.541Z,1362347658.541 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US3CA52M.000 2013-03-03T21:54:18.543Z,1362347658.543 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA61M.000 2013-03-03T21:54:18.544Z,1362347658.544 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA83M.000 2013-03-03T21:54:18.546Z,1362347658.546 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA62M.000 2013-03-03T21:54:18.548Z,1362347658.548 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4CA60M.000 2013-03-03T21:54:18.735Z,1362347658.735 [NavChartDb](INFO): Setup scan of Resources/US5CA62M.000 2013-03-03T21:54:20.156Z,1362347660.156 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized 2013-03-03T21:54:20.194Z,1362347660.194 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2013-03-03T21:54:20.229Z,1362347660.229 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2013-03-03T21:54:20.250Z,1362347660.250 [MissionManager](DEBUG): 2013-03-03T21:54:20.250Z,1362347660.250 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2013-03-03T21:54:20.278Z,1362347660.278 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool 2013-03-03T21:54:20.280Z,1362347660.280 [Default:GPS:A.SetSpeed](DEBUG): Construct. 2013-03-03T21:54:20.283Z,1362347660.283 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface. 2013-03-03T21:54:20.291Z,1362347660.291 [Default:Iridium:A.SetSpeed](DEBUG): Construct. 2013-03-03T21:54:20.325Z,1362347660.325 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface. 2013-03-03T21:54:20.331Z,1362347660.331 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2013-03-03T21:54:20.348Z,1362347660.348 [Default:D.SetSpeed](DEBUG): Construct. 2013-03-03T21:54:20.352Z,1362347660.352 [Default:E.GoToSurface](DEBUG): Construct GoToSurface. 2013-03-03T21:54:20.360Z,1362347660.360 [Default:F.Wait](DEBUG): Construct Wait. 2013-03-03T21:54:20.364Z,1362347660.364 [MissionManager](DEBUG): 400 400 Burn 300 Dropped drop weight due to communications timeout 5.0 1.0 5 2013-03-03T21:54:20.368Z,1362347660.368 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,NAL9602,Onboard,Radio_Freewave,Aanderaa_O2,ISUS,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, 2013-03-03T21:54:20.389Z,1362347660.389 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2013-03-03T21:54:20.447Z,1362347660.447 [Depth_Keller](ERROR): Pressure reading out of range: 1831.078247 decibar 2013-03-03T21:54:20.474Z,1362347660.474 [Radio_Freewave](INFO): Powering up 2013-03-03T21:54:20.575Z,1362347660.575 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-03-03T21:54:20.575Z,1362347660.575 [DVL_micro](INFO): Querying output modes 2013-03-03T21:54:20.576Z,1362347660.576 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606 2013-03-03T21:54:20.587Z,1362347660.587 [DVL_micro](DEBUG): cmdResponse: 01 03 16 2013-03-03T21:54:20.587Z,1362347660.587 [DVL_micro](INFO): NQ1 output enabled 2013-03-03T21:54:20.587Z,1362347660.587 [DVL_micro](INFO): RSSI output enabled 2013-03-03T21:54:20.587Z,1362347660.587 [DVL_micro](INFO): ADCP output enabled 2013-03-03T21:54:20.587Z,1362347660.588 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525 2013-03-03T21:54:20.603Z,1362347660.603 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 2013-03-03T21:54:20.631Z,1362347660.631 [DVL_micro](INFO): pause:Powering down 2013-03-03T21:54:20.668Z,1362347660.668 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2013-03-03T21:54:20.669Z,1362347660.669 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2013-03-03T21:54:20.676Z,1362347660.676 [ElevatorServo](DEBUG): Initializing EZServoServo. 2013-03-03T21:54:20.677Z,1362347660.677 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2013-03-03T21:54:20.683Z,1362347660.683 [MassServo](DEBUG): Initializing EZServoServo. 2013-03-03T21:54:20.684Z,1362347660.684 [MassServo](DEBUG): Initializing MassServo. 2013-03-03T21:54:20.689Z,1362347660.689 [RudderServo](DEBUG): Initializing EZServoServo. 2013-03-03T21:54:20.691Z,1362347660.691 [RudderServo](DEBUG): Initializing RudderServo. 2013-03-03T21:54:20.716Z,1362347660.716 [ThrusterServo](DEBUG): Initializing EZServoServo. 2013-03-03T21:54:20.723Z,1362347660.723 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2013-03-03T21:54:22.803Z,1362347662.803 [Aanderaa_O2](INFO): Powering down 2013-03-03T21:54:23.506Z,1362347663.506 [NAL9602](INFO): Powering up NAL9602 2013-03-03T21:54:33.837Z,1362347673.837 [SBIT](IMPORTANT): Beginning Startup BIT 2013-03-03T21:54:33.840Z,1362347673.840 [CBIT](IMPORTANT): Beginning GF scan 2013-03-03T21:54:34.211Z,1362347674.211 [NAL9602](INFO): NAL9602 initialized 2013-03-03T21:54:41.719Z,1362347681.719 [CommandLine](IMPORTANT): got command burn 5.000000 2013-03-03T21:55:00.411Z,1362347700.411 [CBIT](IMPORTANT): No ground fault detected 2013-03-03T21:55:17.691Z,1362347717.691 [CommandLine](IMPORTANT): got command show variable voltage 2013-03-03T21:55:17.762Z,1362347717.762 [CommandLine](INFO): platform_battery_voltage (volt) 2013-03-03T21:55:17.778Z,1362347717.778 [CommandLine](INFO): IBIT.batteryVoltageThreshold (volt) 2013-03-03T21:55:17.817Z,1362347717.817 [CommandLine](INFO): Batt_Ocean_Server.BattVoltage_0 (volt) 2013-03-03T21:55:17.817Z,1362347717.817 [CommandLine](INFO): Batt_Ocean_Server.BattVoltage_1 (volt) 2013-03-03T21:55:17.818Z,1362347717.818 [CommandLine](INFO): Batt_Ocean_Server.BattVoltage_2 (volt) 2013-03-03T21:55:17.819Z,1362347717.819 [CommandLine](INFO): Batt_Ocean_Server.BattVoltage_3 (volt) 2013-03-03T21:55:17.819Z,1362347717.819 [CommandLine](INFO): Batt_Ocean_Server.BattVoltage_4 (volt) 2013-03-03T21:55:17.820Z,1362347717.820 [CommandLine](INFO): Batt_Ocean_Server.BattVoltage_5 (volt) 2013-03-03T21:55:17.820Z,1362347717.820 [CommandLine](INFO): Batt_Ocean_Server.BattVoltage_6 (volt) 2013-03-03T21:55:17.821Z,1362347717.821 [CommandLine](INFO): Batt_Ocean_Server.BattVoltage_7 (volt) 2013-03-03T21:55:17.822Z,1362347717.822 [CommandLine](INFO): Batt_Ocean_Server.BattVoltage_8 (volt) 2013-03-03T21:55:17.822Z,1362347717.822 [CommandLine](INFO): Batt_Ocean_Server.BattVoltage_9 (volt) 2013-03-03T21:55:17.823Z,1362347717.823 [CommandLine](INFO): Batt_Ocean_Server.BattVoltage_10 (volt) 2013-03-03T21:55:17.823Z,1362347717.823 [CommandLine](INFO): Batt_Ocean_Server.BattVoltage_11 (volt) 2013-03-03T21:55:17.824Z,1362347717.824 [CommandLine](INFO): Batt_Ocean_Server.platform_battery_voltage (volt) 2013-03-03T21:55:17.829Z,1362347717.829 [CommandLine](INFO): DVL_micro.component_voltage (volt) 2013-03-03T21:55:17.829Z,1362347717.829 [CommandLine](INFO): WetLabsBB2FL.component_voltage (volt) 2013-03-03T21:55:17.830Z,1362347717.830 [CommandLine](INFO): WetLabsBB2FL.component_avgVoltage (volt) 2013-03-03T21:55:17.830Z,1362347717.830 [CommandLine](INFO): DVL_micro.component_avgVoltage (volt) 2013-03-03T21:55:17.831Z,1362347717.831 [CommandLine](INFO): CTD_NeilBrown.component_voltage (volt) 2013-03-03T21:55:17.831Z,1362347717.832 [CommandLine](INFO): CTD_NeilBrown.component_avgVoltage (volt) 2013-03-03T21:55:17.832Z,1362347717.832 [CommandLine](INFO): ISUS.component_voltage (volt) 2013-03-03T21:55:17.833Z,1362347717.833 [CommandLine](INFO): ISUS.component_avgVoltage (volt) 2013-03-03T21:55:17.834Z,1362347717.834 [CommandLine](INFO): AHRS_sp3003D.component_voltage (volt) 2013-03-03T21:55:17.836Z,1362347717.836 [CommandLine](INFO): AHRS_sp3003D.component_avgVoltage (volt) 2013-03-03T21:55:17.836Z,1362347717.836 [CommandLine](INFO): Aanderaa_O2.component_voltage (volt) 2013-03-03T21:55:17.836Z,1362347717.836 [CommandLine](INFO): Aanderaa_O2.component_avgVoltage (volt) 2013-03-03T21:55:17.837Z,1362347717.837 [CommandLine](INFO): Radio_Freewave.component_voltage (volt) 2013-03-03T21:55:17.837Z,1362347717.837 [CommandLine](INFO): Radio_Freewave.component_avgVoltage (volt) 2013-03-03T21:55:17.838Z,1362347717.838 [CommandLine](INFO): BuoyancyServo.component_voltage (volt) 2013-03-03T21:55:17.839Z,1362347717.839 [CommandLine](INFO): BuoyancyServo.component_avgVoltage (volt) 2013-03-03T21:55:17.840Z,1362347717.839 [CommandLine](INFO): RudderServo.component_voltage (volt) 2013-03-03T21:55:17.840Z,1362347717.840 [CommandLine](INFO): RudderServo.component_avgVoltage (volt) 2013-03-03T21:55:17.840Z,1362347717.840 [CommandLine](INFO): ThrusterServo.component_voltage (volt) 2013-03-03T21:55:17.841Z,1362347717.841 [CommandLine](INFO): ThrusterServo.component_avgVoltage (volt) 2013-03-03T21:55:17.841Z,1362347717.841 [CommandLine](INFO): NAL9602.component_voltage (volt) 2013-03-03T21:55:17.842Z,1362347717.842 [CommandLine](INFO): NAL9602.component_avgVoltage (volt) 2013-03-03T21:55:17.842Z,1362347717.842 [CommandLine](INFO): ElevatorServo.component_voltage (volt) 2013-03-03T21:55:17.843Z,1362347717.843 [CommandLine](INFO): ElevatorServo.component_avgVoltage (volt) 2013-03-03T21:55:17.844Z,1362347717.844 [CommandLine](INFO): MassServo.component_voltage (volt) 2013-03-03T21:55:17.844Z,1362347717.844 [CommandLine](INFO): MassServo.component_avgVoltage (volt) 2013-03-03T21:55:27.342Z,1362347727.342 [SBIT](IMPORTANT): SBIT PASSED 2013-03-03T21:55:27.722Z,1362347727.722 [MissionManager](IMPORTANT): Started mission Startup 2013-03-03T21:55:27.722Z,1362347727.722 [Startup] Running Loop=1 2013-03-03T21:55:27.723Z,1362347727.723 [Startup](INFO): Aggregate::initialize Startup 2013-03-03T21:55:27.723Z,1362347727.723 [Startup:A.GoToSurface] Running Loop=1 2013-03-03T21:55:27.723Z,1362347727.723 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-03-03T21:55:27.728Z,1362347727.728 [Startup:StartupSatComms] Running Loop=1 2013-03-03T21:55:27.729Z,1362347727.729 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms 2013-03-03T21:55:27.729Z,1362347727.729 [Startup:StartupSatComms:A] Running Loop=1 2013-03-03T21:55:28.003Z,1362347728.003 [CommandLine](IMPORTANT): got command get platform_battery_voltage 2013-03-03T21:55:28.004Z,1362347728.004 [CommandLine](IMPORTANT): platform_battery_voltage 16.184813 volt 2013-03-03T21:55:28.142Z,1362347728.142 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2013-03-03T21:56:19.047Z,1362347779.047 [CommandLine](IMPORTANT): got command show variable version 2013-03-03T21:56:27.839Z,1362347787.839 [Startup:StartupSatComms:A](INFO): Timed out from 2013-03-03T21:55:27.7Z 2013-03-03T21:56:27.839Z,1362347787.839 [Startup:StartupSatComms:A:A_Timeout] Running Loop=1 2013-03-03T21:56:27.839Z,1362347787.839 [Startup:StartupSatComms:A:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:A:A_Timeout 2013-03-03T21:56:27.839Z,1362347787.839 [Startup:StartupSatComms:A:A_Timeout](INFO): Completed Startup:StartupSatComms:A:A_Timeout 2013-03-03T21:56:27.840Z,1362347787.839 [Startup:StartupSatComms:A] Stopped 2013-03-03T21:56:27.840Z,1362347787.840 [Startup:StartupSatComms:B] Running Loop=1 2013-03-03T21:56:28.303Z,1362347788.303 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2013-03-03T21:57:27.985Z,1362347847.985 [Startup:StartupSatComms:B](INFO): Timed out from 2013-03-03T21:56:27.8Z 2013-03-03T21:57:27.985Z,1362347847.985 [Startup:StartupSatComms:B:A_Timeout] Running Loop=1 2013-03-03T21:57:27.985Z,1362347847.985 [Startup:StartupSatComms:B:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:B:A_Timeout 2013-03-03T21:57:27.985Z,1362347847.985 [Startup:StartupSatComms:B:A_Timeout](INFO): Completed Startup:StartupSatComms:B:A_Timeout 2013-03-03T21:57:27.985Z,1362347847.985 [Startup:StartupSatComms:B] Stopped 2013-03-03T21:57:27.986Z,1362347847.986 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2013-03-03T21:57:27.986Z,1362347847.986 [Startup:StartupSatComms] Stopped 2013-03-03T21:57:27.986Z,1362347847.986 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms 2013-03-03T21:57:27.987Z,1362347847.987 [Startup](INFO): Completed Startup 2013-03-03T21:57:27.987Z,1362347847.987 [Startup] Stopped 2013-03-03T21:57:27.987Z,1362347847.987 [Startup](INFO): Aggregate::uninitialize Startup 2013-03-03T21:57:27.987Z,1362347847.987 [Startup:A.GoToSurface] Stopped 2013-03-03T21:57:27.987Z,1362347847.987 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-03-03T21:57:28.398Z,1362347848.398 [MissionManager](IMPORTANT): Started mission Default 2013-03-03T21:57:28.398Z,1362347848.398 [Default] Running Loop=1 2013-03-03T21:57:28.398Z,1362347848.398 [Default](INFO): Aggregate::initialize Default 2013-03-03T21:57:28.398Z,1362347848.398 [Default:D.SetSpeed] Running Loop=1 2013-03-03T21:57:28.398Z,1362347848.398 [Default:D.SetSpeed](DEBUG): Initialize. 2013-03-03T21:57:28.399Z,1362347848.399 [Default:E.GoToSurface] Running Loop=1 2013-03-03T21:57:28.399Z,1362347848.399 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-03-03T21:57:28.399Z,1362347848.399 [Default:Iridium] Running Loop=1 2013-03-03T21:57:28.399Z,1362347848.399 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2013-03-03T21:57:28.399Z,1362347848.399 [Default:Iridium:A.SetSpeed] Running Loop=1 2013-03-03T21:57:28.399Z,1362347848.399 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2013-03-03T21:57:28.400Z,1362347848.400 [Default:Iridium:B.GoToSurface] Running Loop=1 2013-03-03T21:57:28.400Z,1362347848.400 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-03-03T21:57:28.400Z,1362347848.400 [Default:E.GoToSurface] Running Loop=1 2013-03-03T21:57:28.405Z,1362347848.405 [Default:D.SetSpeed] Running Loop=1 2013-03-03T21:57:28.410Z,1362347848.411 [Default:CallIridium] Running Loop=1 2013-03-03T21:57:28.411Z,1362347848.411 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2013-03-03T21:57:28.411Z,1362347848.411 [Default:CallIridium:A] Running Loop=1 2013-03-03T21:57:28.413Z,1362347848.413 [Default:CallIridium:A] Stopped 2013-03-03T21:57:28.413Z,1362347848.413 [Default:CallIridium:B] Running Loop=1 2013-03-03T21:57:28.413Z,1362347848.413 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2013-03-03T21:57:28.419Z,1362347848.419 [Default:Iridium:B.GoToSurface] Stopped 2013-03-03T21:57:28.419Z,1362347848.419 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-03-03T21:57:28.419Z,1362347848.419 [Default:Iridium:Read_Iridium] Running Loop=1 2013-03-03T21:57:28.419Z,1362347848.419 [Default:Iridium:A.SetSpeed] Running Loop=1 2013-03-03T21:57:28.424Z,1362347848.424 [Default:GPS] Running Loop=1 2013-03-03T21:57:28.424Z,1362347848.424 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2013-03-03T21:57:28.424Z,1362347848.424 [Default:GPS:A.SetSpeed] Running Loop=1 2013-03-03T21:57:28.424Z,1362347848.424 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2013-03-03T21:57:28.424Z,1362347848.424 [Default:GPS:B.GoToSurface] Running Loop=1 2013-03-03T21:57:28.425Z,1362347848.425 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-03-03T21:57:28.430Z,1362347848.430 [Default:GPS:B.GoToSurface] Stopped 2013-03-03T21:57:28.430Z,1362347848.430 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-03-03T21:57:28.433Z,1362347848.433 [Default:GPS:Read_GPS] Running Loop=1 2013-03-03T21:57:28.433Z,1362347848.433 [Default:GPS:A.SetSpeed] Running Loop=1 2013-03-03T21:57:28.784Z,1362347848.784 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2013-03-03T21:57:28.788Z,1362347848.788 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix