2013-10-30T18:59:20.986Z,1383159560.986 [Supervisor](DEBUG): Initializing supervisor.
2013-10-30T18:59:20.989Z,1383159560.989 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0
2013-10-30T18:59:20.990Z,1383159560.990 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2013-10-30T18:59:20.991Z,1383159560.991 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0
2013-10-30T18:59:21.009Z,1383159561.009 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2013-10-30T18:59:21.022Z,1383159561.022 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2013-10-30T18:59:21.023Z,1383159561.023 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0
2013-10-30T18:59:21.024Z,1383159561.024 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2013-10-30T18:59:21.025Z,1383159561.025 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0
2013-10-30T18:59:21.026Z,1383159561.026 [Supervisor](INFO): Looking for Config files in directory: Config/
2013-10-30T18:59:21.027Z,1383159561.027 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2013-10-30T18:59:21.484Z,1383159561.484 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2013-10-30T18:59:21.485Z,1383159561.485 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2013-10-30T18:59:21.686Z,1383159561.686 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2013-10-30T18:59:21.687Z,1383159561.687 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2013-10-30T18:59:21.775Z,1383159561.775 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2013-10-30T18:59:21.775Z,1383159561.775 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2013-10-30T18:59:21.893Z,1383159561.893 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2013-10-30T18:59:21.893Z,1383159561.893 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2013-10-30T18:59:22.041Z,1383159562.041 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2013-10-30T18:59:22.041Z,1383159562.041 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2013-10-30T18:59:22.294Z,1383159562.294 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2013-10-30T18:59:22.294Z,1383159562.294 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2013-10-30T18:59:22.462Z,1383159562.462 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2013-10-30T18:59:22.463Z,1383159562.463 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2013-10-30T18:59:22.742Z,1383159562.742 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2013-10-30T18:59:22.743Z,1383159562.743 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2013-10-30T18:59:22.844Z,1383159562.844 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2013-10-30T18:59:22.845Z,1383159562.845 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2013-10-30T18:59:23.276Z,1383159563.276 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2013-10-30T18:59:23.276Z,1383159563.276 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2013-10-30T18:59:23.389Z,1383159563.389 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2013-10-30T18:59:23.389Z,1383159563.389 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2013-10-30T18:59:23.476Z,1383159563.476 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2013-10-30T18:59:23.477Z,1383159563.477 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2013-10-30T18:59:23.577Z,1383159563.577 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2013-10-30T18:59:23.706Z,1383159563.706 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2013-10-30T18:59:23.801Z,1383159563.801 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2013-10-30T18:59:23.908Z,1383159563.908 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2013-10-30T18:59:24.005Z,1383159564.005 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2013-10-30T18:59:24.130Z,1383159564.130 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2013-10-30T18:59:24.249Z,1383159564.249 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2013-10-30T18:59:24.335Z,1383159564.335 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/LOGIN/
2013-10-30T18:59:24.335Z,1383159564.335 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2013-10-30T18:59:24.337Z,1383159564.337 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2013-10-30T18:59:24.516Z,1383159564.516 [InternalSim] Loaded
2013-10-30T18:59:24.516Z,1383159564.516 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2013-10-30T18:59:24.517Z,1383159564.517 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2013-10-30T18:59:24.518Z,1383159564.518 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2013-10-30T18:59:24.610Z,1383159564.610 [SBIT](DEBUG): Construct Startup Built In Test.
2013-10-30T18:59:24.644Z,1383159564.644 [SBIT] Loaded
2013-10-30T18:59:24.645Z,1383159564.645 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2013-10-30T18:59:24.645Z,1383159564.645 [IBIT](DEBUG): Construct Initiated Built In Test.
2013-10-30T18:59:24.676Z,1383159564.676 [IBIT] Loaded
2013-10-30T18:59:24.676Z,1383159564.676 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2013-10-30T18:59:24.678Z,1383159564.678 [CBIT](DEBUG): Construct CBIT Built In Test.
2013-10-30T18:59:24.799Z,1383159564.799 [CBIT] Loaded
2013-10-30T18:59:24.799Z,1383159564.799 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2013-10-30T18:59:24.800Z,1383159564.800 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2013-10-30T18:59:24.800Z,1383159564.800 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2013-10-30T18:59:24.975Z,1383159564.975 [BuoyancyServo] Loaded
2013-10-30T18:59:24.975Z,1383159564.975 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2013-10-30T18:59:24.987Z,1383159564.987 [ElevatorServo] Loaded
2013-10-30T18:59:24.988Z,1383159564.988 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2013-10-30T18:59:24.999Z,1383159564.999 [MassServo] Loaded
2013-10-30T18:59:24.999Z,1383159564.999 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2013-10-30T18:59:25.011Z,1383159565.011 [RudderServo] Loaded
2013-10-30T18:59:25.012Z,1383159565.012 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2013-10-30T18:59:25.023Z,1383159565.023 [ThrusterServo] Loaded
2013-10-30T18:59:25.023Z,1383159565.023 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2013-10-30T18:59:25.024Z,1383159565.024 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2013-10-30T18:59:25.025Z,1383159565.025 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2013-10-30T18:59:25.062Z,1383159565.062 [DepthRateCalculator] Loaded
2013-10-30T18:59:25.063Z,1383159565.063 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2013-10-30T18:59:27.972Z,1383159567.972 [HFRadarModelCalc] Loaded
2013-10-30T18:59:27.972Z,1383159567.972 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2013-10-30T18:59:27.989Z,1383159567.989 [NavChart] Loaded
2013-10-30T18:59:27.989Z,1383159567.989 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2013-10-30T18:59:27.995Z,1383159567.995 [PitchRateCalculator] Loaded
2013-10-30T18:59:27.995Z,1383159567.995 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2013-10-30T18:59:28.006Z,1383159568.006 [SpeedCalculator] Loaded
2013-10-30T18:59:28.007Z,1383159568.007 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2013-10-30T18:59:28.023Z,1383159568.023 [TempGradientCalculator] Loaded
2013-10-30T18:59:28.024Z,1383159568.024 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2013-10-30T18:59:28.030Z,1383159568.030 [YawRateCalculator] Loaded
2013-10-30T18:59:28.030Z,1383159568.030 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2013-10-30T18:59:28.078Z,1383159568.078 [Navigation] Loaded
2013-10-30T18:59:28.079Z,1383159568.079 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread.
2013-10-30T18:59:28.079Z,1383159568.079 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2013-10-30T18:59:28.080Z,1383159568.080 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2013-10-30T18:59:28.344Z,1383159568.344 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2013-10-30T18:59:28.344Z,1383159568.344 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2013-10-30T18:59:28.371Z,1383159568.371 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2013-10-30T18:59:28.371Z,1383159568.371 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2013-10-30T18:59:28.424Z,1383159568.424 [VerticalControl](DEBUG): Construct VerticalControl.
2013-10-30T18:59:28.521Z,1383159568.521 [VerticalControl] Loaded
2013-10-30T18:59:28.521Z,1383159568.521 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2013-10-30T18:59:28.522Z,1383159568.522 [HorizontalControl](DEBUG): Construct HorizontalControl.
2013-10-30T18:59:28.581Z,1383159568.581 [HorizontalControl] Loaded
2013-10-30T18:59:28.581Z,1383159568.581 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2013-10-30T18:59:28.582Z,1383159568.582 [SpeedControl](DEBUG): Construct SpeedControl.
2013-10-30T18:59:28.584Z,1383159568.584 [SpeedControl] Loaded
2013-10-30T18:59:28.584Z,1383159568.584 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2013-10-30T18:59:28.585Z,1383159568.585 [LoopControl](DEBUG): Construct LoopControl.
2013-10-30T18:59:28.586Z,1383159568.586 [LoopControl] Loaded
2013-10-30T18:59:28.586Z,1383159568.586 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2013-10-30T18:59:28.586Z,1383159568.586 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2013-10-30T18:59:28.587Z,1383159568.587 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2013-10-30T18:59:28.593Z,1383159568.593 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator.
2013-10-30T18:59:28.598Z,1383159568.598 [AsyncPiEstimator] Loaded
2013-10-30T18:59:28.598Z,1383159568.598 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread.
2013-10-30T18:59:28.599Z,1383159568.599 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406474E0
2013-10-30T18:59:28.600Z,1383159568.600 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2013-10-30T18:59:28.601Z,1383159568.601 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2013-10-30T18:59:28.816Z,1383159568.816 [AHRS_sp3003D] Loaded
2013-10-30T18:59:28.816Z,1383159568.816 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2013-10-30T18:59:28.830Z,1383159568.830 [Depth_Keller] Loaded
2013-10-30T18:59:28.831Z,1383159568.831 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2013-10-30T18:59:29.027Z,1383159569.027 [DVL_micro] Loaded
2013-10-30T18:59:29.027Z,1383159569.027 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread.
2013-10-30T18:59:29.029Z,1383159569.029 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 406CE4E0
2013-10-30T18:59:29.121Z,1383159569.121 [NAL9602] Loaded
2013-10-30T18:59:29.122Z,1383159569.122 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2013-10-30T18:59:29.164Z,1383159569.164 [Onboard] Loaded
2013-10-30T18:59:29.165Z,1383159569.165 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2013-10-30T18:59:29.171Z,1383159569.171 [Radio_Freewave] Loaded
2013-10-30T18:59:29.172Z,1383159569.172 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread.
2013-10-30T18:59:29.323Z,1383159569.323 [DAT] Loaded
2013-10-30T18:59:29.323Z,1383159569.323 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2013-10-30T18:59:29.324Z,1383159569.324 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2013-10-30T18:59:29.325Z,1383159569.325 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2013-10-30T18:59:29.439Z,1383159569.439 [CTD_NeilBrown] Loaded
2013-10-30T18:59:29.440Z,1383159569.440 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2013-10-30T18:59:29.441Z,1383159569.441 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4072B4E0
2013-10-30T18:59:29.475Z,1383159569.475 [WetLabsBB2FL] Loaded
2013-10-30T18:59:29.475Z,1383159569.475 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2013-10-30T18:59:29.476Z,1383159569.476 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4075B4E0
2013-10-30T18:59:29.477Z,1383159569.477 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2013-10-30T18:59:29.479Z,1383159569.479 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2013-10-30T18:59:29.480Z,1383159569.480 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2013-10-30T18:59:29.488Z,1383159569.488 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2013-10-30T18:59:29.489Z,1383159569.489 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 4078B4E0
2013-10-30T18:59:29.493Z,1383159569.493 [Supervisor](DEBUG): Running supervisor.
2013-10-30T18:59:29.495Z,1383159569.495 [CommandLine](INFO): Thread ID is 2779
2013-10-30T18:59:29.497Z,1383159569.497 [controlThread](INFO): Thread ID is 2778
2013-10-30T18:59:29.497Z,1383159569.497 [controlThread](DEBUG): Initializing ControlThread
2013-10-30T18:59:29.498Z,1383159569.498 [CycleStarter](INFO): Thread ID is 2777
2013-10-30T18:59:29.498Z,1383159569.498 [InternalSim](DEBUG):  InternalSim initializing...
2013-10-30T18:59:29.534Z,1383159569.534 [logger](INFO): Thread ID is 2780
2013-10-30T18:59:29.556Z,1383159569.556 [AsyncPiEstimator](INFO): Thread ID is 2841
2013-10-30T18:59:29.556Z,1383159569.556 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator.
2013-10-30T18:59:29.652Z,1383159569.652 [DVL_micro](INFO): Thread ID is 2842
2013-10-30T18:59:29.840Z,1383159569.840 [CTD_NeilBrown](INFO): Thread ID is 2843
2013-10-30T18:59:29.841Z,1383159569.841 [WetLabsBB2FL](INFO): Thread ID is 2844
2013-10-30T18:59:29.842Z,1383159569.842 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2013-10-30T18:59:29.843Z,1383159569.843 [WetLabsBB2FL](INFO): Powering down
2013-10-30T18:59:29.865Z,1383159569.865 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2013-10-30T18:59:29.890Z,1383159569.890 [NavChartDb](INFO): Thread ID is 2845
2013-10-30T18:59:29.952Z,1383159569.952 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2013-10-30T18:59:29.953Z,1383159569.953 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2013-10-30T18:59:29.953Z,1383159569.953 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2013-10-30T18:59:29.953Z,1383159569.953 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2013-10-30T18:59:29.954Z,1383159569.954 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2013-10-30T18:59:29.954Z,1383159569.954 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2013-10-30T18:59:29.954Z,1383159569.954 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2013-10-30T18:59:29.954Z,1383159569.954 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2013-10-30T18:59:29.955Z,1383159569.955 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2013-10-30T18:59:29.965Z,1383159569.965 [DVL_micro](INFO): Initializing
2013-10-30T18:59:29.965Z,1383159569.965 [DVL_micro](INFO): start:Powering up
2013-10-30T18:59:29.966Z,1383159569.966 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-10-30T18:59:29.966Z,1383159569.966 [DVL_micro](INFO): Cycling power to configure device.
2013-10-30T18:59:29.970Z,1383159569.970 [SBIT](INFO): Initialize SBIT Component.
2013-10-30T18:59:29.971Z,1383159569.971 [SBIT](IMPORTANT): Tethys CM Info: 
 $Rev:10711
2013-10-30T18:59:29.971Z,1383159569.971 [SBIT](IMPORTANT): Kernel Release:2.6.27.8
2013-10-30T18:59:29.971Z,1383159569.971 [SBIT](IMPORTANT): Kernel Version:#634 PREEMPT Wed Feb 13 10:21:48 PST 2013
2013-10-30T18:59:29.980Z,1383159569.980 [IBIT](INFO): Initialize IBIT Component.
2013-10-30T18:59:29.981Z,1383159569.981 [CBIT](DEBUG): Initialize CBIT Component.
2013-10-30T18:59:29.982Z,1383159569.982 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2013-10-30T18:59:30.014Z,1383159570.014 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2013-10-30T18:59:30.015Z,1383159570.015 [NavChart](DEBUG): Initialize NavChart Derivation.
2013-10-30T18:59:30.015Z,1383159570.015 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2013-10-30T18:59:30.015Z,1383159570.015 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2013-10-30T18:59:30.016Z,1383159570.016 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2013-10-30T18:59:30.017Z,1383159570.017 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2013-10-30T18:59:30.017Z,1383159570.017 [Navigation](DEBUG): Initializing Navigation.
2013-10-30T18:59:30.017Z,1383159570.017 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2013-10-30T18:59:30.020Z,1383159570.020 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2013-10-30T18:59:30.025Z,1383159570.025 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2013-10-30T18:59:30.025Z,1383159570.025 [LoopControl](DEBUG): Initialize LoopControlComponent.
2013-10-30T18:59:30.045Z,1383159570.045 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2013-10-30T18:59:30.110Z,1383159570.110 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2013-10-30T18:59:30.143Z,1383159570.143 [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-10-30T18:59:30.144Z,1383159570.144 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2013-10-30T18:59:30.250Z,1383159570.250 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2013-10-30T18:59:30.253Z,1383159570.253 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2013-10-30T18:59:30.256Z,1383159570.256 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-10-30T18:59:30.282Z,1383159570.282 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2013-10-30T18:59:30.285Z,1383159570.285 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-10-30T18:59:30.316Z,1383159570.316 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2013-10-30T18:59:30.341Z,1383159570.341 [Default:D.SetSpeed](DEBUG): Construct.
2013-10-30T18:59:30.344Z,1383159570.344 [Default:E.GoToSurface](DEBUG): Construct GoToSurface.
2013-10-30T18:59:30.363Z,1383159570.363 [Default:F.Wait](DEBUG): Construct Wait.
2013-10-30T18:59:30.378Z,1383159570.378 [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-10-30T18:59:30.383Z,1383159570.383 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Depth_Keller,NAL9602,Onboard,Radio_Freewave,DAT,Depth_Keller,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,
2013-10-30T18:59:30.461Z,1383159570.461 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-10-30T18:59:30.476Z,1383159570.476 [Depth_Keller](ERROR): Pressure reading out of range: 915.671448 decibar
2013-10-30T18:59:30.574Z,1383159570.574 [Radio_Freewave](INFO): Powering up
2013-10-30T18:59:30.579Z,1383159570.579 [DAT](INFO): Powering up
2013-10-30T18:59:30.579Z,1383159570.579 [DAT](DEBUG): Initializing DAT.
2013-10-30T18:59:30.874Z,1383159570.874 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2013-10-30T18:59:30.882Z,1383159570.882 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2013-10-30T18:59:30.889Z,1383159570.889 [ElevatorServo](DEBUG): Initializing EZServoServo.
2013-10-30T18:59:30.914Z,1383159570.914 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2013-10-30T18:59:30.920Z,1383159570.920 [MassServo](DEBUG): Initializing EZServoServo.
2013-10-30T18:59:30.926Z,1383159570.926 [MassServo](DEBUG): Initializing MassServo.
2013-10-30T18:59:30.932Z,1383159570.932 [RudderServo](DEBUG): Initializing EZServoServo.
2013-10-30T18:59:30.938Z,1383159570.938 [RudderServo](DEBUG): Initializing RudderServo.
2013-10-30T18:59:30.948Z,1383159570.948 [ThrusterServo](DEBUG): Initializing EZServoServo.
2013-10-30T18:59:30.954Z,1383159570.954 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2013-10-30T18:59:31.154Z,1383159571.154 [AHRS_sp3003D](ERROR): readHeadingMagBin got 0x42360D0AA4
2013-10-30T18:59:31.154Z,1383159571.154 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2013-10-30T18:59:31.154Z,1383159571.154 [AHRS_sp3003D] Hardware Fault, FailCount= 1
2013-10-30T18:59:31.155Z,1383159571.155 [AHRS_sp3003D](ERROR): Hardware Fault
2013-10-30T18:59:31.365Z,1383159571.365 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2013-10-30T18:59:31.437Z,1383159571.437 [AHRS_sp3003D](INFO): Powering down
2013-10-30T18:59:32.056Z,1383159572.056 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-10-30T18:59:32.056Z,1383159572.056 [DVL_micro](INFO): Querying output modes
2013-10-30T18:59:32.057Z,1383159572.057 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-10-30T18:59:32.068Z,1383159572.068 [DVL_micro](DEBUG): cmdResponse: 01
2013-10-30T18:59:32.068Z,1383159572.068 [DVL_micro](INFO): NQ1 output enabled
2013-10-30T18:59:32.068Z,1383159572.068 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-10-30T18:59:32.080Z,1383159572.080 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 
2013-10-30T18:59:32.085Z,1383159572.085 [DVL_micro](INFO): pause:Powering down
2013-10-30T18:59:32.096Z,1383159572.096 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-10-30T18:59:32.096Z,1383159572.096 [DVL_micro](INFO): resume:Powering up
2013-10-30T18:59:32.096Z,1383159572.096 [DVL_micro](INFO): Cycling power to configure device.
2013-10-30T18:59:32.861Z,1383159572.861 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D
2013-10-30T18:59:32.861Z,1383159572.861 [AHRS_sp3003D] No Fault, FailCount= 1
2013-10-30T18:59:33.184Z,1383159573.184 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-10-30T18:59:34.099Z,1383159574.099 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-10-30T18:59:34.099Z,1383159574.099 [DVL_micro](INFO): Querying output modes
2013-10-30T18:59:34.100Z,1383159574.100 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-10-30T18:59:34.596Z,1383159574.596 [DVL_micro](DEBUG): cmdResponse: 01
2013-10-30T18:59:34.596Z,1383159574.596 [DVL_micro](INFO): NQ1 output enabled
2013-10-30T18:59:34.596Z,1383159574.596 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-10-30T18:59:34.608Z,1383159574.608 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 
2013-10-30T18:59:34.611Z,1383159574.611 [DVL_micro](INFO): pause:Powering down
2013-10-30T18:59:34.713Z,1383159574.713 [NAL9602](INFO): Powering up NAL9602
2013-10-30T18:59:45.376Z,1383159585.376 [NAL9602](INFO): NAL9602 initialized
2013-10-30T18:59:45.499Z,1383159585.499 [SBIT](IMPORTANT): Beginning Startup BIT
2013-10-30T18:59:45.510Z,1383159585.510 [CBIT](IMPORTANT): Beginning GF scan
2013-10-30T18:59:50.064Z,1383159590.064 [CommandLine](IMPORTANT): got command failComponent
2013-10-30T18:59:50.064Z,1383159590.064 [CommandLine](IMPORTANT): Failed components:
2013-10-30T18:59:50.064Z,1383159590.064 [CommandLine](IMPORTANT): No failed Components.
2013-10-30T18:59:50.868Z,1383159590.868 [DAT](INFO): Powering down
2013-10-30T19:00:07.106Z,1383159607.106 [CommandLine](IMPORTANT): got command failComponent
2013-10-30T19:00:07.106Z,1383159607.106 [CommandLine](IMPORTANT): Failed components:
2013-10-30T19:00:07.106Z,1383159607.106 [CommandLine](IMPORTANT): No failed Components.
2013-10-30T19:00:11.460Z,1383159611.460 [NAL9602](IMPORTANT): GPS fix at: 1383159632.00
2013-10-30T19:00:12.898Z,1383159612.898 [CBIT](IMPORTANT): No ground fault detected
2013-10-30T19:00:18.472Z,1383159618.472 [NAL9602](INFO): Powering down
2013-10-30T19:00:39.325Z,1383159639.325 [SBIT](IMPORTANT): SBIT PASSED
2013-10-30T19:00:39.712Z,1383159639.712 [MissionManager](IMPORTANT): Started mission Startup
2013-10-30T19:00:39.712Z,1383159639.712 [Startup] Running Loop=1
2013-10-30T19:00:39.713Z,1383159639.713 [Startup](INFO): Aggregate::initialize Startup
2013-10-30T19:00:39.713Z,1383159639.713 [Startup:A.GoToSurface] Running Loop=1
2013-10-30T19:00:39.713Z,1383159639.713 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-10-30T19:00:39.718Z,1383159639.718 [Startup:StartupSatComms] Running Loop=1
2013-10-30T19:00:39.719Z,1383159639.719 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2013-10-30T19:00:39.719Z,1383159639.719 [Startup:StartupSatComms:A] Running Loop=1
2013-10-30T19:00:40.114Z,1383159640.114 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2013-10-30T19:00:40.500Z,1383159640.500 [NAL9602](INFO): Powering up
2013-10-30T19:00:51.046Z,1383159651.046 [NAL9602](INFO): NAL9602 initialized
2013-10-30T19:01:10.189Z,1383159670.189 [NAL9602](IMPORTANT): GPS fix at: 1383159691.00
2013-10-30T19:01:10.228Z,1383159670.228 [Startup:StartupSatComms:A] Stopped
2013-10-30T19:01:10.228Z,1383159670.228 [Startup:StartupSatComms:B] Running Loop=1
2013-10-30T19:01:10.626Z,1383159670.626 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2013-10-30T19:01:19.218Z,1383159679.218 [CommandLine](IMPORTANT): got command show variable quality
2013-10-30T19:01:19.339Z,1383159679.339 [CommandLine](INFO): NAL9602.sigQuality (count)
2013-10-30T19:01:26.449Z,1383159686.449 [CommandLine](IMPORTANT): got command report mod NAL9602.sigQuality
2013-10-30T19:01:26.531Z,1383159686.531 [Reporter](INFO): NAL9602.sigQuality 5 count
2013-10-30T19:01:30.501Z,1383159690.501 [NAL9602](INFO): SBD MO Status=1, MOMSN=20237, MT Status=0, MTMSN=0
2013-10-30T19:01:30.551Z,1383159690.551 [NAL9602](INFO): Sent 18 bytes from file Logs/20131011T203037/Courier0040.lzma
2013-10-30T19:01:30.552Z,1383159690.552 [NAL9602](INFO): Packets left to send: 0
2013-10-30T19:01:30.554Z,1383159690.554 [NAL9602](INFO): Stored copy of sent data in Logs/20131011T203037/Courier0040.lzma.parts/0000.sbd
2013-10-30T19:01:36.879Z,1383159696.879 [NAL9602](INFO): SBD MO Status=1, MOMSN=20238, MT Status=0, MTMSN=0
2013-10-30T19:01:36.937Z,1383159696.937 [NAL9602](INFO): Sent 18 bytes from file Logs/20131022T211453/Courier0000.lzma
2013-10-30T19:01:36.938Z,1383159696.938 [NAL9602](INFO): Packets left to send: 0
2013-10-30T19:01:36.942Z,1383159696.942 [NAL9602](INFO): Stored copy of sent data in Logs/20131022T211453/Courier0000.lzma.parts/0000.sbd
2013-10-30T19:01:47.257Z,1383159707.257 [NAL9602](INFO): SBD MO Status=1, MOMSN=20239, MT Status=0, MTMSN=0
2013-10-30T19:01:47.314Z,1383159707.314 [NAL9602](INFO): Sent 283 bytes from file Logs/20131022T211718/Courier0004.lzma
2013-10-30T19:01:47.314Z,1383159707.314 [NAL9602](INFO): Packets left to send: 0
2013-10-30T19:01:47.315Z,1383159707.315 [NAL9602](INFO): Stored copy of sent data in Logs/20131022T211718/Courier0004.lzma.parts/0000.sbd
2013-10-30T19:01:54.096Z,1383159714.096 [NAL9602](INFO): SBD MO Status=1, MOMSN=20240, MT Status=0, MTMSN=0
2013-10-30T19:01:54.144Z,1383159714.144 [NAL9602](INFO): Sent 111 bytes from file Logs/20131022T211718/Courier0008.lzma
2013-10-30T19:01:54.144Z,1383159714.144 [NAL9602](INFO): Packets left to send: 0
2013-10-30T19:01:54.146Z,1383159714.146 [NAL9602](INFO): Stored copy of sent data in Logs/20131022T211718/Courier0008.lzma.parts/0000.sbd
2013-10-30T19:02:02.497Z,1383159722.497 [NAL9602](INFO): SBD MO Status=1, MOMSN=20241, MT Status=0, MTMSN=0
2013-10-30T19:02:02.545Z,1383159722.545 [NAL9602](INFO): Sent 98 bytes from file Logs/20131022T214908/Courier0004.lzma
2013-10-30T19:02:02.545Z,1383159722.545 [NAL9602](INFO): Packets left to send: 0
2013-10-30T19:02:02.547Z,1383159722.547 [NAL9602](INFO): Stored copy of sent data in Logs/20131022T214908/Courier0004.lzma.parts/0000.sbd
2013-10-30T19:02:10.514Z,1383159730.514 [Startup:StartupSatComms:B](INFO): Timed out from 2013-10-30T19:01:10.2Z
2013-10-30T19:02:10.514Z,1383159730.514 [Startup:StartupSatComms:B:A_Timeout] Running Loop=1
2013-10-30T19:02:10.514Z,1383159730.514 [Startup:StartupSatComms:B:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:B:A_Timeout
2013-10-30T19:02:10.514Z,1383159730.514 [Startup:StartupSatComms:B:A_Timeout](INFO): Completed Startup:StartupSatComms:B:A_Timeout
2013-10-30T19:02:10.514Z,1383159730.514 [Startup:StartupSatComms:B] Stopped
2013-10-30T19:02:10.514Z,1383159730.514 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2013-10-30T19:02:10.514Z,1383159730.514 [Startup:StartupSatComms] Stopped
2013-10-30T19:02:10.515Z,1383159730.515 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2013-10-30T19:02:10.515Z,1383159730.515 [Startup](INFO): Completed Startup
2013-10-30T19:02:10.515Z,1383159730.515 [Startup] Stopped
2013-10-30T19:02:10.516Z,1383159730.516 [Startup](INFO): Aggregate::uninitialize Startup
2013-10-30T19:02:10.516Z,1383159730.516 [Startup:A.GoToSurface] Stopped
2013-10-30T19:02:10.516Z,1383159730.516 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-10-30T19:02:10.919Z,1383159730.919 [MissionManager](IMPORTANT): Started mission Default
2013-10-30T19:02:10.919Z,1383159730.919 [Default] Running Loop=1
2013-10-30T19:02:10.919Z,1383159730.919 [Default](INFO): Aggregate::initialize Default
2013-10-30T19:02:10.919Z,1383159730.919 [Default:D.SetSpeed] Running Loop=1
2013-10-30T19:02:10.919Z,1383159730.919 [Default:D.SetSpeed](DEBUG): Initialize.
2013-10-30T19:02:10.919Z,1383159730.919 [Default:E.GoToSurface] Running Loop=1
2013-10-30T19:02:10.919Z,1383159730.919 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-10-30T19:02:10.920Z,1383159730.920 [Default:Iridium] Running Loop=1
2013-10-30T19:02:10.920Z,1383159730.920 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-10-30T19:02:10.920Z,1383159730.920 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-10-30T19:02:10.920Z,1383159730.920 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-10-30T19:02:10.920Z,1383159730.920 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-10-30T19:02:10.920Z,1383159730.920 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-10-30T19:02:10.921Z,1383159730.921 [Default:E.GoToSurface] Running Loop=1
2013-10-30T19:02:10.926Z,1383159730.926 [Default:D.SetSpeed] Running Loop=1
2013-10-30T19:02:10.931Z,1383159730.931 [Default:CallIridium] Running Loop=1
2013-10-30T19:02:10.931Z,1383159730.931 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-10-30T19:02:10.932Z,1383159730.932 [Default:CallIridium:A] Running Loop=1
2013-10-30T19:02:10.934Z,1383159730.934 [Default:CallIridium:A] Stopped
2013-10-30T19:02:10.934Z,1383159730.934 [Default:CallIridium:B] Running Loop=1
2013-10-30T19:02:10.934Z,1383159730.934 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-10-30T19:02:10.940Z,1383159730.940 [Default:Iridium:B.GoToSurface] Stopped
2013-10-30T19:02:10.940Z,1383159730.940 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-10-30T19:02:10.940Z,1383159730.940 [Default:Iridium:Read_Iridium] Running Loop=1
2013-10-30T19:02:10.940Z,1383159730.940 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-10-30T19:02:10.945Z,1383159730.945 [Default:GPS] Running Loop=1
2013-10-30T19:02:10.945Z,1383159730.945 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-10-30T19:02:10.945Z,1383159730.945 [Default:GPS:A.SetSpeed] Running Loop=1
2013-10-30T19:02:10.945Z,1383159730.945 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-10-30T19:02:10.945Z,1383159730.945 [Default:GPS:B.GoToSurface] Running Loop=1
2013-10-30T19:02:10.945Z,1383159730.945 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-10-30T19:02:10.951Z,1383159730.951 [Default:GPS:B.GoToSurface] Stopped
2013-10-30T19:02:10.951Z,1383159730.951 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-10-30T19:02:10.951Z,1383159730.951 [Default:GPS:Read_GPS] Running Loop=1
2013-10-30T19:02:10.951Z,1383159730.951 [Default:GPS:A.SetSpeed] Running Loop=1
2013-10-30T19:02:11.343Z,1383159731.343 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2013-10-30T19:02:11.346Z,1383159731.346 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2013-10-30T19:02:14.139Z,1383159734.139 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=20242, MT Status=1, MTMSN=1399
2013-10-30T19:02:14.198Z,1383159734.198 [NAL9602](INFO): Sent 25 bytes from file Logs/20131022T220135/Courier0004.lzma
2013-10-30T19:02:14.199Z,1383159734.199 [NAL9602](INFO): Packets left to send: 0
2013-10-30T19:02:14.200Z,1383159734.200 [NAL9602](INFO): Stored copy of sent data in Logs/20131022T220135/Courier0004.lzma.parts/0000.sbd
2013-10-30T19:02:14.675Z,1383159734.675 [NAL9602](INFO): Received command:ibit
2013-10-30T19:02:14.684Z,1383159734.684 [CommandLine](IMPORTANT): got command ibit
2013-10-30T19:02:14.718Z,1383159734.718 [IBIT](IMPORTANT): Beginning Initiated BIT
2013-10-30T19:02:14.718Z,1383159734.718 [IBIT](IMPORTANT): Beginning control surface checks.

2013-10-30T19:02:14.722Z,1383159734.722 [CBIT](IMPORTANT): Beginning GF scan
2013-10-30T19:02:15.100Z,1383159735.100 [IBIT](IMPORTANT): Beginning Initiated BIT
2013-10-30T19:02:15.100Z,1383159735.100 [IBIT](IMPORTANT): Beginning control surface checks.

2013-10-30T19:02:15.878Z,1383159735.878 [NAL9602](IMPORTANT): GPS fix at: 1383159756.00
2013-10-30T19:02:31.877Z,1383159751.877 [NAL9602](INFO): SBD MO Status=1, MOMSN=20243, MT Status=0, MTMSN=0
2013-10-30T19:02:31.931Z,1383159751.931 [NAL9602](INFO): Sent 206 bytes from file Logs/20131030T185920/Courier0000.lzma
2013-10-30T19:02:31.931Z,1383159751.931 [NAL9602](INFO): Packets left to send: 0
2013-10-30T19:02:31.933Z,1383159751.933 [NAL9602](INFO): Stored copy of sent data in Logs/20131030T185920/Courier0000.lzma.parts/0000.sbd
2013-10-30T19:02:40.981Z,1383159760.981 [CBIT](IMPORTANT): No ground fault detected
2013-10-30T19:02:44.572Z,1383159764.572 [NAL9602](INFO): SBD MO Status=1, MOMSN=20244, MT Status=0, MTMSN=0
2013-10-30T19:02:44.630Z,1383159764.630 [NAL9602](INFO): Sent 18 bytes from file Logs/20131011T203037/Express0041.lzma
2013-10-30T19:02:44.631Z,1383159764.631 [NAL9602](INFO): Packets left to send: 0
2013-10-30T19:02:44.632Z,1383159764.632 [NAL9602](INFO): Stored copy of sent data in Logs/20131011T203037/Express0041.lzma.parts/0000.sbd
2013-10-30T19:03:00.609Z,1383159780.609 [NAL9602](INFO): SBD MO Status=2, MOMSN=20245, MT Status=2, MTMSN=0
2013-10-30T19:03:00.609Z,1383159780.609 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-10-30T19:03:01.038Z,1383159781.038 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 5
Latitude: 36.802868 Longitude: -121.788063
2013-10-30T19:03:01.453Z,1383159781.453 [IBIT](FAULT): Warning: Battery Data not active. Expected only when running primaries. Threshold checking not active.
2013-10-30T19:03:01.809Z,1383159781.809 [NAL9602](IMPORTANT): GPS fix at: 1383159802.00
2013-10-30T19:03:01.831Z,1383159781.831 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2013-10-30T19:03:01.831Z,1383159781.831 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2013-10-30T19:03:01.831Z,1383159781.831 [IBIT](IMPORTANT): Pressure:10.734123 PSI
2013-10-30T19:03:01.832Z,1383159781.832 [IBIT](IMPORTANT): Humidity:20.000895 %
2013-10-30T19:03:02.246Z,1383159782.246 [IBIT](IMPORTANT): surfaceThreshold: 0.500000 m
2013-10-30T19:03:02.246Z,1383159782.246 [IBIT](IMPORTANT): buoyancyNeutral: 300.000000 cc
2013-10-30T19:03:02.246Z,1383159782.246 [IBIT](IMPORTANT): massDefault: 0.800000 cm
2013-10-30T19:03:02.247Z,1383159782.247 [IBIT](IMPORTANT): stopDepth: 112.000000 m
2013-10-30T19:03:02.247Z,1383159782.247 [IBIT](IMPORTANT): abortDepth: 130.000000 m
2013-10-30T19:03:02.247Z,1383159782.247 [IBIT](IMPORTANT): IBIT PASSED
2013-10-30T19:03:02.624Z,1383159782.624 [Default:GPS:Read_GPS] Stopped
2013-10-30T19:03:02.625Z,1383159782.625 [Default:GPS:D] Running Loop=1
2013-10-30T19:03:03.038Z,1383159783.038 [Default:GPS:D] Stopped
2013-10-30T19:03:03.038Z,1383159783.038 [Default:GPS](INFO): Completed Default:GPS
2013-10-30T19:03:03.038Z,1383159783.038 [Default:GPS] Stopped
2013-10-30T19:03:03.039Z,1383159783.039 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-10-30T19:03:03.039Z,1383159783.039 [Default:GPS:A.SetSpeed] Stopped
2013-10-30T19:03:03.039Z,1383159783.039 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-10-30T19:03:05.555Z,1383159785.555 [Reporter](INFO): NAL9602.sigQuality 3 count
2013-10-30T19:03:18.826Z,1383159798.826 [NAL9602](INFO): SBD MO Status=1, MOMSN=20245, MT Status=0, MTMSN=0
2013-10-30T19:03:18.876Z,1383159798.876 [NAL9602](INFO): Sent 18 bytes from file Logs/20131022T211453/Express0001.lzma
2013-10-30T19:03:18.876Z,1383159798.876 [NAL9602](INFO): Packets left to send: 0
2013-10-30T19:03:18.878Z,1383159798.878 [NAL9602](INFO): Stored copy of sent data in Logs/20131022T211453/Express0001.lzma.parts/0000.sbd
2013-10-30T19:03:30.297Z,1383159810.297 [NAL9602](INFO): SBD MO Status=1, MOMSN=20246, MT Status=0, MTMSN=0
2013-10-30T19:03:30.345Z,1383159810.345 [NAL9602](INFO): Sent 332 bytes from file Logs/20131022T211718/Express0001.lzma
2013-10-30T19:03:30.345Z,1383159810.345 [NAL9602](INFO): Packets left to send: 2
2013-10-30T19:03:30.347Z,1383159810.347 [NAL9602](INFO): Stored copy of sent data in Logs/20131022T211718/Express0001.lzma.parts/0002.sbd
2013-10-30T19:03:44.084Z,1383159824.084 [NAL9602](INFO): SBD MO Status=1, MOMSN=20247, MT Status=0, MTMSN=0
2013-10-30T19:03:44.135Z,1383159824.135 [NAL9602](INFO): Sent 332 bytes from file Logs/20131022T211718/Express0001.lzma
2013-10-30T19:03:44.135Z,1383159824.135 [NAL9602](INFO): Packets left to send: 1
2013-10-30T19:03:44.136Z,1383159824.136 [NAL9602](INFO): Stored copy of sent data in Logs/20131022T211718/Express0001.lzma.parts/0001.sbd
2013-10-30T19:03:53.800Z,1383159833.800 [NAL9602](INFO): SBD MO Status=1, MOMSN=20248, MT Status=0, MTMSN=0
2013-10-30T19:03:53.850Z,1383159833.850 [NAL9602](INFO): Sent 35 bytes from file Logs/20131022T211718/Express0001.lzma
2013-10-30T19:03:53.850Z,1383159833.850 [NAL9602](INFO): Packets left to send: 0
2013-10-30T19:03:53.851Z,1383159833.851 [NAL9602](INFO): Stored copy of sent data in Logs/20131022T211718/Express0001.lzma.parts/0000.sbd
2013-10-30T19:04:07.637Z,1383159847.637 [NAL9602](INFO): SBD MO Status=1, MOMSN=20249, MT Status=0, MTMSN=0
2013-10-30T19:04:07.697Z,1383159847.697 [NAL9602](INFO): Sent 332 bytes from file Logs/20131022T211718/Express0005.lzma
2013-10-30T19:04:07.697Z,1383159847.697 [NAL9602](INFO): Packets left to send: 2
2013-10-30T19:04:07.699Z,1383159847.699 [NAL9602](INFO): Stored copy of sent data in Logs/20131022T211718/Express0005.lzma.parts/0002.sbd
2013-10-30T19:04:20.997Z,1383159860.997 [NAL9602](INFO): SBD MO Status=1, MOMSN=20250, MT Status=0, MTMSN=0
2013-10-30T19:04:21.044Z,1383159861.044 [NAL9602](INFO): Sent 332 bytes from file Logs/20131022T211718/Express0005.lzma
2013-10-30T19:04:21.044Z,1383159861.044 [NAL9602](INFO): Packets left to send: 1
2013-10-30T19:04:21.045Z,1383159861.045 [NAL9602](INFO): Stored copy of sent data in Logs/20131022T211718/Express0005.lzma.parts/0001.sbd
2013-10-30T19:04:39.700Z,1383159879.700 [NAL9602](INFO): SBD MO Status=2, MOMSN=20251, MT Status=2, MTMSN=0
2013-10-30T19:04:39.701Z,1383159879.701 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-10-30T19:04:44.622Z,1383159884.622 [Reporter](INFO): NAL9602.sigQuality 2 count
2013-10-30T19:05:03.588Z,1383159903.588 [NAL9602](INFO): SBD MO Status=2, MOMSN=20251, MT Status=2, MTMSN=0
2013-10-30T19:05:03.588Z,1383159903.588 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-10-30T19:05:08.518Z,1383159908.518 [Reporter](INFO): NAL9602.sigQuality 5 count
2013-10-30T19:05:26.503Z,1383159926.503 [NAL9602](INFO): SBD MO Status=2, MOMSN=20251, MT Status=0, MTMSN=0
2013-10-30T19:05:26.504Z,1383159926.504 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-10-30T19:05:31.450Z,1383159931.450 [Reporter](INFO): NAL9602.sigQuality 3 count
2013-10-30T19:05:46.797Z,1383159946.797 [NAL9602](INFO): SBD MO Status=1, MOMSN=20251, MT Status=0, MTMSN=0
2013-10-30T19:05:46.845Z,1383159946.845 [NAL9602](INFO): Sent 80 bytes from file Logs/20131022T211718/Express0005.lzma
2013-10-30T19:05:46.845Z,1383159946.845 [NAL9602](INFO): Packets left to send: 0
2013-10-30T19:05:46.846Z,1383159946.846 [NAL9602](INFO): Stored copy of sent data in Logs/20131022T211718/Express0005.lzma.parts/0000.sbd
2013-10-30T19:06:09.800Z,1383159969.800 [NAL9602](INFO): SBD MO Status=1, MOMSN=20252, MT Status=0, MTMSN=0
2013-10-30T19:06:09.848Z,1383159969.848 [NAL9602](INFO): Sent 332 bytes from file Logs/20131022T211718/Express0009.lzma
2013-10-30T19:06:09.849Z,1383159969.849 [NAL9602](INFO): Packets left to send: 3
2013-10-30T19:06:09.850Z,1383159969.850 [NAL9602](INFO): Stored copy of sent data in Logs/20131022T211718/Express0009.lzma.parts/0003.sbd
2013-10-30T19:06:39.286Z,1383159999.286 [NAL9602](INFO): SBD MO Status=2, MOMSN=20253, MT Status=0, MTMSN=0
2013-10-30T19:06:39.287Z,1383159999.287 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-10-30T19:06:44.624Z,1383160004.624 [Reporter](INFO): NAL9602.sigQuality 2 count
2013-10-30T19:07:04.786Z,1383160024.786 [NAL9602](INFO): SBD MO Status=1, MOMSN=20253, MT Status=0, MTMSN=0
2013-10-30T19:07:04.838Z,1383160024.838 [NAL9602](INFO): Sent 332 bytes from file Logs/20131022T211718/Express0009.lzma
2013-10-30T19:07:04.838Z,1383160024.838 [NAL9602](INFO): Packets left to send: 2
2013-10-30T19:07:04.839Z,1383160024.839 [NAL9602](INFO): Stored copy of sent data in Logs/20131022T211718/Express0009.lzma.parts/0002.sbd
2013-10-30T19:08:13.000Z,1383160093.000 [NAL9602](ERROR): Verify xmit timeout failure.
2013-10-30T19:08:13.508Z,1383160093.508 [NAL9602](ERROR): Waiting on SBDI return line 1. Uart error: serial timeout
2013-10-30T19:08:13.508Z,1383160093.508 [NAL9602](DEBUG): SBDI didn't return with OK. Line 1 Modem reported: 
2013-10-30T19:08:14.017Z,1383160094.017 [NAL9602](ERROR): Waiting on SBDI return line 2. Uart error: serial timeout
2013-10-30T19:08:14.017Z,1383160094.017 [NAL9602](DEBUG): SBDI didn't return with OK. Line 2 Modem reported: 
2013-10-30T19:08:14.842Z,1383160094.842 [NAL9602](ERROR): Fill buffer uart error: serial timeout
2013-10-30T19:08:14.842Z,1383160094.842 [NAL9602](ERROR): Failed to receive READY. Modem reported: 
2013-10-30T19:08:46.184Z,1383160126.184 [NAL9602](ERROR): Queried for signal strength and failed to receive proper response. serial timeout
2013-10-30T19:08:46.703Z,1383160126.703 [NAL9602](FAULT): received: 
2013-10-30T19:08:46.703Z,1383160126.703 [NAL9602] Data Fault, FailCount= 1
2013-10-30T19:08:46.703Z,1383160126.703 [NAL9602](ERROR): Data Fault
2013-10-30T19:08:46.730Z,1383160126.730 [CBIT](ERROR): Data Fault in component: NAL9602
2013-10-30T19:08:46.731Z,1383160126.731 [Reporter](INFO): NAL9602.sigQuality no_value
2013-10-30T19:08:47.081Z,1383160127.081 [NAL9602](INFO): Powering down
2013-10-30T19:08:47.931Z,1383160127.931 [CBIT](INFO): Clearing failed state for component NAL9602
2013-10-30T19:08:47.932Z,1383160127.932 [NAL9602] No Fault, FailCount= 1
2013-10-30T19:08:52.296Z,1383160132.296 [NAL9602](INFO): Powering up NAL9602
2013-10-30T19:09:02.375Z,1383160142.375 [Reporter](INFO): NAL9602.sigQuality 2 count
2013-10-30T19:09:02.777Z,1383160142.777 [NAL9602](INFO): NAL9602 initialized
2013-10-30T19:09:12.129Z,1383160152.129 [Reporter](INFO): NAL9602.sigQuality 5 count
2013-10-30T19:09:20.168Z,1383160160.168 [NAL9602](INFO): SBD MO Status=1, MOMSN=20255, MT Status=0, MTMSN=0
2013-10-30T19:09:20.212Z,1383160160.212 [NAL9602](INFO): Sent 332 bytes from file Logs/20131022T211718/Express0009.lzma
2013-10-30T19:09:20.212Z,1383160160.212 [NAL9602](INFO): Packets left to send: 1
2013-10-30T19:09:20.213Z,1383160160.213 [NAL9602](INFO): Stored copy of sent data in Logs/20131022T211718/Express0009.lzma.parts/0001.sbd
2013-10-30T19:09:29.111Z,1383160169.111 [NAL9602](INFO): SBD MO Status=1, MOMSN=20256, MT Status=0, MTMSN=0
2013-10-30T19:09:29.162Z,1383160169.162 [NAL9602](INFO): Sent 1 bytes from file Logs/20131022T211718/Express0009.lzma
2013-10-30T19:09:29.162Z,1383160169.162 [NAL9602](INFO): Packets left to send: 0
2013-10-30T19:09:29.163Z,1383160169.163 [NAL9602](INFO): Stored copy of sent data in Logs/20131022T211718/Express0009.lzma.parts/0000.sbd
2013-10-30T19:09:41.603Z,1383160181.603 [NAL9602](INFO): SBD MO Status=1, MOMSN=20257, MT Status=0, MTMSN=0
2013-10-30T19:09:41.653Z,1383160181.653 [NAL9602](INFO): Sent 332 bytes from file Logs/20131022T214908/Express0001.lzma
2013-10-30T19:09:41.653Z,1383160181.653 [NAL9602](INFO): Packets left to send: 2
2013-10-30T19:09:41.655Z,1383160181.655 [NAL9602](INFO): Stored copy of sent data in Logs/20131022T214908/Express0001.lzma.parts/0002.sbd
2013-10-30T19:09:53.794Z,1383160193.794 [NAL9602](INFO): SBD MO Status=1, MOMSN=20258, MT Status=0, MTMSN=0
2013-10-30T19:09:53.844Z,1383160193.844 [NAL9602](INFO): Sent 332 bytes from file Logs/20131022T214908/Express0001.lzma
2013-10-30T19:09:53.844Z,1383160193.844 [NAL9602](INFO): Packets left to send: 1
2013-10-30T19:09:53.845Z,1383160193.845 [NAL9602](INFO): Stored copy of sent data in Logs/20131022T214908/Express0001.lzma.parts/0001.sbd
2013-10-30T19:10:00.801Z,1383160200.801 [NAL9602](INFO): SBD MO Status=1, MOMSN=20259, MT Status=0, MTMSN=0
2013-10-30T19:10:00.851Z,1383160200.851 [NAL9602](INFO): Sent 34 bytes from file Logs/20131022T214908/Express0001.lzma
2013-10-30T19:10:00.851Z,1383160200.851 [NAL9602](INFO): Packets left to send: 0
2013-10-30T19:10:00.853Z,1383160200.853 [NAL9602](INFO): Stored copy of sent data in Logs/20131022T214908/Express0001.lzma.parts/0000.sbd
2013-10-30T19:10:14.985Z,1383160214.985 [NAL9602](INFO): SBD MO Status=1, MOMSN=20260, MT Status=0, MTMSN=0
2013-10-30T19:10:15.037Z,1383160215.037 [NAL9602](INFO): Sent 332 bytes from file Logs/20131022T214908/Express0005.lzma
2013-10-30T19:10:15.037Z,1383160215.037 [NAL9602](INFO): Packets left to send: 1
2013-10-30T19:10:15.038Z,1383160215.038 [NAL9602](INFO): Stored copy of sent data in Logs/20131022T214908/Express0005.lzma.parts/0001.sbd
2013-10-30T19:10:28.760Z,1383160228.760 [NAL9602](INFO): SBD MO Status=1, MOMSN=20261, MT Status=0, MTMSN=0
2013-10-30T19:10:28.810Z,1383160228.810 [NAL9602](INFO): Sent 237 bytes from file Logs/20131022T214908/Express0005.lzma
2013-10-30T19:10:28.810Z,1383160228.810 [NAL9602](INFO): Packets left to send: 0
2013-10-30T19:10:28.812Z,1383160228.812 [NAL9602](INFO): Stored copy of sent data in Logs/20131022T214908/Express0005.lzma.parts/0000.sbd
2013-10-30T19:10:40.958Z,1383160240.958 [NAL9602](INFO): SBD MO Status=1, MOMSN=20262, MT Status=0, MTMSN=0
2013-10-30T19:10:41.009Z,1383160241.009 [NAL9602](INFO): Sent 332 bytes from file Logs/20131022T220135/Express0001.lzma
2013-10-30T19:10:41.009Z,1383160241.009 [NAL9602](INFO): Packets left to send: 1
2013-10-30T19:10:41.011Z,1383160241.011 [NAL9602](INFO): Stored copy of sent data in Logs/20131022T220135/Express0001.lzma.parts/0001.sbd
2013-10-30T19:10:54.452Z,1383160254.452 [NAL9602](INFO): SBD MO Status=1, MOMSN=20263, MT Status=0, MTMSN=0
2013-10-30T19:10:54.510Z,1383160254.510 [NAL9602](INFO): Sent 229 bytes from file Logs/20131022T220135/Express0001.lzma
2013-10-30T19:10:54.510Z,1383160254.510 [NAL9602](INFO): Packets left to send: 0
2013-10-30T19:10:54.511Z,1383160254.511 [NAL9602](INFO): Stored copy of sent data in Logs/20131022T220135/Express0001.lzma.parts/0000.sbd
2013-10-30T19:11:06.783Z,1383160266.783 [NAL9602](INFO): SBD MO Status=1, MOMSN=20264, MT Status=0, MTMSN=0
2013-10-30T19:11:06.833Z,1383160266.833 [NAL9602](INFO): Sent 245 bytes from file Logs/20131022T220135/Express0005.lzma
2013-10-30T19:11:06.833Z,1383160266.833 [NAL9602](INFO): Packets left to send: 0
2013-10-30T19:11:06.835Z,1383160266.835 [NAL9602](INFO): Stored copy of sent data in Logs/20131022T220135/Express0005.lzma.parts/0000.sbd
2013-10-30T19:11:26.558Z,1383160286.558 [NAL9602](INFO): SBD MO Status=2, MOMSN=20265, MT Status=2, MTMSN=0
2013-10-30T19:11:26.558Z,1383160286.558 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-10-30T19:11:31.489Z,1383160291.489 [Reporter](INFO): NAL9602.sigQuality 4 count
2013-10-30T19:12:39.696Z,1383160359.696 [NAL9602](ERROR): Verify xmit timeout failure.
2013-10-30T19:12:40.197Z,1383160360.197 [NAL9602](ERROR): Waiting on SBDI return line 1. Uart error: serial timeout
2013-10-30T19:12:40.198Z,1383160360.198 [NAL9602](DEBUG): SBDI didn't return with OK. Line 1 Modem reported: 
2013-10-30T19:12:40.702Z,1383160360.702 [NAL9602](ERROR): Waiting on SBDI return line 2. Uart error: serial timeout
2013-10-30T19:12:40.702Z,1383160360.702 [NAL9602](DEBUG): SBDI didn't return with OK. Line 2 Modem reported: 
2013-10-30T19:13:08.470Z,1383160388.470 [NAL9602](INFO): SBD MO Status=2, MOMSN=20265, MT Status=2, MTMSN=0
2013-10-30T19:13:08.470Z,1383160388.470 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-10-30T19:13:08.838Z,1383160388.838 [CommandLine](IMPORTANT): got command quit
2013-10-30T19:13:09.851Z,1383160389.851 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2013-10-30T19:13:09.851Z,1383160389.851 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2013-10-30T19:13:09.931Z,1383160389.931 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2013-10-30T19:13:09.984Z,1383160389.984 [WetLabsBB2FL](INFO): Powering down
2013-10-30T19:13:09.992Z,1383160389.992 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2013-10-30T19:13:10.272Z,1383160390.272 [CTD_NeilBrown](INFO): Powering down
2013-10-30T19:13:10.276Z,1383160390.276 [ComponentRegistry](INFO): Shutting down DVL_micro ThreadHandler
2013-10-30T19:13:10.377Z,1383160390.377 [DVL_micro](INFO): uninitialize:Powering down
2013-10-30T19:13:10.396Z,1383160390.396 [ComponentRegistry](INFO): Shutting down AsyncPiEstimator ThreadHandler
2013-10-30T19:13:10.557Z,1383160390.557 [AsyncPiEstimator](DEBUG): Uninitialize AsyncPiEstimator.
2013-10-30T19:13:10.577Z,1383160390.577 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2013-10-30T19:13:10.617Z,1383160390.617 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2013-10-30T19:13:10.619Z,1383160390.619 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2013-10-30T19:13:10.888Z,1383160390.888 [controlThread](DEBUG): Uninitializing ControlThread
2013-10-30T19:13:10.889Z,1383160390.889 [AHRS_sp3003D](INFO): Powering down
2013-10-30T19:13:10.978Z,1383160390.978 [NAL9602](INFO): Powering down
2013-10-30T19:13:10.979Z,1383160390.979 [DAT](INFO): Powering down
2013-10-30T19:13:10.980Z,1383160390.980 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2013-10-30T19:13:10.981Z,1383160390.981 [NavChart](DEBUG): Uninitialize NavChart Derivation.
2013-10-30T19:13:10.982Z,1383160390.982 [Default] Stopped
2013-10-30T19:13:10.982Z,1383160390.982 [Default](INFO): Aggregate::uninitialize Default
2013-10-30T19:13:10.982Z,1383160390.982 [Default:Iridium] Stopped
2013-10-30T19:13:10.982Z,1383160390.982 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-10-30T19:13:10.982Z,1383160390.982 [Default:Iridium:A.SetSpeed] Stopped
2013-10-30T19:13:10.982Z,1383160390.982 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-10-30T19:13:10.983Z,1383160390.983 [Default:Iridium:Read_Iridium] Stopped
2013-10-30T19:13:10.983Z,1383160390.983 [Default:CallIridium] Stopped
2013-10-30T19:13:10.983Z,1383160390.983 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-10-30T19:13:10.983Z,1383160390.983 [Default:CallIridium:B] Stopped
2013-10-30T19:13:10.983Z,1383160390.983 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-10-30T19:13:10.983Z,1383160390.983 [Default:D.SetSpeed] Stopped
2013-10-30T19:13:10.983Z,1383160390.983 [Default:D.SetSpeed](DEBUG): Uninitialize.
2013-10-30T19:13:10.983Z,1383160390.983 [Default:E.GoToSurface] Stopped
2013-10-30T19:13:10.983Z,1383160390.983 [Default:E.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-10-30T19:13:10.987Z,1383160390.987 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2013-10-30T19:13:10.988Z,1383160390.988 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2013-10-30T19:13:10.988Z,1383160390.988 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2013-10-30T19:13:10.988Z,1383160390.988 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2013-10-30T19:13:10.988Z,1383160390.988 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2013-10-30T19:13:10.989Z,1383160390.989 [BuoyancyServo](INFO): Powering down
2013-10-30T19:13:11.001Z,1383160391.001 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2013-10-30T19:13:11.002Z,1383160391.002 [ElevatorServo](INFO): Powering down
2013-10-30T19:13:11.002Z,1383160391.002 [MassServo](DEBUG): Uninitialize Mass Servo.
2013-10-30T19:13:11.003Z,1383160391.003 [MassServo](INFO): Powering down
2013-10-30T19:13:11.003Z,1383160391.003 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2013-10-30T19:13:11.003Z,1383160391.003 [RudderServo](INFO): Powering down
2013-10-30T19:13:11.004Z,1383160391.004 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2013-10-30T19:13:11.004Z,1383160391.004 [ThrusterServo](INFO): Powering down
2013-10-30T19:13:11.005Z,1383160391.005 [SBIT](DEBUG): Uninitialize SBIT Component.
2013-10-30T19:13:11.006Z,1383160391.006 [IBIT](DEBUG): Uninitialize IBIT Component.
2013-10-30T19:13:11.006Z,1383160391.006 [CBIT](DEBUG): Uninitialize CBIT Component.