2012-10-26T00:01:17.007Z,1351209677.007 [Supervisor](DEBUG): Initializing supervisor.
2012-10-26T00:01:17.009Z,1351209677.009 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0
2012-10-26T00:01:17.010Z,1351209677.010 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2012-10-26T00:01:17.011Z,1351209677.011 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0
2012-10-26T00:01:17.014Z,1351209677.014 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2012-10-26T00:01:17.025Z,1351209677.025 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2012-10-26T00:01:17.026Z,1351209677.026 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0
2012-10-26T00:01:17.027Z,1351209677.027 [ComponentRegistry](DEBUG): SyncComponent "logger" handled in the control thread.
2012-10-26T00:01:17.027Z,1351209677.027 [Supervisor](INFO): Looking for Config files in directory: Config/
2012-10-26T00:01:17.030Z,1351209677.030 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2012-10-26T00:01:17.366Z,1351209677.366 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2012-10-26T00:01:17.368Z,1351209677.368 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2012-10-26T00:01:17.544Z,1351209677.544 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2012-10-26T00:01:17.544Z,1351209677.544 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2012-10-26T00:01:17.630Z,1351209677.630 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2012-10-26T00:01:17.632Z,1351209677.632 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2012-10-26T00:01:17.834Z,1351209677.834 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2012-10-26T00:01:17.835Z,1351209677.835 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2012-10-26T00:01:17.969Z,1351209677.969 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2012-10-26T00:01:17.972Z,1351209677.972 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2012-10-26T00:01:18.197Z,1351209678.197 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2012-10-26T00:01:18.198Z,1351209678.198 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2012-10-26T00:01:18.365Z,1351209678.365 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2012-10-26T00:01:18.367Z,1351209678.367 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2012-10-26T00:01:18.611Z,1351209678.611 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2012-10-26T00:01:18.613Z,1351209678.613 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2012-10-26T00:01:18.712Z,1351209678.712 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2012-10-26T00:01:18.713Z,1351209678.713 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2012-10-26T00:01:19.102Z,1351209679.102 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2012-10-26T00:01:19.102Z,1351209679.102 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2012-10-26T00:01:19.216Z,1351209679.216 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2012-10-26T00:01:19.217Z,1351209679.217 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2012-10-26T00:01:19.303Z,1351209679.303 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2012-10-26T00:01:19.307Z,1351209679.307 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2012-10-26T00:01:19.407Z,1351209679.408 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2012-10-26T00:01:19.542Z,1351209679.542 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2012-10-26T00:01:19.677Z,1351209679.677 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2012-10-26T00:01:19.779Z,1351209679.779 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2012-10-26T00:01:19.878Z,1351209679.878 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2012-10-26T00:01:19.995Z,1351209679.995 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2012-10-26T00:01:20.088Z,1351209680.088 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2012-10-26T00:01:20.176Z,1351209680.176 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2012-10-26T00:01:20.206Z,1351209680.206 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2012-10-26T00:01:20.374Z,1351209680.374 [InternalSim] Loaded
2012-10-26T00:01:20.374Z,1351209680.374 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2012-10-26T00:01:20.375Z,1351209680.375 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2012-10-26T00:01:20.376Z,1351209680.376 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2012-10-26T00:01:20.452Z,1351209680.453 [SBIT](DEBUG): Construct Startup Built In Test.
2012-10-26T00:01:20.466Z,1351209680.466 [SBIT] Loaded
2012-10-26T00:01:20.466Z,1351209680.466 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2012-10-26T00:01:20.467Z,1351209680.467 [IBIT](DEBUG): Construct Initiated Built In Test.
2012-10-26T00:01:20.495Z,1351209680.495 [IBIT] Loaded
2012-10-26T00:01:20.495Z,1351209680.495 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2012-10-26T00:01:20.499Z,1351209680.499 [CBIT](DEBUG): Construct CBIT Built In Test.
2012-10-26T00:01:20.614Z,1351209680.614 [CBIT] Loaded
2012-10-26T00:01:20.614Z,1351209680.614 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2012-10-26T00:01:20.615Z,1351209680.615 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2012-10-26T00:01:20.615Z,1351209680.615 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2012-10-26T00:01:20.777Z,1351209680.777 [BuoyancyServo] Loaded
2012-10-26T00:01:20.777Z,1351209680.777 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2012-10-26T00:01:20.786Z,1351209680.786 [ElevatorServo] Loaded
2012-10-26T00:01:20.786Z,1351209680.786 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2012-10-26T00:01:20.798Z,1351209680.798 [MassServo] Loaded
2012-10-26T00:01:20.798Z,1351209680.798 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2012-10-26T00:01:20.810Z,1351209680.810 [RudderServo] Loaded
2012-10-26T00:01:20.810Z,1351209680.810 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2012-10-26T00:01:20.822Z,1351209680.822 [ThrusterServo] Loaded
2012-10-26T00:01:20.822Z,1351209680.822 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2012-10-26T00:01:20.822Z,1351209680.822 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2012-10-26T00:01:20.823Z,1351209680.823 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2012-10-26T00:01:20.855Z,1351209680.855 [DepthRateCalculator] Loaded
2012-10-26T00:01:20.856Z,1351209680.856 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2012-10-26T00:01:24.954Z,1351209684.954 [HFRadarModelCalc] Loaded
2012-10-26T00:01:24.954Z,1351209684.954 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2012-10-26T00:01:24.970Z,1351209684.970 [NavChart] Loaded
2012-10-26T00:01:24.970Z,1351209684.970 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2012-10-26T00:01:24.976Z,1351209684.976 [PitchRateCalculator] Loaded
2012-10-26T00:01:24.976Z,1351209684.976 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2012-10-26T00:01:24.982Z,1351209684.982 [SpeedCalculator] Loaded
2012-10-26T00:01:24.983Z,1351209684.983 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2012-10-26T00:01:24.997Z,1351209684.997 [TempGradientCalculator] Loaded
2012-10-26T00:01:24.997Z,1351209684.997 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2012-10-26T00:01:25.002Z,1351209685.002 [YawRateCalculator] Loaded
2012-10-26T00:01:25.003Z,1351209685.003 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2012-10-26T00:01:25.022Z,1351209685.022 [Navigation] Loaded
2012-10-26T00:01:25.022Z,1351209685.022 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread.
2012-10-26T00:01:25.023Z,1351209685.023 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2012-10-26T00:01:25.023Z,1351209685.023 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2012-10-26T00:01:25.272Z,1351209685.272 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2012-10-26T00:01:25.273Z,1351209685.273 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2012-10-26T00:01:25.310Z,1351209685.310 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2012-10-26T00:01:25.311Z,1351209685.311 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2012-10-26T00:01:25.368Z,1351209685.368 [VerticalControl](DEBUG): Construct VerticalControl.
2012-10-26T00:01:25.414Z,1351209685.414 [VerticalControl] Loaded
2012-10-26T00:01:25.414Z,1351209685.414 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2012-10-26T00:01:25.415Z,1351209685.415 [HorizontalControl](DEBUG): Construct HorizontalControl.
2012-10-26T00:01:25.436Z,1351209685.436 [HorizontalControl] Loaded
2012-10-26T00:01:25.436Z,1351209685.436 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2012-10-26T00:01:25.437Z,1351209685.437 [SpeedControl](DEBUG): Construct SpeedControl.
2012-10-26T00:01:25.438Z,1351209685.438 [SpeedControl] Loaded
2012-10-26T00:01:25.439Z,1351209685.439 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2012-10-26T00:01:25.440Z,1351209685.440 [LoopControl](DEBUG): Construct LoopControl.
2012-10-26T00:01:25.440Z,1351209685.440 [LoopControl] Loaded
2012-10-26T00:01:25.440Z,1351209685.441 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2012-10-26T00:01:25.441Z,1351209685.441 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2012-10-26T00:01:25.442Z,1351209685.442 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2012-10-26T00:01:25.450Z,1351209685.450 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator.
2012-10-26T00:01:25.454Z,1351209685.454 [AsyncPiEstimator] Loaded
2012-10-26T00:01:25.455Z,1351209685.455 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread.
2012-10-26T00:01:25.456Z,1351209685.456 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406724E0
2012-10-26T00:01:25.456Z,1351209685.457 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2012-10-26T00:01:25.457Z,1351209685.457 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2012-10-26T00:01:25.619Z,1351209685.619 [AHRS_sp3003D] Loaded
2012-10-26T00:01:25.619Z,1351209685.619 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2012-10-26T00:01:25.867Z,1351209685.867 [Batt_Ocean_Server] Loaded
2012-10-26T00:01:25.868Z,1351209685.868 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2012-10-26T00:01:25.880Z,1351209685.880 [Depth_Keller] Loaded
2012-10-26T00:01:25.880Z,1351209685.880 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2012-10-26T00:01:25.886Z,1351209685.885 [DropWeight] Loaded
2012-10-26T00:01:25.886Z,1351209685.886 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2012-10-26T00:01:26.001Z,1351209686.001 [DVL_micro] Loaded
2012-10-26T00:01:26.001Z,1351209686.001 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread.
2012-10-26T00:01:26.002Z,1351209686.003 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 406F34E0
2012-10-26T00:01:26.082Z,1351209686.082 [NAL9602] Loaded
2012-10-26T00:01:26.083Z,1351209686.083 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2012-10-26T00:01:26.131Z,1351209686.131 [Onboard] Loaded
2012-10-26T00:01:26.131Z,1351209686.131 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2012-10-26T00:01:26.138Z,1351209686.138 [Radio_Freewave] Loaded
2012-10-26T00:01:26.138Z,1351209686.138 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread.
2012-10-26T00:01:26.139Z,1351209686.139 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2012-10-26T00:01:26.140Z,1351209686.140 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2012-10-26T00:01:26.232Z,1351209686.232 [CTD_NeilBrown] Loaded
2012-10-26T00:01:26.232Z,1351209686.232 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2012-10-26T00:01:26.233Z,1351209686.233 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4074B4E0
2012-10-26T00:01:26.243Z,1351209686.243 [PAR_Licor] Loaded
2012-10-26T00:01:26.244Z,1351209686.244 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2012-10-26T00:01:26.260Z,1351209686.260 [Turbulence_NPS] Loaded
2012-10-26T00:01:26.260Z,1351209686.260 [ComponentRegistry](DEBUG): Component "Turbulence_NPS" handled in its own thread.
2012-10-26T00:01:26.261Z,1351209686.261 [Turbulence_NPS ThreadHandler](DEBUG): Created PCaller Thread at 4077B4E0
2012-10-26T00:01:26.290Z,1351209686.290 [WetLabsBB2FL] Loaded
2012-10-26T00:01:26.290Z,1351209686.290 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2012-10-26T00:01:26.291Z,1351209686.291 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407AB4E0
2012-10-26T00:01:26.292Z,1351209686.292 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2012-10-26T00:01:26.294Z,1351209686.294 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2012-10-26T00:01:26.295Z,1351209686.295 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2012-10-26T00:01:26.304Z,1351209686.304 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2012-10-26T00:01:26.306Z,1351209686.306 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 407DB4E0
2012-10-26T00:01:26.310Z,1351209686.310 [Supervisor](DEBUG): Running supervisor.
2012-10-26T00:01:26.311Z,1351209686.311 [CommandLine](INFO): Thread ID is 1025
2012-10-26T00:01:26.314Z,1351209686.314 [controlThread](INFO): Thread ID is 1024
2012-10-26T00:01:26.314Z,1351209686.314 [controlThread](DEBUG): Initializing ControlThread
2012-10-26T00:01:26.314Z,1351209686.314 [CycleStarter](INFO): Thread ID is 1023
2012-10-26T00:01:26.315Z,1351209686.315 [InternalSim](DEBUG):  InternalSim initializing...
2012-10-26T00:01:26.412Z,1351209686.412 [AsyncPiEstimator](INFO): Thread ID is 1086
2012-10-26T00:01:26.412Z,1351209686.412 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator.
2012-10-26T00:01:26.474Z,1351209686.474 [DVL_micro](INFO): Thread ID is 1087
2012-10-26T00:01:26.549Z,1351209686.549 [CTD_NeilBrown](INFO): Thread ID is 1088
2012-10-26T00:01:26.550Z,1351209686.550 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2012-10-26T00:01:26.552Z,1351209686.552 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2012-10-26T00:01:26.589Z,1351209686.589 [Turbulence_NPS](INFO): Thread ID is 1089
2012-10-26T00:01:26.589Z,1351209686.589 [Turbulence_NPS](DEBUG): Initializing Turbulence_NPS.
2012-10-26T00:01:26.590Z,1351209686.590 [Turbulence_NPS](INFO): Opening uart, block timeout 10ths=1
2012-10-26T00:01:26.598Z,1351209686.598 [DVL_micro](INFO): Initializing
2012-10-26T00:01:26.598Z,1351209686.598 [DVL_micro](INFO): start:Powering up
2012-10-26T00:01:26.599Z,1351209686.599 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2012-10-26T00:01:26.600Z,1351209686.600 [DVL_micro](INFO): Cycling power to configure device.
2012-10-26T00:01:26.605Z,1351209686.605 [SBIT](INFO): Initialize SBIT Component.
2012-10-26T00:01:26.606Z,1351209686.606 [SBIT](IMPORTANT): Tethys CM Info:
$Rev: 10014
2012-10-26T00:01:26.607Z,1351209686.607 [WetLabsBB2FL](INFO): Thread ID is 1090
2012-10-26T00:01:26.608Z,1351209686.608 [WetLabsBB2FL](INFO): Powering down
2012-10-26T00:01:26.635Z,1351209686.635 [IBIT](INFO): Initialize IBIT Component.
2012-10-26T00:01:26.636Z,1351209686.636 [CBIT](DEBUG): Initialize CBIT Component.
2012-10-26T00:01:26.636Z,1351209686.636 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2012-10-26T00:01:26.639Z,1351209686.639 [NavChartDb](INFO): Thread ID is 1091
2012-10-26T00:01:26.646Z,1351209686.646 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2012-10-26T00:01:26.653Z,1351209686.653 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2012-10-26T00:01:26.654Z,1351209686.654 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2012-10-26T00:01:26.654Z,1351209686.654 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2012-10-26T00:01:26.654Z,1351209686.654 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2012-10-26T00:01:26.663Z,1351209686.663 [Turbulence_NPS](INFO): Pause powering down
2012-10-26T00:01:26.668Z,1351209686.668 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2012-10-26T00:01:26.668Z,1351209686.668 [NavChart](DEBUG): Initialize NavChart Derivation.
2012-10-26T00:01:26.669Z,1351209686.669 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2012-10-26T00:01:26.669Z,1351209686.669 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2012-10-26T00:01:26.669Z,1351209686.669 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2012-10-26T00:01:26.671Z,1351209686.671 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2012-10-26T00:01:26.671Z,1351209686.671 [Navigation](DEBUG): Initializing Navigation.
2012-10-26T00:01:26.672Z,1351209686.672 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2012-10-26T00:01:26.673Z,1351209686.673 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2012-10-26T00:01:26.674Z,1351209686.674 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2012-10-26T00:01:26.675Z,1351209686.675 [LoopControl](DEBUG): Initialize LoopControlComponent.
2012-10-26T00:01:27.971Z,1351209687.971 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2012-10-26T00:01:27.999Z,1351209687.999 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2012-10-26T00:01:28.031Z,1351209688.031 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2012-10-26T00:01:28.041Z,1351209688.041 [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>


2012-10-26T00:01:28.042Z,1351209688.042 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2012-10-26T00:01:28.076Z,1351209688.076 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2012-10-26T00:01:28.078Z,1351209688.078 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2012-10-26T00:01:28.081Z,1351209688.081 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2012-10-26T00:01:28.092Z,1351209688.092 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2012-10-26T00:01:28.095Z,1351209688.095 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2012-10-26T00:01:28.102Z,1351209688.102 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2012-10-26T00:01:28.111Z,1351209688.111 [Default:D.SetSpeed](DEBUG): Construct.
2012-10-26T00:01:28.114Z,1351209688.114 [Default:E.GoToSurface](DEBUG): Construct GoToSurface.
2012-10-26T00:01:28.119Z,1351209688.119 [Default:F.Wait](DEBUG): Construct Wait.
2012-10-26T00:01:28.123Z,1351209688.122 [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>


2012-10-26T00:01:28.130Z,1351209688.130 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,NAL9602,Onboard,Radio_Freewave,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,logger,
2012-10-26T00:01:28.150Z,1351209688.150 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2012-10-26T00:01:28.851Z,1351209688.851 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2012-10-26T00:01:28.851Z,1351209688.851 [DVL_micro](INFO): Querying output modes
2012-10-26T00:01:28.851Z,1351209688.851 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2012-10-26T00:01:28.902Z,1351209688.902 [DVL_micro](DEBUG): cmdResponse: 01 03 16
2012-10-26T00:01:28.903Z,1351209688.903 [DVL_micro](INFO): NQ1 output enabled
2012-10-26T00:01:28.903Z,1351209688.903 [DVL_micro](INFO): RSSI output enabled
2012-10-26T00:01:28.903Z,1351209688.903 [DVL_micro](INFO): ADCP output enabled
2012-10-26T00:01:28.903Z,1351209688.903 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2012-10-26T00:01:28.911Z,1351209688.911 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 
2012-10-26T00:01:28.916Z,1351209688.916 [DVL_micro](INFO): pause:Powering down
2012-10-26T00:01:29.251Z,1351209689.251 [Radio_Freewave](INFO): Powering up
2012-10-26T00:01:29.355Z,1351209689.355 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2012-10-26T00:01:29.359Z,1351209689.359 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2012-10-26T00:01:29.365Z,1351209689.365 [ElevatorServo](DEBUG): Initializing EZServoServo.
2012-10-26T00:01:29.366Z,1351209689.366 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2012-10-26T00:01:29.372Z,1351209689.372 [MassServo](DEBUG): Initializing EZServoServo.
2012-10-26T00:01:29.375Z,1351209689.375 [MassServo](DEBUG): Initializing MassServo.
2012-10-26T00:01:29.380Z,1351209689.380 [RudderServo](DEBUG): Initializing EZServoServo.
2012-10-26T00:01:29.381Z,1351209689.381 [RudderServo](DEBUG): Initializing RudderServo.
2012-10-26T00:01:29.387Z,1351209689.387 [ThrusterServo](DEBUG): Initializing EZServoServo.
2012-10-26T00:01:29.391Z,1351209689.391 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2012-10-26T00:01:31.373Z,1351209691.373 [NAL9602](INFO): Powering up NAL9602
2012-10-26T00:01:39.695Z,1351209699.695 [CommandLine](IMPORTANT): got command failComponent
2012-10-26T00:01:39.695Z,1351209699.695 [CommandLine](IMPORTANT): Failed components:
2012-10-26T00:01:39.695Z,1351209699.695 [CommandLine](IMPORTANT): No failed Components.
2012-10-26T00:01:42.700Z,1351209702.700 [SBIT](IMPORTANT): Beginning Startup BIT
2012-10-26T00:01:42.703Z,1351209702.703 [CBIT](IMPORTANT): Beginning GF scan
2012-10-26T00:01:42.927Z,1351209702.927 [NAL9602](INFO): NAL9602 initialized
2012-10-26T00:01:47.447Z,1351209707.447 [CommandLine](IMPORTANT): got command get platform_battery_voltage
2012-10-26T00:01:47.447Z,1351209707.447 [CommandLine](IMPORTANT): platform_battery_voltage 16.397186 volt
2012-10-26T00:01:57.419Z,1351209717.419 [CommandLine](IMPORTANT): got command quit
2012-10-26T00:01:58.474Z,1351209718.474 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2012-10-26T00:01:58.475Z,1351209718.474 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2012-10-26T00:02:00.248Z,1351209720.248 [NAL9602](IMPORTANT): GPS fix at: 1351209663.00
2012-10-26T00:02:01.094Z,1351209721.094 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2012-10-26T00:02:01.291Z,1351209721.291 [WetLabsBB2FL](INFO): Powering down
2012-10-26T00:02:01.294Z,1351209721.294 [ComponentRegistry](INFO): Shutting down Turbulence_NPS ThreadHandler
2012-10-26T00:02:01.679Z,1351209721.679 [Turbulence_NPS](INFO): Uninitialize Powering down
2012-10-26T00:02:01.694Z,1351209721.694 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2012-10-26T00:02:02.075Z,1351209722.075 [CTD_NeilBrown](INFO): Powering down
2012-10-26T00:02:02.078Z,1351209722.078 [ComponentRegistry](INFO): Shutting down DVL_micro ThreadHandler
2012-10-26T00:02:02.119Z,1351209722.119 [DVL_micro](INFO): uninitialize:Powering down
2012-10-26T00:02:02.140Z,1351209722.139 [ComponentRegistry](INFO): Shutting down AsyncPiEstimator ThreadHandler
2012-10-26T00:02:02.415Z,1351209722.415 [AsyncPiEstimator](DEBUG): Uninitialize AsyncPiEstimator.
2012-10-26T00:02:02.419Z,1351209722.419 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2012-10-26T00:02:02.421Z,1351209722.421 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2012-10-26T00:02:02.463Z,1351209722.463 [controlThread](DEBUG): Uninitializing ControlThread
2012-10-26T00:02:02.463Z,1351209722.463 [AHRS_sp3003D](INFO): Powering down
2012-10-26T00:02:02.552Z,1351209722.552 [NAL9602](INFO): Powering down
2012-10-26T00:02:02.553Z,1351209722.553 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2012-10-26T00:02:02.554Z,1351209722.554 [NavChart](DEBUG): Uninitialize NavChart Derivation.
2012-10-26T00:02:02.559Z,1351209722.559 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2012-10-26T00:02:02.559Z,1351209722.559 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2012-10-26T00:02:02.560Z,1351209722.560 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2012-10-26T00:02:02.560Z,1351209722.560 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2012-10-26T00:02:02.560Z,1351209722.560 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2012-10-26T00:02:02.561Z,1351209722.560 [BuoyancyServo](INFO): Powering down
2012-10-26T00:02:02.567Z,1351209722.566 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2012-10-26T00:02:02.567Z,1351209722.567 [ElevatorServo](INFO): Powering down
2012-10-26T00:02:02.567Z,1351209722.568 [MassServo](DEBUG): Uninitialize Mass Servo.
2012-10-26T00:02:02.568Z,1351209722.568 [MassServo](INFO): Powering down
2012-10-26T00:02:02.568Z,1351209722.568 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2012-10-26T00:02:02.568Z,1351209722.568 [RudderServo](INFO): Powering down
2012-10-26T00:02:02.569Z,1351209722.569 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2012-10-26T00:02:02.569Z,1351209722.569 [ThrusterServo](INFO): Powering down
2012-10-26T00:02:02.570Z,1351209722.570 [SBIT](DEBUG): Uninitialize SBIT Component.
2012-10-26T00:02:02.571Z,1351209722.570 [IBIT](DEBUG): Uninitialize IBIT Component.
2012-10-26T00:02:02.571Z,1351209722.571 [CBIT](DEBUG): Uninitialize CBIT Component.