2012-11-20T20:46:27.961Z,1353444387.961 [Supervisor](DEBUG): Initializing supervisor.
2012-11-20T20:46:27.963Z,1353444387.963 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0
2012-11-20T20:46:27.964Z,1353444387.964 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2012-11-20T20:46:27.965Z,1353444387.965 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0
2012-11-20T20:46:27.969Z,1353444387.969 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2012-11-20T20:46:27.980Z,1353444387.980 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2012-11-20T20:46:27.981Z,1353444387.981 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0
2012-11-20T20:46:27.982Z,1353444387.982 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2012-11-20T20:46:27.983Z,1353444387.983 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0
2012-11-20T20:46:27.983Z,1353444387.983 [Supervisor](INFO): Looking for Config files in directory: Config/
2012-11-20T20:46:27.984Z,1353444387.984 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2012-11-20T20:46:28.281Z,1353444388.281 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2012-11-20T20:46:28.282Z,1353444388.282 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2012-11-20T20:46:28.477Z,1353444388.477 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2012-11-20T20:46:28.478Z,1353444388.478 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2012-11-20T20:46:28.564Z,1353444388.564 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2012-11-20T20:46:28.564Z,1353444388.564 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2012-11-20T20:46:28.771Z,1353444388.771 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2012-11-20T20:46:28.772Z,1353444388.772 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2012-11-20T20:46:28.910Z,1353444388.910 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2012-11-20T20:46:28.911Z,1353444388.911 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2012-11-20T20:46:29.155Z,1353444389.155 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2012-11-20T20:46:29.155Z,1353444389.155 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2012-11-20T20:46:29.331Z,1353444389.331 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2012-11-20T20:46:29.332Z,1353444389.332 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2012-11-20T20:46:29.603Z,1353444389.603 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2012-11-20T20:46:29.604Z,1353444389.604 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2012-11-20T20:46:29.705Z,1353444389.705 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2012-11-20T20:46:29.706Z,1353444389.706 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2012-11-20T20:46:30.130Z,1353444390.130 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2012-11-20T20:46:30.130Z,1353444390.130 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2012-11-20T20:46:30.247Z,1353444390.247 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2012-11-20T20:46:30.248Z,1353444390.248 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2012-11-20T20:46:30.334Z,1353444390.334 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2012-11-20T20:46:30.335Z,1353444390.335 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2012-11-20T20:46:30.444Z,1353444390.444 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2012-11-20T20:46:30.579Z,1353444390.579 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2012-11-20T20:46:30.666Z,1353444390.667 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2012-11-20T20:46:30.771Z,1353444390.771 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2012-11-20T20:46:30.874Z,1353444390.874 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2012-11-20T20:46:30.997Z,1353444390.997 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2012-11-20T20:46:31.092Z,1353444391.092 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2012-11-20T20:46:31.179Z,1353444391.179 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2012-11-20T20:46:31.212Z,1353444391.212 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2012-11-20T20:46:31.373Z,1353444391.373 [InternalSim] Loaded
2012-11-20T20:46:31.373Z,1353444391.373 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2012-11-20T20:46:31.374Z,1353444391.374 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2012-11-20T20:46:31.375Z,1353444391.375 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2012-11-20T20:46:31.437Z,1353444391.437 [SBIT](DEBUG): Construct Startup Built In Test.
2012-11-20T20:46:31.466Z,1353444391.466 [SBIT] Loaded
2012-11-20T20:46:31.467Z,1353444391.467 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2012-11-20T20:46:31.468Z,1353444391.467 [IBIT](DEBUG): Construct Initiated Built In Test.
2012-11-20T20:46:31.496Z,1353444391.497 [IBIT] Loaded
2012-11-20T20:46:31.497Z,1353444391.497 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2012-11-20T20:46:31.500Z,1353444391.500 [CBIT](DEBUG): Construct CBIT Built In Test.
2012-11-20T20:46:31.624Z,1353444391.624 [CBIT] Loaded
2012-11-20T20:46:31.624Z,1353444391.624 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2012-11-20T20:46:31.625Z,1353444391.625 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2012-11-20T20:46:31.625Z,1353444391.625 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2012-11-20T20:46:31.777Z,1353444391.777 [BuoyancyServo] Loaded
2012-11-20T20:46:31.778Z,1353444391.778 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2012-11-20T20:46:31.790Z,1353444391.790 [ElevatorServo] Loaded
2012-11-20T20:46:31.790Z,1353444391.790 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2012-11-20T20:46:31.802Z,1353444391.802 [MassServo] Loaded
2012-11-20T20:46:31.803Z,1353444391.803 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2012-11-20T20:46:31.815Z,1353444391.815 [RudderServo] Loaded
2012-11-20T20:46:31.815Z,1353444391.815 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2012-11-20T20:46:31.828Z,1353444391.828 [ThrusterServo] Loaded
2012-11-20T20:46:31.828Z,1353444391.828 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2012-11-20T20:46:31.828Z,1353444391.828 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2012-11-20T20:46:31.829Z,1353444391.829 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2012-11-20T20:46:31.846Z,1353444391.846 [DepthRateCalculator] Loaded
2012-11-20T20:46:31.846Z,1353444391.846 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2012-11-20T20:46:36.233Z,1353444396.233 [HFRadarModelCalc] Loaded
2012-11-20T20:46:36.233Z,1353444396.233 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2012-11-20T20:46:36.250Z,1353444396.250 [NavChart] Loaded
2012-11-20T20:46:36.250Z,1353444396.250 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2012-11-20T20:46:36.256Z,1353444396.256 [PitchRateCalculator] Loaded
2012-11-20T20:46:36.256Z,1353444396.256 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2012-11-20T20:46:36.263Z,1353444396.263 [SpeedCalculator] Loaded
2012-11-20T20:46:36.263Z,1353444396.263 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2012-11-20T20:46:36.278Z,1353444396.278 [TempGradientCalculator] Loaded
2012-11-20T20:46:36.279Z,1353444396.279 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2012-11-20T20:46:36.285Z,1353444396.284 [YawRateCalculator] Loaded
2012-11-20T20:46:36.285Z,1353444396.285 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2012-11-20T20:46:36.327Z,1353444396.327 [Navigation] Loaded
2012-11-20T20:46:36.327Z,1353444396.327 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread.
2012-11-20T20:46:36.327Z,1353444396.327 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2012-11-20T20:46:36.328Z,1353444396.328 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2012-11-20T20:46:36.568Z,1353444396.568 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2012-11-20T20:46:36.569Z,1353444396.569 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2012-11-20T20:46:36.593Z,1353444396.593 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2012-11-20T20:46:36.594Z,1353444396.593 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2012-11-20T20:46:36.637Z,1353444396.637 [VerticalControl](DEBUG): Construct VerticalControl.
2012-11-20T20:46:36.733Z,1353444396.733 [VerticalControl] Loaded
2012-11-20T20:46:36.733Z,1353444396.733 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2012-11-20T20:46:36.734Z,1353444396.734 [HorizontalControl](DEBUG): Construct HorizontalControl.
2012-11-20T20:46:36.793Z,1353444396.793 [HorizontalControl] Loaded
2012-11-20T20:46:36.793Z,1353444396.793 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2012-11-20T20:46:36.794Z,1353444396.794 [SpeedControl](DEBUG): Construct SpeedControl.
2012-11-20T20:46:36.796Z,1353444396.796 [SpeedControl] Loaded
2012-11-20T20:46:36.796Z,1353444396.796 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2012-11-20T20:46:36.797Z,1353444396.797 [LoopControl](DEBUG): Construct LoopControl.
2012-11-20T20:46:36.798Z,1353444396.798 [LoopControl] Loaded
2012-11-20T20:46:36.798Z,1353444396.798 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2012-11-20T20:46:36.799Z,1353444396.799 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2012-11-20T20:46:36.799Z,1353444396.799 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2012-11-20T20:46:36.804Z,1353444396.804 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator.
2012-11-20T20:46:36.809Z,1353444396.809 [AsyncPiEstimator] Loaded
2012-11-20T20:46:36.810Z,1353444396.810 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread.
2012-11-20T20:46:36.811Z,1353444396.811 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406A14E0
2012-11-20T20:46:36.812Z,1353444396.812 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2012-11-20T20:46:36.812Z,1353444396.812 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2012-11-20T20:46:36.941Z,1353444396.941 [AHRS_sp3003D] Loaded
2012-11-20T20:46:36.941Z,1353444396.941 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2012-11-20T20:46:37.211Z,1353444397.211 [Batt_Ocean_Server] Loaded
2012-11-20T20:46:37.212Z,1353444397.211 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2012-11-20T20:46:37.225Z,1353444397.225 [Depth_Keller] Loaded
2012-11-20T20:46:37.225Z,1353444397.225 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2012-11-20T20:46:37.231Z,1353444397.231 [DropWeight] Loaded
2012-11-20T20:46:37.231Z,1353444397.231 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2012-11-20T20:46:37.398Z,1353444397.398 [DVL_micro] Loaded
2012-11-20T20:46:37.399Z,1353444397.399 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread.
2012-11-20T20:46:37.400Z,1353444397.400 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 407234E0
2012-11-20T20:46:37.485Z,1353444397.485 [NAL9602] Loaded
2012-11-20T20:46:37.485Z,1353444397.485 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2012-11-20T20:46:37.539Z,1353444397.539 [Onboard] Loaded
2012-11-20T20:46:37.539Z,1353444397.539 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2012-11-20T20:46:37.546Z,1353444397.546 [Radio_Freewave] Loaded
2012-11-20T20:46:37.547Z,1353444397.546 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread.
2012-11-20T20:46:37.547Z,1353444397.547 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2012-11-20T20:46:37.548Z,1353444397.548 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2012-11-20T20:46:37.624Z,1353444397.624 [CTD_NeilBrown] Loaded
2012-11-20T20:46:37.625Z,1353444397.625 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2012-11-20T20:46:37.626Z,1353444397.626 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4077C4E0
2012-11-20T20:46:37.643Z,1353444397.643 [PAR_Licor] Loaded
2012-11-20T20:46:37.643Z,1353444397.643 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2012-11-20T20:46:37.698Z,1353444397.698 [Turbulence_NPS] Loaded
2012-11-20T20:46:37.699Z,1353444397.699 [ComponentRegistry](DEBUG): Component "Turbulence_NPS" handled in its own thread.
2012-11-20T20:46:37.700Z,1353444397.700 [Turbulence_NPS ThreadHandler](DEBUG): Created PCaller Thread at 407AC4E0
2012-11-20T20:46:37.731Z,1353444397.731 [WetLabsBB2FL] Loaded
2012-11-20T20:46:37.731Z,1353444397.731 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2012-11-20T20:46:37.733Z,1353444397.733 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407DC4E0
2012-11-20T20:46:37.733Z,1353444397.733 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2012-11-20T20:46:37.736Z,1353444397.736 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2012-11-20T20:46:37.737Z,1353444397.737 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2012-11-20T20:46:37.743Z,1353444397.743 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2012-11-20T20:46:37.745Z,1353444397.745 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 4080C4E0
2012-11-20T20:46:37.749Z,1353444397.749 [Supervisor](DEBUG): Running supervisor.
2012-11-20T20:46:37.750Z,1353444397.750 [CommandLine](INFO): Thread ID is 1398
2012-11-20T20:46:37.753Z,1353444397.753 [controlThread](INFO): Thread ID is 1397
2012-11-20T20:46:37.753Z,1353444397.753 [controlThread](DEBUG): Initializing ControlThread
2012-11-20T20:46:37.753Z,1353444397.753 [CycleStarter](INFO): Thread ID is 1396
2012-11-20T20:46:37.754Z,1353444397.754 [InternalSim](DEBUG):  InternalSim initializing...
2012-11-20T20:46:37.785Z,1353444397.785 [logger](INFO): Thread ID is 1399
2012-11-20T20:46:37.814Z,1353444397.815 [SBIT](INFO): Initialize SBIT Component.
2012-11-20T20:46:37.815Z,1353444397.815 [SBIT](IMPORTANT): Tethys CM Info:
$Rev: 10057
2012-11-20T20:46:37.816Z,1353444397.816 [IBIT](INFO): Initialize IBIT Component.
2012-11-20T20:46:37.816Z,1353444397.816 [CBIT](DEBUG): Initialize CBIT Component.
2012-11-20T20:46:37.817Z,1353444397.817 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2012-11-20T20:46:37.829Z,1353444397.829 [AsyncPiEstimator](INFO): Thread ID is 1460
2012-11-20T20:46:37.830Z,1353444397.829 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator.
2012-11-20T20:46:37.842Z,1353444397.842 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2012-11-20T20:46:37.842Z,1353444397.842 [NavChart](DEBUG): Initialize NavChart Derivation.
2012-11-20T20:46:37.843Z,1353444397.843 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2012-11-20T20:46:37.843Z,1353444397.843 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2012-11-20T20:46:37.843Z,1353444397.843 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2012-11-20T20:46:37.845Z,1353444397.845 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2012-11-20T20:46:37.845Z,1353444397.845 [Navigation](DEBUG): Initializing Navigation.
2012-11-20T20:46:37.846Z,1353444397.846 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2012-11-20T20:46:37.847Z,1353444397.847 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2012-11-20T20:46:37.848Z,1353444397.848 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2012-11-20T20:46:37.849Z,1353444397.849 [LoopControl](DEBUG): Initialize LoopControlComponent.
2012-11-20T20:46:37.853Z,1353444397.853 [DVL_micro](INFO): Thread ID is 1461
2012-11-20T20:46:37.862Z,1353444397.862 [DVL_micro](INFO): Initializing
2012-11-20T20:46:37.862Z,1353444397.862 [DVL_micro](INFO): start:Powering up
2012-11-20T20:46:37.863Z,1353444397.863 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2012-11-20T20:46:37.863Z,1353444397.863 [DVL_micro](INFO): Cycling power to configure device.
2012-11-20T20:46:37.878Z,1353444397.878 [CTD_NeilBrown](INFO): Thread ID is 1462
2012-11-20T20:46:37.878Z,1353444397.878 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2012-11-20T20:46:37.881Z,1353444397.881 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2012-11-20T20:46:37.901Z,1353444397.901 [Turbulence_NPS](INFO): Thread ID is 1463
2012-11-20T20:46:37.902Z,1353444397.902 [Turbulence_NPS](DEBUG): Initializing Turbulence_NPS.
2012-11-20T20:46:37.902Z,1353444397.902 [Turbulence_NPS](INFO): Opening uart, block timeout 10ths=1
2012-11-20T20:46:37.922Z,1353444397.922 [WetLabsBB2FL](INFO): Thread ID is 1464
2012-11-20T20:46:37.922Z,1353444397.922 [WetLabsBB2FL](INFO): Powering down
2012-11-20T20:46:37.947Z,1353444397.947 [NavChartDb](INFO): Thread ID is 1465
2012-11-20T20:46:37.950Z,1353444397.950 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2012-11-20T20:46:37.950Z,1353444397.950 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2012-11-20T20:46:37.951Z,1353444397.951 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2012-11-20T20:46:37.951Z,1353444397.951 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2012-11-20T20:46:37.951Z,1353444397.951 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2012-11-20T20:46:37.981Z,1353444397.981 [Turbulence_NPS](INFO): Pause powering down
2012-11-20T20:46:39.742Z,1353444399.742 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2012-11-20T20:46:39.776Z,1353444399.776 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2012-11-20T20:46:39.818Z,1353444399.819 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2012-11-20T20:46:39.864Z,1353444399.864 [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-11-20T20:46:39.865Z,1353444399.865 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2012-11-20T20:46:39.925Z,1353444399.925 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2012-11-20T20:46:39.925Z,1353444399.925 [DVL_micro](INFO): Querying output modes
2012-11-20T20:46:39.926Z,1353444399.926 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2012-11-20T20:46:39.937Z,1353444399.937 [DVL_micro](DEBUG): cmdResponse: 01
2012-11-20T20:46:39.937Z,1353444399.937 [DVL_micro](INFO): NQ1 output enabled
2012-11-20T20:46:39.937Z,1353444399.937 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2012-11-20T20:46:39.947Z,1353444399.947 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2012-11-20T20:46:39.949Z,1353444399.949 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 
2012-11-20T20:46:39.954Z,1353444399.954 [DVL_micro](INFO): pause:Powering down
2012-11-20T20:46:39.961Z,1353444399.961 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2012-11-20T20:46:39.964Z,1353444399.964 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2012-11-20T20:46:39.972Z,1353444399.972 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2012-11-20T20:46:39.987Z,1353444399.987 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2012-11-20T20:46:40.025Z,1353444400.025 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2012-11-20T20:46:40.050Z,1353444400.050 [Default:D.SetSpeed](DEBUG): Construct.
2012-11-20T20:46:40.065Z,1353444400.065 [Default:E.GoToSurface](DEBUG): Construct GoToSurface.
2012-11-20T20:46:40.070Z,1353444400.070 [Default:F.Wait](DEBUG): Construct Wait.
2012-11-20T20:46:40.074Z,1353444400.074 [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-11-20T20:46:40.078Z,1353444400.078 [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,
2012-11-20T20:46:40.136Z,1353444400.136 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2012-11-20T20:46:40.426Z,1353444400.426 [Radio_Freewave](INFO): Powering up
2012-11-20T20:46:40.744Z,1353444400.744 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2012-11-20T20:46:40.761Z,1353444400.761 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2012-11-20T20:46:40.768Z,1353444400.768 [ElevatorServo](DEBUG): Initializing EZServoServo.
2012-11-20T20:46:40.773Z,1353444400.773 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2012-11-20T20:46:40.779Z,1353444400.779 [MassServo](DEBUG): Initializing EZServoServo.
2012-11-20T20:46:40.785Z,1353444400.785 [MassServo](DEBUG): Initializing MassServo.
2012-11-20T20:46:40.806Z,1353444400.806 [RudderServo](DEBUG): Initializing EZServoServo.
2012-11-20T20:46:40.813Z,1353444400.813 [RudderServo](DEBUG): Initializing RudderServo.
2012-11-20T20:46:40.818Z,1353444400.819 [ThrusterServo](DEBUG): Initializing EZServoServo.
2012-11-20T20:46:40.825Z,1353444400.825 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2012-11-20T20:46:42.841Z,1353444402.841 [NAL9602](INFO): Powering up NAL9602
2012-11-20T20:46:44.053Z,1353444404.053 [CommandLine](IMPORTANT): got command maintain control SpeedControl.propOmegaAction 300.000000 revolution_per_minute
2012-11-20T20:46:44.065Z,1353444404.065 [ComponentRegistry](DEBUG): SyncComponent "Maintain_SpeedControl.propOmegaAction" handled in the control thread.
2012-11-20T20:46:44.296Z,1353444404.296 [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,Maintain_SpeedControl.propOmegaAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,
2012-11-20T20:46:53.170Z,1353444413.170 [SBIT](IMPORTANT): Beginning Startup BIT
2012-11-20T20:46:53.172Z,1353444413.172 [CBIT](IMPORTANT): Beginning GF scan
2012-11-20T20:46:53.513Z,1353444413.513 [NAL9602](INFO): NAL9602 initialized
2012-11-20T20:46:54.861Z,1353444414.861 [ThrusterServo](FAULT): Overload Error
2012-11-20T20:46:54.861Z,1353444414.861 [ThrusterServo] Hardware Fault, FailCount= 1
2012-11-20T20:46:54.861Z,1353444414.861 [ThrusterServo](ERROR): Hardware Fault
2012-11-20T20:46:54.864Z,1353444414.864 [CBIT](ERROR): Hardware Fault in component: ThrusterServo
2012-11-20T20:46:55.309Z,1353444415.309 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2012-11-20T20:46:55.310Z,1353444415.309 [ThrusterServo](INFO): Powering down
2012-11-20T20:46:55.313Z,1353444415.313 [CBIT](INFO): Clearing failed state for component ThrusterServo
2012-11-20T20:46:55.313Z,1353444415.313 [ThrusterServo] No Fault, FailCount= 1
2012-11-20T20:46:56.086Z,1353444416.086 [ThrusterServo](DEBUG): Initializing EZServoServo.
2012-11-20T20:46:56.206Z,1353444416.205 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2012-11-20T20:47:06.329Z,1353444426.329 [ThrusterServo](FAULT): Overload Error
2012-11-20T20:47:06.329Z,1353444426.329 [ThrusterServo] Hardware Fault, FailCount= 1
2012-11-20T20:47:06.329Z,1353444426.329 [ThrusterServo](ERROR): Hardware Fault
2012-11-20T20:47:06.333Z,1353444426.333 [CBIT](ERROR): Hardware Fault in component: ThrusterServo
2012-11-20T20:47:06.687Z,1353444426.687 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2012-11-20T20:47:06.687Z,1353444426.687 [ThrusterServo](INFO): Powering down
2012-11-20T20:47:06.709Z,1353444426.709 [CBIT](INFO): Clearing failed state for component ThrusterServo
2012-11-20T20:47:06.709Z,1353444426.709 [ThrusterServo] No Fault, FailCount= 1
2012-11-20T20:47:07.474Z,1353444427.474 [ThrusterServo](DEBUG): Initializing EZServoServo.
2012-11-20T20:47:07.594Z,1353444427.593 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2012-11-20T20:47:19.835Z,1353444439.835 [CBIT](IMPORTANT): No ground fault detected
2012-11-20T20:47:24.517Z,1353444444.517 [CommandLine](IMPORTANT): got command maintain clear
2012-11-20T20:47:24.612Z,1353444444.612 [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,
2012-11-20T20:47:46.803Z,1353444466.803 [SBIT](IMPORTANT): SBIT PASSED
2012-11-20T20:47:47.187Z,1353444467.187 [MissionManager](IMPORTANT): Started mission Startup
2012-11-20T20:47:47.187Z,1353444467.187 [Startup] Running Loop=1
2012-11-20T20:47:47.187Z,1353444467.187 [Startup](INFO): Aggregate::initialize Startup
2012-11-20T20:47:47.187Z,1353444467.187 [Startup:A.GoToSurface] Running Loop=1
2012-11-20T20:47:47.187Z,1353444467.187 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-11-20T20:47:47.222Z,1353444467.222 [Startup:StartupSatComms] Running Loop=1
2012-11-20T20:47:47.222Z,1353444467.222 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2012-11-20T20:47:47.222Z,1353444467.222 [Startup:StartupSatComms:A] Running Loop=1
2012-11-20T20:47:47.588Z,1353444467.588 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2012-11-20T20:48:47.580Z,1353444527.580 [Startup:StartupSatComms:A](INFO): Timed out from 2012-11-20T20:47:47.2Z
2012-11-20T20:48:47.580Z,1353444527.580 [Startup:StartupSatComms:A:A_Timeout] Running Loop=1
2012-11-20T20:48:47.580Z,1353444527.580 [Startup:StartupSatComms:A:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:A:A_Timeout
2012-11-20T20:48:47.581Z,1353444527.581 [Startup:StartupSatComms:A:A_Timeout](INFO): Completed Startup:StartupSatComms:A:A_Timeout
2012-11-20T20:48:47.581Z,1353444527.581 [Startup:StartupSatComms:A] Stopped
2012-11-20T20:48:47.581Z,1353444527.581 [Startup:StartupSatComms:B] Running Loop=1
2012-11-20T20:48:47.976Z,1353444527.976 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2012-11-20T20:48:49.865Z,1353444529.865 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2012-11-20T20:48:54.222Z,1353444534.223 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2012-11-20T20:48:58.106Z,1353444538.106 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2012-11-20T20:49:02.467Z,1353444542.467 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2012-11-20T20:49:07.227Z,1353444547.227 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2012-11-20T20:49:11.474Z,1353444551.474 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2012-11-20T20:49:16.179Z,1353444556.179 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2012-11-20T20:49:20.535Z,1353444560.535 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2012-11-20T20:49:25.249Z,1353444565.249 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2012-11-20T20:49:29.614Z,1353444569.614 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2012-11-20T20:49:33.922Z,1353444573.922 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2012-11-20T20:49:38.294Z,1353444578.294 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2012-11-20T20:49:43.103Z,1353444583.103 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2012-11-20T20:49:47.330Z,1353444587.330 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2012-11-20T20:49:47.780Z,1353444587.780 [Startup:StartupSatComms:B](INFO): Timed out from 2012-11-20T20:48:47.6Z
2012-11-20T20:49:47.780Z,1353444587.780 [Startup:StartupSatComms:B:A_Timeout] Running Loop=1
2012-11-20T20:49:47.780Z,1353444587.780 [Startup:StartupSatComms:B:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:B:A_Timeout
2012-11-20T20:49:47.781Z,1353444587.781 [Startup:StartupSatComms:B:A_Timeout](INFO): Completed Startup:StartupSatComms:B:A_Timeout
2012-11-20T20:49:47.781Z,1353444587.781 [Startup:StartupSatComms:B] Stopped
2012-11-20T20:49:47.781Z,1353444587.781 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2012-11-20T20:49:47.781Z,1353444587.781 [Startup:StartupSatComms] Stopped
2012-11-20T20:49:47.781Z,1353444587.781 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2012-11-20T20:49:47.782Z,1353444587.782 [Startup](INFO): Completed Startup
2012-11-20T20:49:47.782Z,1353444587.782 [Startup] Stopped
2012-11-20T20:49:47.782Z,1353444587.782 [Startup](INFO): Aggregate::uninitialize Startup
2012-11-20T20:49:47.782Z,1353444587.782 [Startup:A.GoToSurface] Stopped
2012-11-20T20:49:47.782Z,1353444587.782 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-11-20T20:49:48.142Z,1353444588.142 [MissionManager](IMPORTANT): Started mission Default
2012-11-20T20:49:48.142Z,1353444588.142 [Default] Running Loop=1
2012-11-20T20:49:48.142Z,1353444588.142 [Default](INFO): Aggregate::initialize Default
2012-11-20T20:49:48.142Z,1353444588.142 [Default:D.SetSpeed] Running Loop=1
2012-11-20T20:49:48.142Z,1353444588.142 [Default:D.SetSpeed](DEBUG): Initialize.
2012-11-20T20:49:48.142Z,1353444588.142 [Default:E.GoToSurface] Running Loop=1
2012-11-20T20:49:48.142Z,1353444588.142 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-11-20T20:49:48.143Z,1353444588.143 [Default:Iridium] Running Loop=1
2012-11-20T20:49:48.143Z,1353444588.143 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2012-11-20T20:49:48.143Z,1353444588.143 [Default:Iridium:A.SetSpeed] Running Loop=1
2012-11-20T20:49:48.143Z,1353444588.143 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2012-11-20T20:49:48.143Z,1353444588.143 [Default:Iridium:B.GoToSurface] Running Loop=1
2012-11-20T20:49:48.143Z,1353444588.143 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-11-20T20:49:48.144Z,1353444588.144 [Default:E.GoToSurface] Running Loop=1
2012-11-20T20:49:48.149Z,1353444588.149 [Default:D.SetSpeed] Running Loop=1
2012-11-20T20:49:48.154Z,1353444588.154 [Default:CallIridium] Running Loop=1
2012-11-20T20:49:48.154Z,1353444588.154 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2012-11-20T20:49:48.154Z,1353444588.154 [Default:CallIridium:A] Running Loop=1
2012-11-20T20:49:48.156Z,1353444588.156 [Default:CallIridium:A] Stopped
2012-11-20T20:49:48.156Z,1353444588.156 [Default:CallIridium:B] Running Loop=1
2012-11-20T20:49:48.156Z,1353444588.156 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2012-11-20T20:49:48.162Z,1353444588.162 [Default:Iridium:B.GoToSurface] Stopped
2012-11-20T20:49:48.162Z,1353444588.162 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-11-20T20:49:48.163Z,1353444588.163 [Default:Iridium:Read_Iridium] Running Loop=1
2012-11-20T20:49:48.163Z,1353444588.163 [Default:Iridium:A.SetSpeed] Running Loop=1
2012-11-20T20:49:48.170Z,1353444588.170 [Default:GPS] Running Loop=1
2012-11-20T20:49:48.170Z,1353444588.170 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2012-11-20T20:49:48.170Z,1353444588.170 [Default:GPS:A.SetSpeed] Running Loop=1
2012-11-20T20:49:48.170Z,1353444588.170 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2012-11-20T20:49:48.171Z,1353444588.171 [Default:GPS:B.GoToSurface] Running Loop=1
2012-11-20T20:49:48.171Z,1353444588.171 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-11-20T20:49:48.176Z,1353444588.176 [Default:GPS:B.GoToSurface] Stopped
2012-11-20T20:49:48.176Z,1353444588.176 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-11-20T20:49:48.176Z,1353444588.176 [Default:GPS:Read_GPS] Running Loop=1
2012-11-20T20:49:48.176Z,1353444588.176 [Default:GPS:A.SetSpeed] Running Loop=1
2012-11-20T20:49:48.557Z,1353444588.557 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2012-11-20T20:49:48.559Z,1353444588.559 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2012-11-20T20:49:52.058Z,1353444592.058 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2012-11-20T20:49:56.415Z,1353444596.415 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2012-11-20T20:50:01.092Z,1353444601.092 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2012-11-20T20:50:05.406Z,1353444605.406 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2012-11-20T20:50:09.241Z,1353444609.241 [CommandLine](IMPORTANT): got command quit
2012-11-20T20:50:09.771Z,1353444609.771 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2012-11-20T20:50:10.260Z,1353444610.260 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2012-11-20T20:50:10.261Z,1353444610.261 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2012-11-20T20:50:10.485Z,1353444610.485 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2012-11-20T20:50:10.565Z,1353444610.565 [WetLabsBB2FL](INFO): Powering down
2012-11-20T20:50:10.577Z,1353444610.577 [ComponentRegistry](INFO): Shutting down Turbulence_NPS ThreadHandler
2012-11-20T20:50:10.609Z,1353444610.609 [Turbulence_NPS](INFO): Uninitialize Powering down
2012-11-20T20:50:10.625Z,1353444610.625 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2012-11-20T20:50:10.797Z,1353444610.797 [CTD_NeilBrown](INFO): Powering down
2012-11-20T20:50:10.805Z,1353444610.805 [ComponentRegistry](INFO): Shutting down DVL_micro ThreadHandler
2012-11-20T20:50:10.961Z,1353444610.961 [DVL_micro](INFO): uninitialize:Powering down
2012-11-20T20:50:10.966Z,1353444610.966 [ComponentRegistry](INFO): Shutting down AsyncPiEstimator ThreadHandler
2012-11-20T20:50:11.165Z,1353444611.165 [AsyncPiEstimator](DEBUG): Uninitialize AsyncPiEstimator.
2012-11-20T20:50:11.177Z,1353444611.178 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2012-11-20T20:50:11.190Z,1353444611.190 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2012-11-20T20:50:11.198Z,1353444611.198 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2012-11-20T20:50:11.431Z,1353444611.431 [controlThread](DEBUG): Uninitializing ControlThread
2012-11-20T20:50:11.431Z,1353444611.431 [AHRS_sp3003D](INFO): Powering down
2012-11-20T20:50:11.518Z,1353444611.518 [NAL9602](INFO): Powering down
2012-11-20T20:50:11.520Z,1353444611.520 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2012-11-20T20:50:11.521Z,1353444611.521 [NavChart](DEBUG): Uninitialize NavChart Derivation.
2012-11-20T20:50:11.522Z,1353444611.522 [Default] Stopped
2012-11-20T20:50:11.522Z,1353444611.522 [Default](INFO): Aggregate::uninitialize Default
2012-11-20T20:50:11.522Z,1353444611.522 [Default:GPS] Stopped
2012-11-20T20:50:11.522Z,1353444611.522 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2012-11-20T20:50:11.522Z,1353444611.522 [Default:GPS:A.SetSpeed] Stopped
2012-11-20T20:50:11.522Z,1353444611.522 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2012-11-20T20:50:11.522Z,1353444611.522 [Default:GPS:Read_GPS] Stopped
2012-11-20T20:50:11.522Z,1353444611.522 [Default:Iridium] Stopped
2012-11-20T20:50:11.522Z,1353444611.522 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2012-11-20T20:50:11.522Z,1353444611.523 [Default:Iridium:A.SetSpeed] Stopped
2012-11-20T20:50:11.523Z,1353444611.523 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2012-11-20T20:50:11.523Z,1353444611.523 [Default:Iridium:Read_Iridium] Stopped
2012-11-20T20:50:11.523Z,1353444611.523 [Default:CallIridium] Stopped
2012-11-20T20:50:11.523Z,1353444611.523 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2012-11-20T20:50:11.523Z,1353444611.523 [Default:CallIridium:B] Stopped
2012-11-20T20:50:11.523Z,1353444611.523 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2012-11-20T20:50:11.523Z,1353444611.523 [Default:D.SetSpeed] Stopped
2012-11-20T20:50:11.523Z,1353444611.523 [Default:D.SetSpeed](DEBUG): Uninitialize.
2012-11-20T20:50:11.523Z,1353444611.523 [Default:E.GoToSurface] Stopped
2012-11-20T20:50:11.523Z,1353444611.523 [Default:E.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-11-20T20:50:11.527Z,1353444611.527 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2012-11-20T20:50:11.528Z,1353444611.528 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2012-11-20T20:50:11.528Z,1353444611.528 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2012-11-20T20:50:11.529Z,1353444611.529 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2012-11-20T20:50:11.529Z,1353444611.529 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2012-11-20T20:50:11.529Z,1353444611.529 [BuoyancyServo](INFO): Powering down
2012-11-20T20:50:11.541Z,1353444611.541 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2012-11-20T20:50:11.541Z,1353444611.541 [ElevatorServo](INFO): Powering down
2012-11-20T20:50:11.542Z,1353444611.542 [MassServo](DEBUG): Uninitialize Mass Servo.
2012-11-20T20:50:11.542Z,1353444611.542 [MassServo](INFO): Powering down
2012-11-20T20:50:11.543Z,1353444611.543 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2012-11-20T20:50:11.543Z,1353444611.543 [RudderServo](INFO): Powering down
2012-11-20T20:50:11.544Z,1353444611.544 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2012-11-20T20:50:11.544Z,1353444611.544 [ThrusterServo](INFO): Powering down
2012-11-20T20:50:11.545Z,1353444611.545 [SBIT](DEBUG): Uninitialize SBIT Component.
2012-11-20T20:50:11.545Z,1353444611.545 [IBIT](DEBUG): Uninitialize IBIT Component.
2012-11-20T20:50:11.545Z,1353444611.546 [CBIT](DEBUG): Uninitialize CBIT Component.