2012-05-24T00:32:15.053Z,1337819535.053 [Supervisor](DEBUG): Initializing supervisor. 2012-05-24T00:32:15.056Z,1337819535.056 [SyncHandler](DEBUG): Created PCaller Thread at 1077138656 2012-05-24T00:32:15.056Z,1337819535.056 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2012-05-24T00:32:15.057Z,1337819535.057 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 1077335264 2012-05-24T00:32:15.058Z,1337819535.058 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2012-05-24T00:32:15.068Z,1337819535.068 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2012-05-24T00:32:15.069Z,1337819535.069 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 1077531872 2012-05-24T00:32:15.070Z,1337819535.070 [ComponentRegistry](DEBUG): SyncComponent "logger" handled in the control thread. 2012-05-24T00:32:15.071Z,1337819535.071 [Supervisor](INFO): Looking for Config files in directory: Config/ 2012-05-24T00:32:15.072Z,1337819535.072 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2012-05-24T00:32:15.335Z,1337819535.335 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2012-05-24T00:32:15.336Z,1337819535.336 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2012-05-24T00:32:15.514Z,1337819535.514 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2012-05-24T00:32:15.514Z,1337819535.514 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2012-05-24T00:32:15.598Z,1337819535.598 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2012-05-24T00:32:15.599Z,1337819535.599 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2012-05-24T00:32:15.781Z,1337819535.781 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2012-05-24T00:32:15.781Z,1337819535.781 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2012-05-24T00:32:15.904Z,1337819535.904 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2012-05-24T00:32:15.905Z,1337819535.905 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2012-05-24T00:32:16.115Z,1337819536.115 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2012-05-24T00:32:16.116Z,1337819536.116 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2012-05-24T00:32:16.259Z,1337819536.260 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2012-05-24T00:32:16.260Z,1337819536.260 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2012-05-24T00:32:16.512Z,1337819536.512 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2012-05-24T00:32:16.512Z,1337819536.512 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2012-05-24T00:32:16.609Z,1337819536.609 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2012-05-24T00:32:16.609Z,1337819536.609 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2012-05-24T00:32:16.978Z,1337819536.978 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2012-05-24T00:32:16.978Z,1337819536.978 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2012-05-24T00:32:17.086Z,1337819537.086 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2012-05-24T00:32:17.086Z,1337819537.086 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2012-05-24T00:32:17.171Z,1337819537.171 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2012-05-24T00:32:17.172Z,1337819537.172 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2012-05-24T00:32:17.273Z,1337819537.273 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2012-05-24T00:32:17.402Z,1337819537.402 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2012-05-24T00:32:17.500Z,1337819537.500 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2012-05-24T00:32:17.595Z,1337819537.595 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2012-05-24T00:32:17.702Z,1337819537.702 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2012-05-24T00:32:17.790Z,1337819537.790 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2012-05-24T00:32:17.876Z,1337819537.876 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2012-05-24T00:32:17.986Z,1337819537.986 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2012-05-24T00:32:18.109Z,1337819538.109 [InternalSim] Loaded 2012-05-24T00:32:18.109Z,1337819538.109 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread. 2012-05-24T00:32:18.110Z,1337819538.110 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2012-05-24T00:32:18.111Z,1337819538.111 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2012-05-24T00:32:18.153Z,1337819538.153 [SBIT](DEBUG): Construct Startup Built In Test. 2012-05-24T00:32:18.164Z,1337819538.164 [SBIT] Loaded 2012-05-24T00:32:18.164Z,1337819538.164 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2012-05-24T00:32:18.165Z,1337819538.165 [IBIT](DEBUG): Construct Initiated Built In Test. 2012-05-24T00:32:18.188Z,1337819538.188 [IBIT] Loaded 2012-05-24T00:32:18.188Z,1337819538.188 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2012-05-24T00:32:18.195Z,1337819538.195 [CBIT](DEBUG): Construct CBIT Built In Test. 2012-05-24T00:32:18.298Z,1337819538.298 [CBIT] Loaded 2012-05-24T00:32:18.298Z,1337819538.298 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2012-05-24T00:32:18.299Z,1337819538.299 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2012-05-24T00:32:18.299Z,1337819538.299 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2012-05-24T00:32:18.425Z,1337819538.425 [BuoyancyServo] Loaded 2012-05-24T00:32:18.425Z,1337819538.425 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2012-05-24T00:32:18.432Z,1337819538.432 [ElevatorServo] Loaded 2012-05-24T00:32:18.432Z,1337819538.432 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2012-05-24T00:32:18.438Z,1337819538.438 [MassServo] Loaded 2012-05-24T00:32:18.439Z,1337819538.439 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2012-05-24T00:32:18.445Z,1337819538.445 [RudderServo] Loaded 2012-05-24T00:32:18.445Z,1337819538.445 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2012-05-24T00:32:18.452Z,1337819538.452 [ThrusterServo] Loaded 2012-05-24T00:32:18.452Z,1337819538.452 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2012-05-24T00:32:18.453Z,1337819538.453 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2012-05-24T00:32:18.453Z,1337819538.453 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2012-05-24T00:32:18.468Z,1337819538.468 [DepthRateCalculator] Loaded 2012-05-24T00:32:18.468Z,1337819538.468 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2012-05-24T00:32:18.484Z,1337819538.484 [NavChart] Loaded 2012-05-24T00:32:18.484Z,1337819538.484 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2012-05-24T00:32:18.490Z,1337819538.490 [PitchRateCalculator] Loaded 2012-05-24T00:32:18.490Z,1337819538.490 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2012-05-24T00:32:18.496Z,1337819538.496 [SpeedCalculator] Loaded 2012-05-24T00:32:18.496Z,1337819538.496 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2012-05-24T00:32:18.510Z,1337819538.510 [TempGradientCalculator] Loaded 2012-05-24T00:32:18.510Z,1337819538.510 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2012-05-24T00:32:18.516Z,1337819538.516 [YawRateCalculator] Loaded 2012-05-24T00:32:18.516Z,1337819538.516 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2012-05-24T00:32:18.545Z,1337819538.545 [Navigation] Loaded 2012-05-24T00:32:18.545Z,1337819538.545 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread. 2012-05-24T00:32:18.546Z,1337819538.546 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2012-05-24T00:32:18.546Z,1337819538.546 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2012-05-24T00:32:18.750Z,1337819538.750 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2012-05-24T00:32:18.751Z,1337819538.751 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2012-05-24T00:32:18.771Z,1337819538.771 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2012-05-24T00:32:18.772Z,1337819538.772 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2012-05-24T00:32:18.809Z,1337819538.809 [VerticalControl](DEBUG): Construct VerticalControl. 2012-05-24T00:32:18.852Z,1337819538.852 [VerticalControl] Loaded 2012-05-24T00:32:18.852Z,1337819538.852 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2012-05-24T00:32:18.853Z,1337819538.853 [HorizontalControl](DEBUG): Construct HorizontalControl. 2012-05-24T00:32:18.872Z,1337819538.872 [HorizontalControl] Loaded 2012-05-24T00:32:18.873Z,1337819538.872 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2012-05-24T00:32:18.873Z,1337819538.874 [SpeedControl](DEBUG): Construct SpeedControl. 2012-05-24T00:32:18.875Z,1337819538.875 [SpeedControl] Loaded 2012-05-24T00:32:18.876Z,1337819538.876 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2012-05-24T00:32:18.877Z,1337819538.876 [LoopControl](DEBUG): Construct LoopControl. 2012-05-24T00:32:18.877Z,1337819538.877 [LoopControl] Loaded 2012-05-24T00:32:18.877Z,1337819538.877 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2012-05-24T00:32:18.878Z,1337819538.878 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2012-05-24T00:32:18.878Z,1337819538.878 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2012-05-24T00:32:18.883Z,1337819538.884 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator. 2012-05-24T00:32:18.888Z,1337819538.888 [AsyncPiEstimator] Loaded 2012-05-24T00:32:18.888Z,1337819538.888 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread. 2012-05-24T00:32:18.890Z,1337819538.889 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 1078994144 2012-05-24T00:32:18.890Z,1337819538.890 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2012-05-24T00:32:18.891Z,1337819538.891 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2012-05-24T00:32:18.981Z,1337819538.981 [AHRS_sp3003D] Loaded 2012-05-24T00:32:18.981Z,1337819538.981 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread. 2012-05-24T00:32:19.219Z,1337819539.219 [Batt_Ocean_Server] Loaded 2012-05-24T00:32:19.220Z,1337819539.220 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread. 2012-05-24T00:32:19.231Z,1337819539.231 [Depth_Keller] Loaded 2012-05-24T00:32:19.232Z,1337819539.232 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2012-05-24T00:32:19.237Z,1337819539.237 [DropWeight] Loaded 2012-05-24T00:32:19.237Z,1337819539.237 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2012-05-24T00:32:19.328Z,1337819539.328 [DVL_micro] Loaded 2012-05-24T00:32:19.329Z,1337819539.329 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2012-05-24T00:32:19.406Z,1337819539.406 [NAL9601] Loaded 2012-05-24T00:32:19.406Z,1337819539.406 [ComponentRegistry](DEBUG): SyncComponent "NAL9601" handled in the control thread. 2012-05-24T00:32:19.453Z,1337819539.453 [Onboard] Loaded 2012-05-24T00:32:19.453Z,1337819539.453 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2012-05-24T00:32:19.459Z,1337819539.459 [Radio_Freewave] Loaded 2012-05-24T00:32:19.459Z,1337819539.459 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread. 2012-05-24T00:32:19.460Z,1337819539.460 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2012-05-24T00:32:19.461Z,1337819539.461 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2012-05-24T00:32:19.506Z,1337819539.506 [CTD_NeilBrown] Loaded 2012-05-24T00:32:19.506Z,1337819539.506 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2012-05-24T00:32:19.507Z,1337819539.507 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 1079645408 2012-05-24T00:32:19.539Z,1337819539.539 [WetLabsBB2FL] Loaded 2012-05-24T00:32:19.539Z,1337819539.539 [ComponentRegistry](DEBUG): SyncComponent "WetLabsBB2FL" handled in the control thread. 2012-05-24T00:32:19.540Z,1337819539.540 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2012-05-24T00:32:19.542Z,1337819539.542 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2012-05-24T00:32:19.543Z,1337819539.543 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2012-05-24T00:32:19.548Z,1337819539.548 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2012-05-24T00:32:19.549Z,1337819539.549 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 1079842016 2012-05-24T00:32:19.549Z,1337819539.549 [Supervisor](DEBUG): Running supervisor. 2012-05-24T00:32:19.553Z,1337819539.553 [controlThread](DEBUG): Initializing ControlThread 2012-05-24T00:32:19.553Z,1337819539.553 [InternalSim](DEBUG): InternalSim initializing... 2012-05-24T00:32:19.587Z,1337819539.587 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator. 2012-05-24T00:32:19.596Z,1337819539.596 [SBIT](INFO): Initialize SBIT Component. 2012-05-24T00:32:19.597Z,1337819539.597 [SBIT](IMPORTANT): Tethys CM Info: $Rev: 9636 $ 2012-05-24T00:32:19.598Z,1337819539.598 [IBIT](INFO): Initialize IBIT Component. 2012-05-24T00:32:19.600Z,1337819539.600 [CBIT](DEBUG): Initialize CBIT Component. 2012-05-24T00:32:19.601Z,1337819539.601 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL. 2012-05-24T00:32:19.601Z,1337819539.601 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2012-05-24T00:32:19.602Z,1337819539.602 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown. 2012-05-24T00:32:19.628Z,1337819539.628 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2012-05-24T00:32:19.628Z,1337819539.628 [NavChart](DEBUG): Initialize NavChart Derivation. 2012-05-24T00:32:19.628Z,1337819539.628 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2012-05-24T00:32:19.629Z,1337819539.629 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2012-05-24T00:32:19.629Z,1337819539.629 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2012-05-24T00:32:19.631Z,1337819539.631 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2012-05-24T00:32:19.631Z,1337819539.631 [Navigation](DEBUG): Initializing Navigation. 2012-05-24T00:32:19.632Z,1337819539.632 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2012-05-24T00:32:19.634Z,1337819539.634 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2012-05-24T00:32:19.634Z,1337819539.634 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2012-05-24T00:32:19.635Z,1337819539.635 [LoopControl](DEBUG): Initialize LoopControlComponent. 2012-05-24T00:32:19.706Z,1337819539.706 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources 2012-05-24T00:32:19.713Z,1337819539.713 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2012-05-24T00:32:19.717Z,1337819539.717 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2012-05-24T00:32:19.721Z,1337819539.721 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2012-05-24T00:32:19.725Z,1337819539.725 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2012-05-24T00:32:19.725Z,1337819539.725 [NavChartDb](INFO): Creating index for Soundings 2012-05-24T00:32:19.729Z,1337819539.729 [NavChartDb](INFO): Creating index for Contour 0p0 2012-05-24T00:32:19.731Z,1337819539.731 [NavChartDb](INFO): Creating index for Contour 1p8 2012-05-24T00:32:19.733Z,1337819539.733 [NavChartDb](INFO): Creating index for Contour 3p6 2012-05-24T00:32:19.735Z,1337819539.735 [NavChartDb](INFO): Creating index for Contour 5p4 2012-05-24T00:32:19.737Z,1337819539.737 [NavChartDb](INFO): Creating index for Contour 9p1 2012-05-24T00:32:19.739Z,1337819539.739 [NavChartDb](INFO): Creating index for Contour 10p9 2012-05-24T00:32:19.740Z,1337819539.740 [NavChartDb](INFO): Creating index for Contour 18p2 2012-05-24T00:32:19.743Z,1337819539.743 [NavChartDb](INFO): Creating index for Contour 36p5 2012-05-24T00:32:19.744Z,1337819539.744 [NavChartDb](INFO): Creating index for Contour 54p8 2012-05-24T00:32:19.746Z,1337819539.746 [NavChartDb](INFO): Creating index for Contour 73p1 2012-05-24T00:32:19.748Z,1337819539.748 [NavChartDb](INFO): Creating index for Contour 91p4 2012-05-24T00:32:19.750Z,1337819539.750 [NavChartDb](INFO): Creating index for Contour 182p8 2012-05-24T00:32:19.752Z,1337819539.752 [NavChartDb](INFO): Creating index for Contour 365p7 2012-05-24T00:32:19.754Z,1337819539.754 [NavChartDb](INFO): Creating index for Contour 548p6 2012-05-24T00:32:19.756Z,1337819539.756 [NavChartDb](INFO): Creating index for Contour 731p5 2012-05-24T00:32:19.758Z,1337819539.758 [NavChartDb](INFO): Creating index for Contour 914p4 2012-05-24T00:32:19.760Z,1337819539.760 [NavChartDb](INFO): Creating index for Contour 1097p2 2012-05-24T00:32:19.762Z,1337819539.762 [NavChartDb](INFO): Creating index for Contour 1280p1 2012-05-24T00:32:19.764Z,1337819539.764 [NavChartDb](INFO): Creating index for Contour 1463p0 2012-05-24T00:32:19.766Z,1337819539.766 [NavChartDb](INFO): Creating index for Contour 1645p9 2012-05-24T00:32:19.768Z,1337819539.768 [NavChartDb](INFO): Creating index for Contour 1828p8 2012-05-24T00:32:19.770Z,1337819539.770 [NavChartDb](INFO): Creating index for Contour 2011p6 2012-05-24T00:32:19.772Z,1337819539.772 [NavChartDb](INFO): Creating index for Contour 2194p5 2012-05-24T00:32:19.773Z,1337819539.773 [NavChartDb](INFO): Creating index for Contour 2377p4 2012-05-24T00:32:19.775Z,1337819539.776 [NavChartDb](INFO): Creating index for Contour 2560p3 2012-05-24T00:32:19.777Z,1337819539.777 [NavChartDb](INFO): Creating index for Contour 2743p2 2012-05-24T00:32:19.779Z,1337819539.779 [NavChartDb](INFO): Creating index for Contour 2926p0 2012-05-24T00:32:19.781Z,1337819539.781 [NavChartDb](INFO): Creating index for Contour 3108p9 2012-05-24T00:32:19.783Z,1337819539.783 [NavChartDb](INFO): Creating index for Contour 3291p8 2012-05-24T00:32:19.785Z,1337819539.785 [NavChartDb](INFO): Creating index for Contour 3474p7 2012-05-24T00:32:19.787Z,1337819539.787 [NavChartDb](INFO): Creating index for Contour 3657p6 2012-05-24T00:32:21.387Z,1337819541.387 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized 2012-05-24T00:32:21.392Z,1337819541.392 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2012-05-24T00:32:21.407Z,1337819541.408 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2012-05-24T00:32:21.417Z,1337819541.417 [MissionManager](DEBUG): 2012-05-24T00:32:21.417Z,1337819541.417 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2012-05-24T00:32:21.443Z,1337819541.443 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool 2012-05-24T00:32:21.445Z,1337819541.445 [Default:GPS:A.SetSpeed](DEBUG): Construct. 2012-05-24T00:32:21.448Z,1337819541.448 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface. 2012-05-24T00:32:21.458Z,1337819541.458 [Default:Iridium:A.SetSpeed](DEBUG): Construct. 2012-05-24T00:32:21.461Z,1337819541.461 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface. 2012-05-24T00:32:21.467Z,1337819541.467 [Default:Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2012-05-24T00:32:21.476Z,1337819541.476 [Default:D.SetSpeed](DEBUG): Construct. 2012-05-24T00:32:21.479Z,1337819541.479 [Default:E.GoToSurface](DEBUG): Construct GoToSurface. 2012-05-24T00:32:21.483Z,1337819541.483 [Default:F.Wait](DEBUG): Construct Wait. 2012-05-24T00:32:21.487Z,1337819541.487 [MissionManager](DEBUG): 400 400 Burn 300 Dropped drop weight due to communications timeout 5.0 1.0 5 2012-05-24T00:32:21.492Z,1337819541.492 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,DVL_micro,NAL9601,Onboard,Radio_Freewave,WetLabsBB2FL,Depth_Keller,DepthRateCalculator,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,logger, 2012-05-24T00:32:21.515Z,1337819541.515 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2012-05-24T00:32:21.630Z,1337819541.630 [DVL_micro](DEBUG): Initializing DVL_micro. 2012-05-24T00:32:21.650Z,1337819541.650 [Radio_Freewave](INFO): Powering up 2012-05-24T00:32:21.655Z,1337819541.655 [WetLabsBB2FL](INFO): Powering down 2012-05-24T00:32:21.724Z,1337819541.724 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2012-05-24T00:32:21.725Z,1337819541.724 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2012-05-24T00:32:21.739Z,1337819541.740 [ElevatorServo](DEBUG): Initializing EZServoServo. 2012-05-24T00:32:21.740Z,1337819541.740 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2012-05-24T00:32:21.748Z,1337819541.748 [MassServo](DEBUG): Initializing EZServoServo. 2012-05-24T00:32:21.749Z,1337819541.749 [MassServo](DEBUG): Initializing MassServo. 2012-05-24T00:32:21.757Z,1337819541.757 [RudderServo](DEBUG): Initializing EZServoServo. 2012-05-24T00:32:21.758Z,1337819541.759 [RudderServo](DEBUG): Initializing RudderServo. 2012-05-24T00:32:21.766Z,1337819541.766 [ThrusterServo](DEBUG): Initializing EZServoServo. 2012-05-24T00:32:21.767Z,1337819541.767 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2012-05-24T00:32:24.773Z,1337819544.773 [NAL9601](INFO): Powering up NAL9601 2012-05-24T00:32:35.209Z,1337819555.209 [SBIT](IMPORTANT): Beginning Startup BIT 2012-05-24T00:32:35.211Z,1337819555.211 [CBIT](IMPORTANT): Beginning GF scan 2012-05-24T00:33:01.412Z,1337819581.411 [CBIT](IMPORTANT): No ground fault detected 2012-05-24T00:33:03.263Z,1337819583.263 [CommandLine](IMPORTANT): got command failComponent 2012-05-24T00:33:03.263Z,1337819583.263 [CommandLine](IMPORTANT): Failed components: 2012-05-24T00:33:03.263Z,1337819583.263 [CommandLine](IMPORTANT): No failed Components. 2012-05-24T00:33:17.349Z,1337819597.349 [SBIT](IMPORTANT): SBIT PASSED 2012-05-24T00:33:17.751Z,1337819597.750 [MissionManager](IMPORTANT): Started mission Startup 2012-05-24T00:33:17.751Z,1337819597.751 [Startup] Running Loop=1 2012-05-24T00:33:17.751Z,1337819597.751 [Startup](INFO): Aggregate::initialize Startup 2012-05-24T00:33:17.751Z,1337819597.751 [Startup:A.GoToSurface] Running Loop=1 2012-05-24T00:33:17.751Z,1337819597.751 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-05-24T00:33:17.757Z,1337819597.757 [Startup:StartupSatComms] Running Loop=1 2012-05-24T00:33:17.757Z,1337819597.757 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms 2012-05-24T00:33:17.757Z,1337819597.757 [Startup:StartupSatComms:A] Running Loop=1 2012-05-24T00:33:18.116Z,1337819598.116 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2012-05-24T00:33:32.502Z,1337819612.503 [NAL9601](ERROR): NAL9601 initialize uart error: serial timeout 2012-05-24T00:33:32.503Z,1337819612.503 [NAL9601] Communications Fault, FailCount= 1 2012-05-24T00:33:32.503Z,1337819612.503 [NAL9601](ERROR): Communications Fault 2012-05-24T00:33:32.547Z,1337819612.546 [CBIT](ERROR): Communications Fault in component: NAL9601 2012-05-24T00:33:32.659Z,1337819612.659 [NAL9601](INFO): Powering down 2012-05-24T00:33:32.703Z,1337819612.703 [CBIT](INFO): Clearing failed state for component NAL9601 2012-05-24T00:33:32.703Z,1337819612.703 [NAL9601] No Fault, FailCount= 1 2012-05-24T00:33:37.847Z,1337819617.847 [NAL9601](INFO): Powering up NAL9601 2012-05-24T00:34:17.832Z,1337819657.832 [Startup:StartupSatComms:A](INFO): Timed out from 2012-05-24T00:33:17.8Z 2012-05-24T00:34:17.832Z,1337819657.832 [Startup:StartupSatComms:A_Timeout] Running Loop=1 2012-05-24T00:34:17.832Z,1337819657.832 [Startup:StartupSatComms:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:A_Timeout 2012-05-24T00:34:17.832Z,1337819657.832 [Startup:StartupSatComms:A_Timeout](INFO): Completed Startup:StartupSatComms:A_Timeout 2012-05-24T00:34:17.832Z,1337819657.832 [Startup:StartupSatComms:A] Stopped 2012-05-24T00:34:17.833Z,1337819657.833 [Startup:StartupSatComms:B] Running Loop=1 2012-05-24T00:34:18.224Z,1337819658.224 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2012-05-24T00:34:43.487Z,1337819683.487 [NAL9601](INFO): NAL9601 initialized 2012-05-24T00:35:18.104Z,1337819718.104 [Startup:StartupSatComms:B](INFO): Timed out from 2012-05-24T00:34:17.8Z 2012-05-24T00:35:18.104Z,1337819718.104 [Startup:StartupSatComms:A_Timeout] Running Loop=1 2012-05-24T00:35:18.105Z,1337819718.105 [Startup:StartupSatComms:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:A_Timeout 2012-05-24T00:35:18.105Z,1337819718.105 [Startup:StartupSatComms:A_Timeout](INFO): Completed Startup:StartupSatComms:A_Timeout 2012-05-24T00:35:18.105Z,1337819718.105 [Startup:StartupSatComms:B] Stopped 2012-05-24T00:35:18.105Z,1337819718.105 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2012-05-24T00:35:18.105Z,1337819718.105 [Startup:StartupSatComms] Stopped 2012-05-24T00:35:18.105Z,1337819718.105 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms 2012-05-24T00:35:18.106Z,1337819718.106 [Startup](INFO): Completed Startup 2012-05-24T00:35:18.106Z,1337819718.106 [Startup] Stopped 2012-05-24T00:35:18.106Z,1337819718.106 [Startup](INFO): Aggregate::uninitialize Startup 2012-05-24T00:35:18.106Z,1337819718.106 [Startup:A.GoToSurface] Stopped 2012-05-24T00:35:18.106Z,1337819718.106 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-05-24T00:35:18.504Z,1337819718.504 [MissionManager](IMPORTANT): Started mission Default 2012-05-24T00:35:18.504Z,1337819718.504 [Default] Running Loop=1 2012-05-24T00:35:18.504Z,1337819718.504 [Default](INFO): Aggregate::initialize Default 2012-05-24T00:35:18.504Z,1337819718.504 [Default:D.SetSpeed] Running Loop=1 2012-05-24T00:35:18.504Z,1337819718.504 [Default:D.SetSpeed](DEBUG): Initialize. 2012-05-24T00:35:18.504Z,1337819718.504 [Default:E.GoToSurface] Running Loop=1 2012-05-24T00:35:18.504Z,1337819718.504 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-05-24T00:35:18.505Z,1337819718.505 [Default:Iridium] Running Loop=1 2012-05-24T00:35:18.505Z,1337819718.505 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2012-05-24T00:35:18.505Z,1337819718.505 [Default:Iridium:A.SetSpeed] Running Loop=1 2012-05-24T00:35:18.505Z,1337819718.505 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2012-05-24T00:35:18.505Z,1337819718.505 [Default:Iridium:B.GoToSurface] Running Loop=1 2012-05-24T00:35:18.505Z,1337819718.505 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-05-24T00:35:18.506Z,1337819718.506 [Default:E.GoToSurface] Running Loop=1 2012-05-24T00:35:18.511Z,1337819718.511 [Default:D.SetSpeed] Running Loop=1 2012-05-24T00:35:18.516Z,1337819718.516 [Default:CallIridium] Running Loop=1 2012-05-24T00:35:18.516Z,1337819718.516 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2012-05-24T00:35:18.516Z,1337819718.516 [Default:CallIridium:A] Running Loop=1 2012-05-24T00:35:18.518Z,1337819718.518 [Default:CallIridium:A] Stopped 2012-05-24T00:35:18.518Z,1337819718.518 [Default:CallIridium:B] Running Loop=1 2012-05-24T00:35:18.518Z,1337819718.518 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2012-05-24T00:35:18.524Z,1337819718.524 [Default:Iridium:B.GoToSurface] Stopped 2012-05-24T00:35:18.524Z,1337819718.524 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-05-24T00:35:18.524Z,1337819718.524 [Default:Iridium:Read_Iridium] Running Loop=1 2012-05-24T00:35:18.524Z,1337819718.524 [Default:Iridium:A.SetSpeed] Running Loop=1 2012-05-24T00:35:18.529Z,1337819718.529 [Default:GPS] Running Loop=1 2012-05-24T00:35:18.529Z,1337819718.529 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2012-05-24T00:35:18.529Z,1337819718.529 [Default:GPS:A.SetSpeed] Running Loop=1 2012-05-24T00:35:18.529Z,1337819718.529 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2012-05-24T00:35:18.530Z,1337819718.530 [Default:GPS:B.GoToSurface] Running Loop=1 2012-05-24T00:35:18.530Z,1337819718.530 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-05-24T00:35:18.535Z,1337819718.535 [Default:GPS:B.GoToSurface] Stopped 2012-05-24T00:35:18.535Z,1337819718.535 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-05-24T00:35:18.536Z,1337819718.536 [Default:GPS:Read_GPS] Running Loop=1 2012-05-24T00:35:18.536Z,1337819718.536 [Default:GPS:A.SetSpeed] Running Loop=1 2012-05-24T00:35:18.933Z,1337819718.933 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2012-05-24T00:35:18.936Z,1337819718.936 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2012-05-24T00:36:08.279Z,1337819768.279 [CommandLine](IMPORTANT): got command failComponent 2012-05-24T00:36:08.279Z,1337819768.279 [CommandLine](IMPORTANT): Failed components: 2012-05-24T00:36:08.279Z,1337819768.279 [CommandLine](IMPORTANT): No failed Components. 2012-05-24T00:36:13.815Z,1337819773.815 [CommandLine](IMPORTANT): got command run ./Missions/Maintenance/tank_weight.xml 2012-05-24T00:36:13.815Z,1337819773.815 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/tank_weight.xml 2012-05-24T00:36:13.861Z,1337819773.861 [MissionManager](INFO): DefineArg tank_weight.BuoyancyLimitHiCC = 0.000955 n/a 2012-05-24T00:36:13.869Z,1337819773.869 [MissionManager](INFO): DefineArg tank_weight.BuoyancyLimitLoCC = 0.000080 n/a 2012-05-24T00:36:13.875Z,1337819773.875 [tank_weight:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope. 2012-05-24T00:36:13.891Z,1337819773.891 [tank_weight:B.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2012-05-24T00:36:13.908Z,1337819773.908 [MissionManager](INFO): Inserting Stack: Missions/Insert/Science.xml 2012-05-24T00:36:13.992Z,1337819773.992 [MissionManager](INFO): DefineArg tank_weight:Science.SampleAanderaaO2 = 0.000000 n/a 2012-05-24T00:36:13.995Z,1337819773.995 [MissionManager](INFO): DefineArg tank_weight:Science.SampleISUS = 0 bool 2012-05-24T00:36:13.998Z,1337819773.998 [MissionManager](INFO): DefineArg tank_weight:Science.SampleNeilBrown = 1.000000 n/a 2012-05-24T00:36:14.001Z,1337819774.001 [MissionManager](INFO): DefineArg tank_weight:Science.SampleWetLabsBB2FL = 1.000000 n/a 2012-05-24T00:36:14.005Z,1337819774.005 [MissionManager](INFO): DefineArg tank_weight:Science.PeakDetectChlActive = 0 bool 2012-05-24T00:36:14.007Z,1337819774.007 [MissionManager](INFO): DefineArg tank_weight:Science.PeakDetectNO3Active = 0 bool 2012-05-24T00:36:14.011Z,1337819774.011 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakChl = 0.000000 ug/l 2012-05-24T00:36:14.013Z,1337819774.013 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakChlDepth = 0.000000 m 2012-05-24T00:36:14.016Z,1337819774.016 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakChlLatitude = nan arcdeg 2012-05-24T00:36:14.020Z,1337819774.020 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakChlLongitude = nan arcdeg 2012-05-24T00:36:14.023Z,1337819774.023 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakNO3 = 0.000000 uM/l 2012-05-24T00:36:14.026Z,1337819774.026 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakNO3Depth = 0.000000 m 2012-05-24T00:36:14.029Z,1337819774.029 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakNO3Latitude = nan arcdeg 2012-05-24T00:36:14.032Z,1337819774.032 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakNO3Longitude = nan arcdeg 2012-05-24T00:36:14.040Z,1337819774.039 [tank_weight:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2012-05-24T00:36:14.049Z,1337819774.049 [tank_weight:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2012-05-24T00:36:14.058Z,1337819774.058 [MissionManager](INFO): RedefineArg tank_weight:Science.SampleISUS = 1 bool 2012-05-24T00:36:14.060Z,1337819774.060 [tank_weight:D:A.SetSpeed](DEBUG): Construct. 2012-05-24T00:36:14.063Z,1337819774.063 [tank_weight:D:B.Pitch](DEBUG): Construct. 2012-05-24T00:36:14.069Z,1337819774.069 [tank_weight:D:BuoyancyLo:A.Buoyancy](DEBUG): Construct Buoyancy. 2012-05-24T00:36:14.073Z,1337819774.073 [tank_weight:D:BuoyancyLo:B.Wait](DEBUG): Construct Wait. 2012-05-24T00:36:14.075Z,1337819774.075 [tank_weight:D:BuoyancyHi:A.Buoyancy](DEBUG): Construct Buoyancy. 2012-05-24T00:36:14.079Z,1337819774.079 [tank_weight:D:BuoyancyHi:B.Wait](DEBUG): Construct Wait. 2012-05-24T00:36:14.086Z,1337819774.086 [MissionManager](DEBUG): 0 0 15 0 0 15 65 5 2012-05-24T00:36:14.087Z,1337819774.087 [CommandLine](IMPORTANT): Running ./Missions/Maintenance/tank_weight.xml 2012-05-24T00:36:14.212Z,1337819774.212 [Default] Stopped 2012-05-24T00:36:14.212Z,1337819774.212 [Default](INFO): Aggregate::uninitialize Default 2012-05-24T00:36:14.212Z,1337819774.212 [Default:GPS] Stopped 2012-05-24T00:36:14.212Z,1337819774.212 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2012-05-24T00:36:14.212Z,1337819774.212 [Default:GPS:A.SetSpeed] Stopped 2012-05-24T00:36:14.212Z,1337819774.212 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2012-05-24T00:36:14.212Z,1337819774.212 [Default:GPS:Read_GPS] Stopped 2012-05-24T00:36:14.212Z,1337819774.212 [Default:Iridium] Stopped 2012-05-24T00:36:14.212Z,1337819774.212 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2012-05-24T00:36:14.213Z,1337819774.213 [Default:Iridium:A.SetSpeed] Stopped 2012-05-24T00:36:14.213Z,1337819774.213 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2012-05-24T00:36:14.213Z,1337819774.213 [Default:Iridium:Read_Iridium] Stopped 2012-05-24T00:36:14.213Z,1337819774.213 [Default:CallIridium] Stopped 2012-05-24T00:36:14.213Z,1337819774.213 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2012-05-24T00:36:14.213Z,1337819774.213 [Default:CallIridium:B] Stopped 2012-05-24T00:36:14.213Z,1337819774.213 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2012-05-24T00:36:14.213Z,1337819774.213 [Default:D.SetSpeed] Stopped 2012-05-24T00:36:14.213Z,1337819774.213 [Default:D.SetSpeed](DEBUG): Uninitialize. 2012-05-24T00:36:14.213Z,1337819774.213 [Default:E.GoToSurface] Stopped 2012-05-24T00:36:14.213Z,1337819774.213 [Default:E.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-05-24T00:36:14.213Z,1337819774.213 [MissionManager](IMPORTANT): Started mission tank_weight 2012-05-24T00:36:14.213Z,1337819774.214 [tank_weight] Running Loop=1 2012-05-24T00:36:14.214Z,1337819774.214 [tank_weight](INFO): Aggregate::initialize tank_weight 2012-05-24T00:36:14.214Z,1337819774.214 [tank_weight:A.AltitudeEnvelope] Running Loop=1 2012-05-24T00:36:14.214Z,1337819774.214 [tank_weight:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent. 2012-05-24T00:36:14.214Z,1337819774.214 [tank_weight:B.DepthEnvelope] Running Loop=1 2012-05-24T00:36:14.214Z,1337819774.214 [tank_weight:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent. 2012-05-24T00:36:14.215Z,1337819774.215 [tank_weight:Science] Running Loop=1 2012-05-24T00:36:14.215Z,1337819774.215 [tank_weight:Science](INFO): Aggregate::initialize tank_weight:Science 2012-05-24T00:36:14.215Z,1337819774.215 [tank_weight:Science:A] Running Loop=1 2012-05-24T00:36:14.215Z,1337819774.215 [tank_weight:Science:B] Running Loop=1 2012-05-24T00:36:14.215Z,1337819774.215 [tank_weight:Science:C] Running Loop=1 2012-05-24T00:36:14.215Z,1337819774.216 [tank_weight:Science:D] Running Loop=1 2012-05-24T00:36:14.216Z,1337819774.216 [tank_weight:D] Running Loop=1 2012-05-24T00:36:14.216Z,1337819774.216 [tank_weight:D](INFO): Aggregate::initialize tank_weight:D 2012-05-24T00:36:14.216Z,1337819774.216 [tank_weight:D:A.SetSpeed] Running Loop=1 2012-05-24T00:36:14.216Z,1337819774.216 [tank_weight:D:A.SetSpeed](DEBUG): Initialize. 2012-05-24T00:36:14.216Z,1337819774.216 [tank_weight:D:B.Pitch] Running Loop=1 2012-05-24T00:36:14.216Z,1337819774.216 [tank_weight:D:B.Pitch](DEBUG): Initialize. 2012-05-24T00:36:14.216Z,1337819774.216 [tank_weight:D:BuoyancyLo] Running Loop=1 2012-05-24T00:36:14.216Z,1337819774.217 [tank_weight:D:BuoyancyLo](INFO): Aggregate::initialize tank_weight:D:BuoyancyLo 2012-05-24T00:36:14.217Z,1337819774.217 [tank_weight:D:BuoyancyLo:A.Buoyancy] Running Loop=1 2012-05-24T00:36:14.217Z,1337819774.217 [tank_weight:D:BuoyancyLo:A.Buoyancy](DEBUG): Initialize Buoyancy Component. 2012-05-24T00:36:14.217Z,1337819774.217 [tank_weight:D:BuoyancyLo:B.Wait] Running Loop=1 2012-05-24T00:36:14.217Z,1337819774.217 [tank_weight:D:BuoyancyLo:B.Wait](DEBUG): Initialize Wait Component. 2012-05-24T00:36:14.222Z,1337819774.222 [tank_weight:D:BuoyancyLo:A.Buoyancy] Running Loop=1 2012-05-24T00:36:14.226Z,1337819774.226 [tank_weight:D:B.Pitch] Running Loop=1 2012-05-24T00:36:14.231Z,1337819774.231 [tank_weight:D:A.SetSpeed] Running Loop=1 2012-05-24T00:36:14.235Z,1337819774.235 [tank_weight:Science] Running Loop=1 2012-05-24T00:36:14.236Z,1337819774.236 [tank_weight:Science:D] Running Loop=1 2012-05-24T00:36:14.236Z,1337819774.236 [tank_weight:Science:D](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water 2012-05-24T00:36:14.237Z,1337819774.237 [tank_weight:Science:C] Running Loop=1 2012-05-24T00:36:14.238Z,1337819774.238 [tank_weight:Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature 2012-05-24T00:36:14.239Z,1337819774.239 [tank_weight:Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity 2012-05-24T00:36:14.240Z,1337819774.240 [tank_weight:Science:B] Running Loop=1 2012-05-24T00:36:14.241Z,1337819774.240 [tank_weight:Science:B](DEBUG): Initialize ReadDataComponent to sense mole_concentration_of_nitrate_in_sea_water 2012-05-24T00:36:14.242Z,1337819774.242 [tank_weight:B.DepthEnvelope] Running Loop=1 2012-05-24T00:36:14.247Z,1337819774.247 [tank_weight:A.AltitudeEnvelope] Running Loop=1 2012-05-24T00:36:14.887Z,1337819774.887 [WetLabsBB2FL](INFO): Powering up 2012-05-24T00:36:16.099Z,1337819776.099 [tank_weight:A.AltitudeEnvelope](ERROR): Altitude Measurement is not Active. 2012-05-24T00:36:18.483Z,1337819778.483 [WetLabsBB2FL](DEBUG): Error parsing data: 2012-05-24T00:36:18.483Z,1337819778.483 [WetLabsBB2FL] Data Fault, FailCount= 1 2012-05-24T00:36:18.483Z,1337819778.483 [WetLabsBB2FL](ERROR): Data Fault 2012-05-24T00:36:18.523Z,1337819778.523 [CBIT](ERROR): Data Fault in component: WetLabsBB2FL 2012-05-24T00:36:18.979Z,1337819778.979 [WetLabsBB2FL](INFO): Powering down 2012-05-24T00:36:19.026Z,1337819779.026 [CBIT](INFO): Clearing failed state for component WetLabsBB2FL 2012-05-24T00:36:19.027Z,1337819779.027 [WetLabsBB2FL] No Fault, FailCount= 1 2012-05-24T00:36:19.291Z,1337819779.291 [WetLabsBB2FL](INFO): Powering up 2012-05-24T00:37:38.311Z,1337819858.311 [CommandLine](IMPORTANT): got command show stack 2012-05-24T00:37:38.311Z,1337819858.311 [CommandLine](INFO): Behavior Stack: 2012-05-24T00:37:38.311Z,1337819858.311 [tank_weight](INFO): Priority 0: tank_weight:A.AltitudeEnvelope 2012-05-24T00:37:38.312Z,1337819858.312 [tank_weight](INFO): Priority 1: tank_weight:B.DepthEnvelope 2012-05-24T00:37:38.312Z,1337819858.312 [tank_weight:Science](INFO): Priority 2: tank_weight:Science:B 2012-05-24T00:37:38.312Z,1337819858.312 [tank_weight:Science](INFO): Priority 3: tank_weight:Science:C 2012-05-24T00:37:38.313Z,1337819858.313 [tank_weight:Science](INFO): Priority 4: tank_weight:Science:D 2012-05-24T00:37:38.313Z,1337819858.313 [tank_weight:D](INFO): Priority 5: tank_weight:D:A.SetSpeed 2012-05-24T00:37:38.313Z,1337819858.313 [tank_weight:D](INFO): Priority 6: tank_weight:D:B.Pitch 2012-05-24T00:37:38.313Z,1337819858.313 [tank_weight:D:BuoyancyLo](INFO): Priority 7: tank_weight:D:BuoyancyLo:A.Buoyancy 2012-05-24T00:37:38.314Z,1337819858.314 [tank_weight:D:BuoyancyLo](INFO): Priority 8: tank_weight:D:BuoyancyLo:B.Wait 2012-05-24T00:37:43.307Z,1337819863.307 [CommandLine](IMPORTANT): got command stop 2012-05-24T00:37:43.711Z,1337819863.711 [tank_weight] Stopped 2012-05-24T00:37:43.711Z,1337819863.711 [tank_weight](INFO): Aggregate::uninitialize tank_weight 2012-05-24T00:37:43.711Z,1337819863.711 [tank_weight:A.AltitudeEnvelope] Stopped 2012-05-24T00:37:43.711Z,1337819863.711 [tank_weight:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent. 2012-05-24T00:37:43.711Z,1337819863.711 [tank_weight:B.DepthEnvelope] Stopped 2012-05-24T00:37:43.711Z,1337819863.711 [tank_weight:B.DepthEnvelope](DEBUG): Uninitialize. 2012-05-24T00:37:43.711Z,1337819863.711 [tank_weight:Science] Stopped 2012-05-24T00:37:43.712Z,1337819863.712 [tank_weight:Science](INFO): Aggregate::uninitialize tank_weight:Science 2012-05-24T00:37:43.712Z,1337819863.712 [tank_weight:Science:A] Stopped 2012-05-24T00:37:43.712Z,1337819863.712 [tank_weight:Science:B] Stopped 2012-05-24T00:37:43.712Z,1337819863.712 [tank_weight:Science:C] Stopped 2012-05-24T00:37:43.712Z,1337819863.712 [tank_weight:Science:D] Stopped 2012-05-24T00:37:43.712Z,1337819863.712 [tank_weight:D] Stopped 2012-05-24T00:37:43.712Z,1337819863.712 [tank_weight:D](INFO): Aggregate::uninitialize tank_weight:D 2012-05-24T00:37:43.712Z,1337819863.712 [tank_weight:D:A.SetSpeed] Stopped 2012-05-24T00:37:43.712Z,1337819863.712 [tank_weight:D:A.SetSpeed](DEBUG): Uninitialize. 2012-05-24T00:37:43.712Z,1337819863.712 [tank_weight:D:B.Pitch] Stopped 2012-05-24T00:37:43.712Z,1337819863.712 [tank_weight:D:BuoyancyLo] Stopped 2012-05-24T00:37:43.712Z,1337819863.712 [tank_weight:D:BuoyancyLo](INFO): Aggregate::uninitialize tank_weight:D:BuoyancyLo 2012-05-24T00:37:43.712Z,1337819863.713 [tank_weight:D:BuoyancyLo:A.Buoyancy] Stopped 2012-05-24T00:37:43.713Z,1337819863.713 [tank_weight:D:BuoyancyLo:A.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2012-05-24T00:37:43.713Z,1337819863.713 [tank_weight:D:BuoyancyLo:B.Wait] Stopped 2012-05-24T00:37:43.713Z,1337819863.713 [tank_weight:D:BuoyancyLo:B.Wait](DEBUG): Uninitialize Wait Component. 2012-05-24T00:37:44.175Z,1337819864.175 [WetLabsBB2FL](INFO): Powering down 2012-05-24T00:37:44.187Z,1337819864.187 [MissionManager](IMPORTANT): Started mission Default 2012-05-24T00:37:44.188Z,1337819864.188 [Default] Running Loop=1 2012-05-24T00:37:44.188Z,1337819864.188 [Default](INFO): Aggregate::initialize Default 2012-05-24T00:37:44.188Z,1337819864.188 [Default:D.SetSpeed] Running Loop=1 2012-05-24T00:37:44.188Z,1337819864.188 [Default:D.SetSpeed](DEBUG): Initialize. 2012-05-24T00:37:44.188Z,1337819864.188 [Default:E.GoToSurface] Running Loop=1 2012-05-24T00:37:44.188Z,1337819864.188 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-05-24T00:37:44.188Z,1337819864.188 [Default:Iridium] Running Loop=1 2012-05-24T00:37:44.188Z,1337819864.188 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2012-05-24T00:37:44.189Z,1337819864.188 [Default:Iridium:A.SetSpeed] Running Loop=1 2012-05-24T00:37:44.189Z,1337819864.189 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2012-05-24T00:37:44.189Z,1337819864.189 [Default:Iridium:B.GoToSurface] Running Loop=1 2012-05-24T00:37:44.189Z,1337819864.189 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-05-24T00:37:44.191Z,1337819864.191 [Default:CallIridium] Running Loop=1 2012-05-24T00:37:44.191Z,1337819864.191 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2012-05-24T00:37:44.191Z,1337819864.191 [Default:CallIridium:A] Running Loop=1 2012-05-24T00:37:44.191Z,1337819864.191 [Default:CallIridium:A] Stopped 2012-05-24T00:37:44.191Z,1337819864.191 [Default:CallIridium:B] Running Loop=1 2012-05-24T00:37:44.191Z,1337819864.191 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2012-05-24T00:37:44.192Z,1337819864.192 [Default:Iridium:B.GoToSurface] Stopped 2012-05-24T00:37:44.192Z,1337819864.192 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-05-24T00:37:44.192Z,1337819864.192 [Default:Iridium:Read_Iridium] Running Loop=1 2012-05-24T00:37:44.193Z,1337819864.193 [Default:GPS] Running Loop=1 2012-05-24T00:37:44.193Z,1337819864.193 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2012-05-24T00:37:44.193Z,1337819864.193 [Default:GPS:A.SetSpeed] Running Loop=1 2012-05-24T00:37:44.193Z,1337819864.193 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2012-05-24T00:37:44.193Z,1337819864.193 [Default:GPS:B.GoToSurface] Running Loop=1 2012-05-24T00:37:44.193Z,1337819864.193 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-05-24T00:37:44.194Z,1337819864.194 [Default:GPS:B.GoToSurface] Stopped 2012-05-24T00:37:44.194Z,1337819864.194 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-05-24T00:37:44.194Z,1337819864.194 [Default:GPS:Read_GPS] Running Loop=1 2012-05-24T00:37:51.159Z,1337819871.159 [CommandLine](IMPORTANT): got command quit 2012-05-24T00:37:51.234Z,1337819871.234 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2012-05-24T00:37:51.235Z,1337819871.234 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2012-05-24T00:37:51.327Z,1337819871.327 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler 2012-05-24T00:37:51.403Z,1337819871.403 [ComponentRegistry](INFO): Shutting down AsyncPiEstimator ThreadHandler 2012-05-24T00:37:51.593Z,1337819871.593 [AsyncPiEstimator](DEBUG): Uninitialize AsyncPiEstimator. 2012-05-24T00:37:51.593Z,1337819871.593 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2012-05-24T00:37:51.593Z,1337819871.593 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2012-05-24T00:37:51.660Z,1337819871.660 [controlThread](DEBUG): Uninitializing ControlThread 2012-05-24T00:37:51.660Z,1337819871.660 [AHRS_sp3003D](INFO): Powering down 2012-05-24T00:37:51.748Z,1337819871.747 [DVL_micro](INFO): Powering down 2012-05-24T00:37:51.748Z,1337819871.748 [NAL9601](INFO): Powering down 2012-05-24T00:37:51.749Z,1337819871.749 [WetLabsBB2FL](INFO): Powering down 2012-05-24T00:37:51.749Z,1337819871.749 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2012-05-24T00:37:51.750Z,1337819871.750 [NavChart](DEBUG): Uninitialize NavChart Derivation. 2012-05-24T00:37:51.751Z,1337819871.751 [Default] Stopped 2012-05-24T00:37:51.751Z,1337819871.751 [Default](INFO): Aggregate::uninitialize Default 2012-05-24T00:37:51.751Z,1337819871.751 [Default:GPS] Stopped 2012-05-24T00:37:51.751Z,1337819871.751 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2012-05-24T00:37:51.751Z,1337819871.751 [Default:GPS:A.SetSpeed] Stopped 2012-05-24T00:37:51.751Z,1337819871.751 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2012-05-24T00:37:51.751Z,1337819871.751 [Default:GPS:Read_GPS] Stopped 2012-05-24T00:37:51.752Z,1337819871.751 [Default:Iridium] Stopped 2012-05-24T00:37:51.752Z,1337819871.752 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2012-05-24T00:37:51.752Z,1337819871.752 [Default:Iridium:A.SetSpeed] Stopped 2012-05-24T00:37:51.752Z,1337819871.752 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2012-05-24T00:37:51.752Z,1337819871.752 [Default:Iridium:Read_Iridium] Stopped 2012-05-24T00:37:51.752Z,1337819871.752 [Default:CallIridium] Stopped 2012-05-24T00:37:51.752Z,1337819871.752 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2012-05-24T00:37:51.752Z,1337819871.752 [Default:CallIridium:B] Stopped 2012-05-24T00:37:51.752Z,1337819871.752 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2012-05-24T00:37:51.752Z,1337819871.752 [Default:D.SetSpeed] Stopped 2012-05-24T00:37:51.752Z,1337819871.752 [Default:D.SetSpeed](DEBUG): Uninitialize. 2012-05-24T00:37:51.752Z,1337819871.752 [Default:E.GoToSurface] Stopped 2012-05-24T00:37:51.752Z,1337819871.753 [Default:E.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-05-24T00:37:51.757Z,1337819871.757 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2012-05-24T00:37:51.757Z,1337819871.757 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2012-05-24T00:37:51.757Z,1337819871.757 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2012-05-24T00:37:51.758Z,1337819871.758 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2012-05-24T00:37:51.758Z,1337819871.758 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2012-05-24T00:37:51.758Z,1337819871.758 [BuoyancyServo](INFO): Powering down 2012-05-24T00:37:51.759Z,1337819871.759 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2012-05-24T00:37:51.759Z,1337819871.759 [ElevatorServo](INFO): Powering down 2012-05-24T00:37:51.759Z,1337819871.759 [MassServo](DEBUG): Uninitialize Mass Servo. 2012-05-24T00:37:51.759Z,1337819871.759 [MassServo](INFO): Powering down 2012-05-24T00:37:51.760Z,1337819871.760 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2012-05-24T00:37:51.760Z,1337819871.760 [RudderServo](INFO): Powering down 2012-05-24T00:37:51.760Z,1337819871.760 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2012-05-24T00:37:51.760Z,1337819871.760 [ThrusterServo](INFO): Powering down 2012-05-24T00:37:51.761Z,1337819871.761 [SBIT](DEBUG): Uninitialize SBIT Component. 2012-05-24T00:37:51.761Z,1337819871.761 [IBIT](DEBUG): Uninitialize IBIT Component. 2012-05-24T00:37:51.761Z,1337819871.761 [CBIT](DEBUG): Uninitialize CBIT Component.