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.