2013-03-05T08:11:16.123Z,1362471076.123 [Supervisor](DEBUG): Initializing supervisor.
2013-03-05T08:11:16.126Z,1362471076.126 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0
2013-03-05T08:11:16.127Z,1362471076.127 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2013-03-05T08:11:16.131Z,1362471076.131 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0
2013-03-05T08:11:16.134Z,1362471076.134 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2013-03-05T08:11:16.145Z,1362471076.145 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2013-03-05T08:11:16.147Z,1362471076.147 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0
2013-03-05T08:11:16.147Z,1362471076.147 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2013-03-05T08:11:16.150Z,1362471076.151 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0
2013-03-05T08:11:16.151Z,1362471076.151 [Supervisor](INFO): Looking for Config files in directory: Config/
2013-03-05T08:11:16.155Z,1362471076.155 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2013-03-05T08:11:16.466Z,1362471076.466 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2013-03-05T08:11:16.467Z,1362471076.467 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2013-03-05T08:11:16.675Z,1362471076.675 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2013-03-05T08:11:16.676Z,1362471076.676 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2013-03-05T08:11:16.771Z,1362471076.771 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2013-03-05T08:11:16.773Z,1362471076.773 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2013-03-05T08:11:16.982Z,1362471076.982 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2013-03-05T08:11:16.983Z,1362471076.983 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2013-03-05T08:11:17.131Z,1362471077.131 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2013-03-05T08:11:17.133Z,1362471077.133 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2013-03-05T08:11:17.386Z,1362471077.386 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2013-03-05T08:11:17.387Z,1362471077.387 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2013-03-05T08:11:17.575Z,1362471077.575 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2013-03-05T08:11:17.577Z,1362471077.577 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2013-03-05T08:11:17.852Z,1362471077.852 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2013-03-05T08:11:17.854Z,1362471077.854 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2013-03-05T08:11:17.967Z,1362471077.967 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2013-03-05T08:11:17.968Z,1362471077.968 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2013-03-05T08:11:18.408Z,1362471078.408 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2013-03-05T08:11:18.408Z,1362471078.408 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2013-03-05T08:11:18.536Z,1362471078.536 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2013-03-05T08:11:18.536Z,1362471078.536 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2013-03-05T08:11:18.628Z,1362471078.628 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2013-03-05T08:11:18.631Z,1362471078.631 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2013-03-05T08:11:18.878Z,1362471078.878 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2013-03-05T08:11:19.038Z,1362471079.039 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2013-03-05T08:11:19.134Z,1362471079.134 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2013-03-05T08:11:19.246Z,1362471079.246 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2013-03-05T08:11:19.356Z,1362471079.356 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2013-03-05T08:11:19.488Z,1362471079.488 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2013-03-05T08:11:19.592Z,1362471079.592 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2013-03-05T08:11:19.690Z,1362471079.690 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2013-03-05T08:11:19.720Z,1362471079.720 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2013-03-05T08:11:19.922Z,1362471079.922 [InternalSim] Loaded
2013-03-05T08:11:19.923Z,1362471079.923 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2013-03-05T08:11:19.924Z,1362471079.924 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2013-03-05T08:11:19.924Z,1362471079.924 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2013-03-05T08:11:20.007Z,1362471080.007 [SBIT](DEBUG): Construct Startup Built In Test.
2013-03-05T08:11:20.039Z,1362471080.039 [SBIT] Loaded
2013-03-05T08:11:20.040Z,1362471080.039 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2013-03-05T08:11:20.040Z,1362471080.040 [IBIT](DEBUG): Construct Initiated Built In Test.
2013-03-05T08:11:20.073Z,1362471080.073 [IBIT] Loaded
2013-03-05T08:11:20.073Z,1362471080.073 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2013-03-05T08:11:20.077Z,1362471080.077 [CBIT](DEBUG): Construct CBIT Built In Test.
2013-03-05T08:11:20.209Z,1362471080.209 [CBIT] Loaded
2013-03-05T08:11:20.209Z,1362471080.209 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2013-03-05T08:11:20.210Z,1362471080.210 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2013-03-05T08:11:20.211Z,1362471080.211 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2013-03-05T08:11:20.388Z,1362471080.388 [BuoyancyServo] Loaded
2013-03-05T08:11:20.388Z,1362471080.388 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2013-03-05T08:11:20.401Z,1362471080.401 [ElevatorServo] Loaded
2013-03-05T08:11:20.401Z,1362471080.401 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2013-03-05T08:11:20.417Z,1362471080.417 [MassServo] Loaded
2013-03-05T08:11:20.417Z,1362471080.417 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2013-03-05T08:11:20.429Z,1362471080.429 [RudderServo] Loaded
2013-03-05T08:11:20.429Z,1362471080.429 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2013-03-05T08:11:20.441Z,1362471080.441 [ThrusterServo] Loaded
2013-03-05T08:11:20.442Z,1362471080.441 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2013-03-05T08:11:20.442Z,1362471080.442 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2013-03-05T08:11:20.443Z,1362471080.443 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2013-03-05T08:11:20.478Z,1362471080.478 [DepthRateCalculator] Loaded
2013-03-05T08:11:20.479Z,1362471080.478 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2013-03-05T08:11:23.941Z,1362471083.941 [HFRadarModelCalc] Loaded
2013-03-05T08:11:23.941Z,1362471083.941 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2013-03-05T08:11:23.962Z,1362471083.962 [NavChart] Loaded
2013-03-05T08:11:23.962Z,1362471083.962 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2013-03-05T08:11:23.968Z,1362471083.968 [PitchRateCalculator] Loaded
2013-03-05T08:11:23.968Z,1362471083.968 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2013-03-05T08:11:23.975Z,1362471083.975 [SpeedCalculator] Loaded
2013-03-05T08:11:23.975Z,1362471083.975 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2013-03-05T08:11:23.990Z,1362471083.990 [TempGradientCalculator] Loaded
2013-03-05T08:11:23.990Z,1362471083.990 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2013-03-05T08:11:23.996Z,1362471083.996 [YawRateCalculator] Loaded
2013-03-05T08:11:23.996Z,1362471083.996 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2013-03-05T08:11:24.045Z,1362471084.045 [Navigation] Loaded
2013-03-05T08:11:24.045Z,1362471084.045 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread.
2013-03-05T08:11:24.046Z,1362471084.046 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2013-03-05T08:11:24.046Z,1362471084.046 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2013-03-05T08:11:26.231Z,1362471086.231 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2013-03-05T08:11:26.232Z,1362471086.232 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2013-03-05T08:11:26.270Z,1362471086.270 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2013-03-05T08:11:26.274Z,1362471086.274 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2013-03-05T08:11:26.337Z,1362471086.337 [VerticalControl](DEBUG): Construct VerticalControl.
2013-03-05T08:11:26.438Z,1362471086.438 [VerticalControl] Loaded
2013-03-05T08:11:26.439Z,1362471086.439 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2013-03-05T08:11:26.440Z,1362471086.440 [HorizontalControl](DEBUG): Construct HorizontalControl.
2013-03-05T08:11:26.504Z,1362471086.504 [HorizontalControl] Loaded
2013-03-05T08:11:26.504Z,1362471086.504 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2013-03-05T08:11:26.505Z,1362471086.505 [SpeedControl](DEBUG): Construct SpeedControl.
2013-03-05T08:11:26.507Z,1362471086.507 [SpeedControl] Loaded
2013-03-05T08:11:26.507Z,1362471086.507 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2013-03-05T08:11:26.508Z,1362471086.508 [LoopControl](DEBUG): Construct LoopControl.
2013-03-05T08:11:26.509Z,1362471086.509 [LoopControl] Loaded
2013-03-05T08:11:26.509Z,1362471086.509 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2013-03-05T08:11:26.510Z,1362471086.510 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2013-03-05T08:11:26.510Z,1362471086.510 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2013-03-05T08:11:26.518Z,1362471086.518 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator.
2013-03-05T08:11:26.523Z,1362471086.523 [AsyncPiEstimator] Loaded
2013-03-05T08:11:26.523Z,1362471086.523 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread.
2013-03-05T08:11:26.527Z,1362471086.527 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406A44E0
2013-03-05T08:11:26.527Z,1362471086.527 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2013-03-05T08:11:26.528Z,1362471086.528 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2013-03-05T08:11:26.712Z,1362471086.712 [AHRS_sp3003D] Loaded
2013-03-05T08:11:26.713Z,1362471086.713 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2013-03-05T08:11:27.000Z,1362471087.000 [Batt_Ocean_Server] Loaded
2013-03-05T08:11:27.001Z,1362471087.001 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2013-03-05T08:11:27.014Z,1362471087.014 [Depth_Keller] Loaded
2013-03-05T08:11:27.014Z,1362471087.014 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2013-03-05T08:11:27.020Z,1362471087.020 [DropWeight] Loaded
2013-03-05T08:11:27.020Z,1362471087.020 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2013-03-05T08:11:27.216Z,1362471087.216 [DVL_micro] Loaded
2013-03-05T08:11:27.216Z,1362471087.216 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread.
2013-03-05T08:11:27.219Z,1362471087.218 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 407284E0
2013-03-05T08:11:27.310Z,1362471087.310 [NAL9602] Loaded
2013-03-05T08:11:27.310Z,1362471087.310 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2013-03-05T08:11:27.365Z,1362471087.365 [Onboard] Loaded
2013-03-05T08:11:27.365Z,1362471087.365 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2013-03-05T08:11:27.376Z,1362471087.376 [Radio_Freewave] Loaded
2013-03-05T08:11:27.376Z,1362471087.376 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread.
2013-03-05T08:11:27.377Z,1362471087.377 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2013-03-05T08:11:27.377Z,1362471087.378 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2013-03-05T08:11:27.463Z,1362471087.463 [Aanderaa_O2] Loaded
2013-03-05T08:11:27.463Z,1362471087.463 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2013-03-05T08:11:27.504Z,1362471087.504 [CTD_NeilBrown] Loaded
2013-03-05T08:11:27.504Z,1362471087.504 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2013-03-05T08:11:27.507Z,1362471087.507 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4077A4E0
2013-03-05T08:11:27.520Z,1362471087.520 [ISUS] Loaded
2013-03-05T08:11:27.520Z,1362471087.520 [ComponentRegistry](DEBUG): SyncComponent "ISUS" handled in the control thread.
2013-03-05T08:11:27.540Z,1362471087.540 [PAR_Licor] Loaded
2013-03-05T08:11:27.540Z,1362471087.540 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2013-03-05T08:11:27.570Z,1362471087.570 [WetLabsBB2FL] Loaded
2013-03-05T08:11:27.574Z,1362471087.574 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2013-03-05T08:11:27.578Z,1362471087.579 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407AA4E0
2013-03-05T08:11:27.579Z,1362471087.579 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2013-03-05T08:11:27.581Z,1362471087.582 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2013-03-05T08:11:27.583Z,1362471087.583 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2013-03-05T08:11:27.593Z,1362471087.593 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2013-03-05T08:11:27.595Z,1362471087.595 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 407DA4E0
2013-03-05T08:11:27.599Z,1362471087.599 [Supervisor](DEBUG): Running supervisor.
2013-03-05T08:11:27.600Z,1362471087.600 [CommandLine](INFO): Thread ID is 749
2013-03-05T08:11:27.603Z,1362471087.603 [controlThread](INFO): Thread ID is 748
2013-03-05T08:11:27.603Z,1362471087.603 [controlThread](DEBUG): Initializing ControlThread
2013-03-05T08:11:27.604Z,1362471087.604 [CycleStarter](INFO): Thread ID is 747
2013-03-05T08:11:27.604Z,1362471087.604 [InternalSim](DEBUG):  InternalSim initializing...
2013-03-05T08:11:27.714Z,1362471087.714 [logger](INFO): Thread ID is 750
2013-03-05T08:11:27.807Z,1362471087.807 [AsyncPiEstimator](INFO): Thread ID is 811
2013-03-05T08:11:27.807Z,1362471087.807 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator.
2013-03-05T08:11:27.912Z,1362471087.912 [DVL_micro](INFO): Thread ID is 812
2013-03-05T08:11:27.955Z,1362471087.955 [DVL_micro](INFO): Initializing
2013-03-05T08:11:27.955Z,1362471087.955 [DVL_micro](INFO): start:Powering up
2013-03-05T08:11:27.956Z,1362471087.956 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-03-05T08:11:27.957Z,1362471087.957 [DVL_micro](INFO): Cycling power to configure device.
2013-03-05T08:11:27.993Z,1362471087.993 [CTD_NeilBrown](INFO): Thread ID is 813
2013-03-05T08:11:27.993Z,1362471087.993 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2013-03-05T08:11:27.996Z,1362471087.996 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2013-03-05T08:11:28.009Z,1362471088.009 [SBIT](INFO): Initialize SBIT Component.
2013-03-05T08:11:28.010Z,1362471088.010 [SBIT](IMPORTANT): Tethys CM Info:
$Rev: 10215
2013-03-05T08:11:28.015Z,1362471088.015 [IBIT](INFO): Initialize IBIT Component.
2013-03-05T08:11:28.031Z,1362471088.031 [CBIT](DEBUG): Initialize CBIT Component.
2013-03-05T08:11:28.031Z,1362471088.031 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2013-03-05T08:11:28.032Z,1362471088.032 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2013-03-05T08:11:28.032Z,1362471088.033 [WetLabsBB2FL](INFO): Thread ID is 814
2013-03-05T08:11:28.033Z,1362471088.033 [WetLabsBB2FL](INFO): Powering down
2013-03-05T08:11:28.060Z,1362471088.060 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2013-03-05T08:11:28.061Z,1362471088.061 [NavChart](DEBUG): Initialize NavChart Derivation.
2013-03-05T08:11:28.061Z,1362471088.061 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2013-03-05T08:11:28.062Z,1362471088.062 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2013-03-05T08:11:28.062Z,1362471088.062 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2013-03-05T08:11:28.064Z,1362471088.064 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2013-03-05T08:11:28.064Z,1362471088.065 [Navigation](DEBUG): Initializing Navigation.
2013-03-05T08:11:28.065Z,1362471088.065 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2013-03-05T08:11:28.067Z,1362471088.067 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2013-03-05T08:11:28.068Z,1362471088.068 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2013-03-05T08:11:28.068Z,1362471088.068 [LoopControl](DEBUG): Initialize LoopControlComponent.
2013-03-05T08:11:28.073Z,1362471088.073 [NavChartDb](INFO): Thread ID is 815
2013-03-05T08:11:28.082Z,1362471088.082 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2013-03-05T08:11:28.083Z,1362471088.083 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2013-03-05T08:11:28.083Z,1362471088.083 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2013-03-05T08:11:28.083Z,1362471088.083 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2013-03-05T08:11:28.084Z,1362471088.084 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2013-03-05T08:11:28.084Z,1362471088.084 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2013-03-05T08:11:28.084Z,1362471088.084 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2013-03-05T08:11:28.084Z,1362471088.084 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2013-03-05T08:11:28.084Z,1362471088.085 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2013-03-05T08:11:29.968Z,1362471089.968 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2013-03-05T08:11:30.014Z,1362471090.014 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2013-03-05T08:11:30.039Z,1362471090.039 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-03-05T08:11:30.039Z,1362471090.039 [DVL_micro](INFO): Querying output modes
2013-03-05T08:11:30.040Z,1362471090.040 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-03-05T08:11:30.051Z,1362471090.051 [DVL_micro](DEBUG): cmdResponse: 01
2013-03-05T08:11:30.051Z,1362471090.051 [DVL_micro](INFO): NQ1 output enabled
2013-03-05T08:11:30.051Z,1362471090.051 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-03-05T08:11:30.063Z,1362471090.063 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 
2013-03-05T08:11:30.068Z,1362471090.068 [DVL_micro](INFO): pause:Powering down
2013-03-05T08:11:30.081Z,1362471090.081 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2013-03-05T08:11:30.104Z,1362471090.104 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://aosn.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface RunIn="Progression"/>

    <Aggregate Id="StartupSatComms" >

        <ReadDatum>
            <Timeout Duration="P1M" /><Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" /><Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2013-03-05T08:11:30.105Z,1362471090.105 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2013-03-05T08:11:30.175Z,1362471090.175 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2013-03-05T08:11:30.177Z,1362471090.177 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2013-03-05T08:11:30.196Z,1362471090.196 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-03-05T08:11:30.204Z,1362471090.204 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2013-03-05T08:11:30.239Z,1362471090.239 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-03-05T08:11:30.246Z,1362471090.246 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2013-03-05T08:11:30.284Z,1362471090.284 [Default:D.SetSpeed](DEBUG): Construct.
2013-03-05T08:11:30.287Z,1362471090.287 [Default:E.GoToSurface](DEBUG): Construct GoToSurface.
2013-03-05T08:11:30.292Z,1362471090.292 [Default:F.Wait](DEBUG): Construct Wait.
2013-03-05T08:11:30.308Z,1362471090.308 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
xmlns:Control="Tethys/Control"
xmlns:Guidance="Tethys/Guidance" 
xmlns:Units="Tethys/Units"
xmlns:Universal="Tethys/Universal"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="Tethys http://aosn.mbari.org/tethys/Xml/Tethys.xsd
Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
Id="Default">

    <DefineArg Name="NeedGPS"><True/></DefineArg>

    <Aggregate Id="GPS" >

        <When><Arg Name="NeedGPS"/>
        </When>

<!-- Run at high speed -->

        <Guidance:SetSpeed RunIn="Parallel">
            <Setting><Guidance:SetSpeed.period/><Units:millisecond/><Value>400</Value></Setting>
        </Guidance:SetSpeed>

<!-- Get to the surface -->

        <Guidance:GoToSurface RunIn="Sequence"/>

<!-- Get GPS fix -->

        <ReadDatum Id="Read_GPS"><Universal:latitude_fix/>
        </ReadDatum>

        <Assign><Arg Name="NeedGPS"/><False/></Assign>

    </Aggregate>

    <Aggregate Id="Iridium" >

<!-- Run at high speed -->

        <Guidance:SetSpeed RunIn="Parallel">
            <Setting><Guidance:SetSpeed.period/><Units:millisecond/><Value>400</Value></Setting>
        </Guidance:SetSpeed>

<!-- Get to the surface -->

        <Guidance:GoToSurface RunIn="Sequence"/>

<!-- Do data comms -->

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P2H">
                <Guidance:Execute RunIn="Sequence">
                    <Setting>
                    <Guidance:Execute.command/><String>Burn 300</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped drop weight due to communications timeout</Syslog>
            </Timeout><Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

    <Aggregate Id="CallIridium" >

        <When>
            <Elapsed><Universal:platform_communications/></Elapsed>
            <Gt><Units:minute/><Value>5.0</Value></Gt>
            <And><Universal:platform_conversation/><Eq><True/></Eq></And>
            <Or>
            <Elapsed><Universal:platform_communications/></Elapsed><Gt><Units:hour/><Value>1.0</Value></Gt></Or>
        </When>

        <Assign><Arg Name="NeedGPS"/><True/></Assign>

        <Call RefId="Iridium"/>

    </Aggregate>

<!-- Wait forever at the surface-->

<!-- Run at low speed -->

    <Guidance:SetSpeed RunIn="Parallel">
        <Setting><Guidance:SetSpeed.period/><Units:second/><Value>5</Value></Setting>
    </Guidance:SetSpeed>

    <Guidance:GoToSurface RunIn="Parallel"/>

    <Guidance:Wait RunIn="Sequence"></Guidance:Wait>

</Mission>


2013-03-05T08:11:30.313Z,1362471090.313 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,NAL9602,Onboard,Radio_Freewave,Aanderaa_O2,ISUS,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,
2013-03-05T08:11:30.391Z,1362471090.391 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-03-05T08:11:30.411Z,1362471090.411 [Depth_Keller](ERROR): Pressure reading out of range: 1831.078247 decibar
2013-03-05T08:11:30.515Z,1362471090.515 [Radio_Freewave](INFO): Powering up
2013-03-05T08:11:30.931Z,1362471090.931 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2013-03-05T08:11:30.939Z,1362471090.939 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2013-03-05T08:11:30.961Z,1362471090.961 [ElevatorServo](DEBUG): Initializing EZServoServo.
2013-03-05T08:11:30.971Z,1362471090.971 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2013-03-05T08:11:30.985Z,1362471090.985 [MassServo](DEBUG): Initializing EZServoServo.
2013-03-05T08:11:30.988Z,1362471090.988 [MassServo](DEBUG): Initializing MassServo.
2013-03-05T08:11:30.994Z,1362471090.994 [RudderServo](DEBUG): Initializing EZServoServo.
2013-03-05T08:11:30.999Z,1362471090.999 [RudderServo](DEBUG): Initializing RudderServo.
2013-03-05T08:11:31.004Z,1362471091.004 [ThrusterServo](DEBUG): Initializing EZServoServo.
2013-03-05T08:11:31.011Z,1362471091.011 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2013-03-05T08:11:32.123Z,1362471092.123 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2013-03-05T08:11:32.123Z,1362471092.123 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2013-03-05T08:11:32.123Z,1362471092.123 [BuoyancyServo] Communications Fault, FailCount= 1
2013-03-05T08:11:32.123Z,1362471092.123 [BuoyancyServo](ERROR): Communications Fault
2013-03-05T08:11:32.325Z,1362471092.325 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2013-03-05T08:11:32.563Z,1362471092.563 [NAL9602](INFO): Powering up NAL9602
2013-03-05T08:11:32.602Z,1362471092.602 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2013-03-05T08:11:32.603Z,1362471092.603 [BuoyancyServo](INFO): Powering down
2013-03-05T08:11:33.871Z,1362471093.871 [Aanderaa_O2](INFO): Powering down
2013-03-05T08:11:34.905Z,1362471094.905 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2013-03-05T08:11:34.905Z,1362471094.905 [BuoyancyServo] No Fault, FailCount= 1
2013-03-05T08:11:35.179Z,1362471095.179 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2013-03-05T08:11:35.311Z,1362471095.311 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.