2013-02-25T18:54:30.034Z,1361818470.034 [Supervisor](DEBUG): Initializing supervisor.
2013-02-25T18:54:30.037Z,1361818470.037 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0
2013-02-25T18:54:30.037Z,1361818470.037 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2013-02-25T18:54:30.038Z,1361818470.038 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0
2013-02-25T18:54:30.042Z,1361818470.042 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2013-02-25T18:54:30.052Z,1361818470.052 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2013-02-25T18:54:30.053Z,1361818470.053 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0
2013-02-25T18:54:30.054Z,1361818470.054 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2013-02-25T18:54:30.055Z,1361818470.055 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0
2013-02-25T18:54:30.056Z,1361818470.056 [Supervisor](INFO): Looking for Config files in directory: Config/
2013-02-25T18:54:30.057Z,1361818470.057 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2013-02-25T18:54:30.331Z,1361818470.331 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2013-02-25T18:54:30.331Z,1361818470.332 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2013-02-25T18:54:30.516Z,1361818470.516 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2013-02-25T18:54:30.517Z,1361818470.517 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2013-02-25T18:54:30.601Z,1361818470.601 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2013-02-25T18:54:30.601Z,1361818470.602 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2013-02-25T18:54:30.795Z,1361818470.795 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2013-02-25T18:54:30.795Z,1361818470.795 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2013-02-25T18:54:30.927Z,1361818470.927 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2013-02-25T18:54:30.927Z,1361818470.927 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2013-02-25T18:54:31.155Z,1361818471.155 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2013-02-25T18:54:31.156Z,1361818471.156 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2013-02-25T18:54:31.324Z,1361818471.324 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2013-02-25T18:54:31.324Z,1361818471.324 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2013-02-25T18:54:31.572Z,1361818471.572 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2013-02-25T18:54:31.573Z,1361818471.573 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2013-02-25T18:54:31.670Z,1361818471.670 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2013-02-25T18:54:31.670Z,1361818471.671 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2013-02-25T18:54:32.063Z,1361818472.063 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2013-02-25T18:54:32.063Z,1361818472.063 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2013-02-25T18:54:32.176Z,1361818472.176 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2013-02-25T18:54:32.177Z,1361818472.177 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2013-02-25T18:54:32.261Z,1361818472.261 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2013-02-25T18:54:32.262Z,1361818472.262 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2013-02-25T18:54:32.363Z,1361818472.363 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2013-02-25T18:54:32.490Z,1361818472.490 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2013-02-25T18:54:32.575Z,1361818472.575 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2013-02-25T18:54:32.676Z,1361818472.676 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2013-02-25T18:54:32.775Z,1361818472.775 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2013-02-25T18:54:32.892Z,1361818472.892 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2013-02-25T18:54:32.984Z,1361818472.984 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2013-02-25T18:54:33.070Z,1361818473.070 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2013-02-25T18:54:33.098Z,1361818473.098 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2013-02-25T18:54:33.248Z,1361818473.248 [InternalSim] Loaded
2013-02-25T18:54:33.248Z,1361818473.248 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2013-02-25T18:54:33.249Z,1361818473.249 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2013-02-25T18:54:33.250Z,1361818473.250 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2013-02-25T18:54:33.305Z,1361818473.305 [SBIT](DEBUG): Construct Startup Built In Test.
2013-02-25T18:54:33.334Z,1361818473.334 [SBIT] Loaded
2013-02-25T18:54:33.334Z,1361818473.334 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2013-02-25T18:54:33.335Z,1361818473.335 [IBIT](DEBUG): Construct Initiated Built In Test.
2013-02-25T18:54:33.363Z,1361818473.363 [IBIT] Loaded
2013-02-25T18:54:33.364Z,1361818473.364 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2013-02-25T18:54:33.367Z,1361818473.367 [CBIT](DEBUG): Construct CBIT Built In Test.
2013-02-25T18:54:33.485Z,1361818473.485 [CBIT] Loaded
2013-02-25T18:54:33.485Z,1361818473.485 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2013-02-25T18:54:33.486Z,1361818473.486 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2013-02-25T18:54:33.486Z,1361818473.486 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2013-02-25T18:54:33.636Z,1361818473.635 [BuoyancyServo] Loaded
2013-02-25T18:54:33.636Z,1361818473.636 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2013-02-25T18:54:33.648Z,1361818473.648 [ElevatorServo] Loaded
2013-02-25T18:54:33.648Z,1361818473.648 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2013-02-25T18:54:33.660Z,1361818473.660 [MassServo] Loaded
2013-02-25T18:54:33.660Z,1361818473.660 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2013-02-25T18:54:33.672Z,1361818473.672 [RudderServo] Loaded
2013-02-25T18:54:33.673Z,1361818473.673 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2013-02-25T18:54:33.684Z,1361818473.684 [ThrusterServo] Loaded
2013-02-25T18:54:33.685Z,1361818473.685 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2013-02-25T18:54:33.685Z,1361818473.685 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2013-02-25T18:54:33.686Z,1361818473.685 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2013-02-25T18:54:33.702Z,1361818473.702 [DepthRateCalculator] Loaded
2013-02-25T18:54:33.702Z,1361818473.702 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2013-02-25T18:54:37.671Z,1361818477.671 [HFRadarModelCalc] Loaded
2013-02-25T18:54:37.672Z,1361818477.672 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2013-02-25T18:54:37.687Z,1361818477.687 [NavChart] Loaded
2013-02-25T18:54:37.688Z,1361818477.688 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2013-02-25T18:54:37.693Z,1361818477.693 [PitchRateCalculator] Loaded
2013-02-25T18:54:37.694Z,1361818477.694 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2013-02-25T18:54:37.700Z,1361818477.700 [SpeedCalculator] Loaded
2013-02-25T18:54:37.700Z,1361818477.700 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2013-02-25T18:54:37.715Z,1361818477.715 [TempGradientCalculator] Loaded
2013-02-25T18:54:37.715Z,1361818477.715 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2013-02-25T18:54:37.721Z,1361818477.721 [YawRateCalculator] Loaded
2013-02-25T18:54:37.721Z,1361818477.721 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2013-02-25T18:54:37.761Z,1361818477.761 [Navigation] Loaded
2013-02-25T18:54:37.762Z,1361818477.762 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread.
2013-02-25T18:54:37.762Z,1361818477.762 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2013-02-25T18:54:37.763Z,1361818477.763 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2013-02-25T18:54:37.979Z,1361818477.979 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2013-02-25T18:54:37.980Z,1361818477.980 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2013-02-25T18:54:38.001Z,1361818478.001 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2013-02-25T18:54:38.001Z,1361818478.001 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2013-02-25T18:54:38.040Z,1361818478.040 [VerticalControl](DEBUG): Construct VerticalControl.
2013-02-25T18:54:38.132Z,1361818478.132 [VerticalControl] Loaded
2013-02-25T18:54:38.133Z,1361818478.133 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2013-02-25T18:54:38.134Z,1361818478.134 [HorizontalControl](DEBUG): Construct HorizontalControl.
2013-02-25T18:54:38.193Z,1361818478.193 [HorizontalControl] Loaded
2013-02-25T18:54:38.193Z,1361818478.193 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2013-02-25T18:54:38.194Z,1361818478.194 [SpeedControl](DEBUG): Construct SpeedControl.
2013-02-25T18:54:38.196Z,1361818478.195 [SpeedControl] Loaded
2013-02-25T18:54:38.196Z,1361818478.196 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2013-02-25T18:54:38.197Z,1361818478.197 [LoopControl](DEBUG): Construct LoopControl.
2013-02-25T18:54:38.197Z,1361818478.197 [LoopControl] Loaded
2013-02-25T18:54:38.198Z,1361818478.197 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2013-02-25T18:54:38.198Z,1361818478.198 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2013-02-25T18:54:38.199Z,1361818478.198 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2013-02-25T18:54:38.204Z,1361818478.204 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator.
2013-02-25T18:54:38.209Z,1361818478.209 [AsyncPiEstimator] Loaded
2013-02-25T18:54:38.209Z,1361818478.209 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread.
2013-02-25T18:54:38.210Z,1361818478.210 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406A44E0
2013-02-25T18:54:38.211Z,1361818478.211 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2013-02-25T18:54:38.211Z,1361818478.211 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2013-02-25T18:54:38.336Z,1361818478.336 [AHRS_sp3003D] Loaded
2013-02-25T18:54:38.337Z,1361818478.337 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2013-02-25T18:54:38.603Z,1361818478.603 [Batt_Ocean_Server] Loaded
2013-02-25T18:54:38.603Z,1361818478.603 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2013-02-25T18:54:38.616Z,1361818478.616 [Depth_Keller] Loaded
2013-02-25T18:54:38.617Z,1361818478.616 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2013-02-25T18:54:38.622Z,1361818478.622 [DropWeight] Loaded
2013-02-25T18:54:38.623Z,1361818478.623 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2013-02-25T18:54:38.782Z,1361818478.782 [DVL_micro] Loaded
2013-02-25T18:54:38.783Z,1361818478.783 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread.
2013-02-25T18:54:38.784Z,1361818478.784 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 407284E0
2013-02-25T18:54:38.865Z,1361818478.865 [NAL9602] Loaded
2013-02-25T18:54:38.865Z,1361818478.865 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2013-02-25T18:54:38.923Z,1361818478.923 [Onboard] Loaded
2013-02-25T18:54:38.923Z,1361818478.923 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2013-02-25T18:54:38.930Z,1361818478.930 [Radio_Freewave] Loaded
2013-02-25T18:54:38.930Z,1361818478.930 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread.
2013-02-25T18:54:38.931Z,1361818478.931 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2013-02-25T18:54:38.931Z,1361818478.931 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2013-02-25T18:54:38.987Z,1361818478.987 [Aanderaa_O2] Loaded
2013-02-25T18:54:38.987Z,1361818478.987 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2013-02-25T18:54:39.001Z,1361818479.001 [ISUS] Loaded
2013-02-25T18:54:39.001Z,1361818479.001 [ComponentRegistry](DEBUG): SyncComponent "ISUS" handled in the control thread.
2013-02-25T18:54:39.016Z,1361818479.016 [PAR_Licor] Loaded
2013-02-25T18:54:39.017Z,1361818479.017 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2013-02-25T18:54:39.046Z,1361818479.046 [WetLabsBB2FL] Loaded
2013-02-25T18:54:39.047Z,1361818479.047 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2013-02-25T18:54:39.048Z,1361818479.048 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4077A4E0
2013-02-25T18:54:39.048Z,1361818479.048 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2013-02-25T18:54:39.051Z,1361818479.051 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2013-02-25T18:54:39.052Z,1361818479.052 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2013-02-25T18:54:39.058Z,1361818479.058 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2013-02-25T18:54:39.060Z,1361818479.059 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 407AA4E0
2013-02-25T18:54:39.064Z,1361818479.064 [Supervisor](DEBUG): Running supervisor.
2013-02-25T18:54:39.065Z,1361818479.065 [CommandLine](INFO): Thread ID is 640
2013-02-25T18:54:39.067Z,1361818479.067 [controlThread](INFO): Thread ID is 639
2013-02-25T18:54:39.068Z,1361818479.068 [controlThread](DEBUG): Initializing ControlThread
2013-02-25T18:54:39.068Z,1361818479.068 [CycleStarter](INFO): Thread ID is 638
2013-02-25T18:54:39.068Z,1361818479.069 [InternalSim](DEBUG):  InternalSim initializing...
2013-02-25T18:54:39.103Z,1361818479.103 [logger](INFO): Thread ID is 641
2013-02-25T18:54:39.130Z,1361818479.130 [SBIT](INFO): Initialize SBIT Component.
2013-02-25T18:54:39.130Z,1361818479.130 [SBIT](IMPORTANT): Tethys CM Info:
$Rev: 10150
2013-02-25T18:54:39.131Z,1361818479.131 [IBIT](INFO): Initialize IBIT Component.
2013-02-25T18:54:39.132Z,1361818479.132 [CBIT](DEBUG): Initialize CBIT Component.
2013-02-25T18:54:39.132Z,1361818479.132 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2013-02-25T18:54:39.143Z,1361818479.143 [AsyncPiEstimator](INFO): Thread ID is 702
2013-02-25T18:54:39.143Z,1361818479.143 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator.
2013-02-25T18:54:39.157Z,1361818479.157 [DVL_micro](INFO): Thread ID is 703
2013-02-25T18:54:39.163Z,1361818479.163 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2013-02-25T18:54:39.164Z,1361818479.164 [NavChart](DEBUG): Initialize NavChart Derivation.
2013-02-25T18:54:39.164Z,1361818479.164 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2013-02-25T18:54:39.165Z,1361818479.165 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2013-02-25T18:54:39.165Z,1361818479.165 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2013-02-25T18:54:39.167Z,1361818479.167 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2013-02-25T18:54:39.167Z,1361818479.167 [Navigation](DEBUG): Initializing Navigation.
2013-02-25T18:54:39.168Z,1361818479.168 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2013-02-25T18:54:39.169Z,1361818479.169 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2013-02-25T18:54:39.170Z,1361818479.170 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2013-02-25T18:54:39.171Z,1361818479.171 [LoopControl](DEBUG): Initialize LoopControlComponent.
2013-02-25T18:54:39.177Z,1361818479.177 [DVL_micro](INFO): Initializing
2013-02-25T18:54:39.177Z,1361818479.177 [DVL_micro](INFO): start:Powering up
2013-02-25T18:54:39.178Z,1361818479.178 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-02-25T18:54:39.179Z,1361818479.179 [DVL_micro](INFO): Cycling power to configure device.
2013-02-25T18:54:39.187Z,1361818479.187 [WetLabsBB2FL](INFO): Thread ID is 704
2013-02-25T18:54:39.187Z,1361818479.187 [WetLabsBB2FL](INFO): Powering down
2013-02-25T18:54:39.227Z,1361818479.227 [NavChartDb](INFO): Thread ID is 706
2013-02-25T18:54:39.229Z,1361818479.229 [NavChartDb](FAULT): Change detected in ENC collection. Wiping NavChart Directory
2013-02-25T18:54:39.233Z,1361818479.233 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2013-02-25T18:54:39.235Z,1361818479.235 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA50M.000
2013-02-25T18:54:39.236Z,1361818479.237 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US2WC11M.000
2013-02-25T18:54:39.238Z,1361818479.238 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US1WC07M.000
2013-02-25T18:54:39.240Z,1361818479.240 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US3CA52M.000
2013-02-25T18:54:39.242Z,1361818479.242 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA61M.000
2013-02-25T18:54:39.243Z,1361818479.243 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA83M.000
2013-02-25T18:54:39.245Z,1361818479.245 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA62M.000
2013-02-25T18:54:39.247Z,1361818479.247 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4CA60M.000
2013-02-25T18:54:39.434Z,1361818479.434 [NavChartDb](INFO): Setup scan of Resources/US5CA62M.000
2013-02-25T18:54:41.251Z,1361818481.251 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2013-02-25T18:54:41.262Z,1361818481.263 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-02-25T18:54:41.263Z,1361818481.263 [DVL_micro](INFO): Querying output modes
2013-02-25T18:54:41.263Z,1361818481.263 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-02-25T18:54:41.274Z,1361818481.274 [DVL_micro](DEBUG): cmdResponse: 01
2013-02-25T18:54:41.275Z,1361818481.274 [DVL_micro](INFO): NQ1 output enabled
2013-02-25T18:54:41.275Z,1361818481.275 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-02-25T18:54:41.286Z,1361818481.286 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 
2013-02-25T18:54:41.291Z,1361818481.291 [DVL_micro](INFO): pause:Powering down
2013-02-25T18:54:41.294Z,1361818481.294 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2013-02-25T18:54:41.304Z,1361818481.304 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2013-02-25T18:54:41.339Z,1361818481.339 [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-02-25T18:54:41.340Z,1361818481.340 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2013-02-25T18:54:41.377Z,1361818481.377 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2013-02-25T18:54:41.380Z,1361818481.380 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2013-02-25T18:54:41.383Z,1361818481.383 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-02-25T18:54:41.391Z,1361818481.391 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2013-02-25T18:54:41.394Z,1361818481.394 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-02-25T18:54:41.401Z,1361818481.401 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2013-02-25T18:54:41.430Z,1361818481.430 [Default:D.SetSpeed](DEBUG): Construct.
2013-02-25T18:54:41.433Z,1361818481.433 [Default:E.GoToSurface](DEBUG): Construct GoToSurface.
2013-02-25T18:54:41.450Z,1361818481.450 [Default:F.Wait](DEBUG): Construct Wait.
2013-02-25T18:54:41.454Z,1361818481.454 [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-02-25T18:54:41.461Z,1361818481.461 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,NAL9602,Onboard,Radio_Freewave,Aanderaa_O2,ISUS,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,
2013-02-25T18:54:41.484Z,1361818481.484 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-02-25T18:54:41.602Z,1361818481.602 [Radio_Freewave](INFO): Powering up
2013-02-25T18:54:41.863Z,1361818481.863 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2013-02-25T18:54:41.864Z,1361818481.864 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2013-02-25T18:54:41.871Z,1361818481.871 [ElevatorServo](DEBUG): Initializing EZServoServo.
2013-02-25T18:54:41.872Z,1361818481.872 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2013-02-25T18:54:41.878Z,1361818481.878 [MassServo](DEBUG): Initializing EZServoServo.
2013-02-25T18:54:41.879Z,1361818481.879 [MassServo](DEBUG): Initializing MassServo.
2013-02-25T18:54:41.884Z,1361818481.884 [RudderServo](DEBUG): Initializing EZServoServo.
2013-02-25T18:54:41.885Z,1361818481.885 [RudderServo](DEBUG): Initializing RudderServo.
2013-02-25T18:54:41.891Z,1361818481.891 [ThrusterServo](DEBUG): Initializing EZServoServo.
2013-02-25T18:54:41.892Z,1361818481.892 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2013-02-25T18:54:48.847Z,1361818488.847 [CommandLine](IMPORTANT): got command maintain control VerticalControl.buoyancyAction 100.000000 cubic_centimeter
2013-02-25T18:54:48.848Z,1361818488.848 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.buoyancyAction" handled in the control thread.
2013-02-25T18:54:48.947Z,1361818488.947 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,NAL9602,Onboard,Radio_Freewave,Aanderaa_O2,ISUS,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.buoyancyAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,
2013-02-25T18:54:54.479Z,1361818494.479 [CommandLine](IMPORTANT): got command report mod platform_buoyancy_position
2013-02-25T18:54:54.544Z,1361818494.544 [SBIT](IMPORTANT): Beginning Startup BIT
2013-02-25T18:54:54.547Z,1361818494.546 [CBIT](IMPORTANT): Beginning GF scan
2013-02-25T18:54:54.552Z,1361818494.552 [Reporter](INFO): platform_buoyancy_position 604.071363 cc
2013-02-25T18:54:55.005Z,1361818495.005 [Reporter](INFO): platform_buoyancy_position 602.056796 cc
2013-02-25T18:54:55.368Z,1361818495.368 [Reporter](INFO): platform_buoyancy_position 601.922569 cc
2013-02-25T18:54:55.779Z,1361818495.779 [Reporter](INFO): platform_buoyancy_position 599.773717 cc
2013-02-25T18:54:56.236Z,1361818496.236 [Reporter](INFO): platform_buoyancy_position 597.759208 cc
2013-02-25T18:54:57.119Z,1361818497.119 [Reporter](INFO): platform_buoyancy_position 595.476129 cc
2013-02-25T18:54:57.447Z,1361818497.447 [Reporter](INFO): platform_buoyancy_position 593.864475 cc
2013-02-25T18:54:57.895Z,1361818497.895 [Reporter](INFO): platform_buoyancy_position 593.327335 cc
2013-02-25T18:54:58.340Z,1361818498.340 [Reporter](INFO): platform_buoyancy_position 591.312826 cc
2013-02-25T18:54:58.643Z,1361818498.643 [Reporter](INFO): platform_buoyancy_position 591.044256 cc
2013-02-25T18:54:59.079Z,1361818499.079 [Reporter](INFO): platform_buoyancy_position 589.163974 cc
2013-02-25T18:54:59.475Z,1361818499.476 [Reporter](INFO): platform_buoyancy_position 588.895462 cc
2013-02-25T18:54:59.951Z,1361818499.951 [Reporter](INFO): platform_buoyancy_position 586.880895 cc
2013-02-25T18:55:00.259Z,1361818500.260 [Reporter](INFO): platform_buoyancy_position 585.000729 cc
2013-02-25T18:55:00.627Z,1361818500.627 [Reporter](INFO): platform_buoyancy_position 584.732101 cc
2013-02-25T18:55:01.027Z,1361818501.027 [Reporter](INFO): platform_buoyancy_position 582.851935 cc
2013-02-25T18:55:01.427Z,1361818501.427 [Reporter](INFO): platform_buoyancy_position 580.568856 cc
2013-02-25T18:55:01.888Z,1361818501.888 [Reporter](INFO): platform_buoyancy_position 580.165884 cc
2013-02-25T18:55:02.227Z,1361818502.227 [Reporter](INFO): platform_buoyancy_position 578.285719 cc
2013-02-25T18:55:02.619Z,1361818502.619 [Reporter](INFO): platform_buoyancy_position 576.674123 cc
2013-02-25T18:55:03.104Z,1361818503.104 [Reporter](INFO): platform_buoyancy_position 576.271268 cc
2013-02-25T18:55:03.417Z,1361818503.417 [Reporter](INFO): platform_buoyancy_position 574.122416 cc
2013-02-25T18:55:03.784Z,1361818503.784 [Reporter](INFO): platform_buoyancy_position 573.988073 cc
2013-02-25T18:55:04.184Z,1361818504.184 [Reporter](INFO): platform_buoyancy_position 571.839279 cc
2013-02-25T18:55:04.584Z,1361818504.584 [Reporter](INFO): platform_buoyancy_position 569.959113 cc
2013-02-25T18:55:04.992Z,1361818504.992 [Reporter](INFO): platform_buoyancy_position 569.690543 cc
2013-02-25T18:55:05.384Z,1361818505.384 [Reporter](INFO): platform_buoyancy_position 567.676034 cc
2013-02-25T18:55:05.784Z,1361818505.784 [Reporter](INFO): platform_buoyancy_position 567.541749 cc
2013-02-25T18:55:06.189Z,1361818506.189 [Reporter](INFO): platform_buoyancy_position 565.258611 cc
2013-02-25T18:55:06.620Z,1361818506.620 [Reporter](INFO): platform_buoyancy_position 563.378446 cc
2013-02-25T18:55:07.052Z,1361818507.052 [Reporter](INFO): platform_buoyancy_position 563.244161 cc
2013-02-25T18:55:07.384Z,1361818507.384 [Reporter](INFO): platform_buoyancy_position 561.095309 cc
2013-02-25T18:55:07.784Z,1361818507.784 [Reporter](INFO): platform_buoyancy_position 559.215143 cc
2013-02-25T18:55:08.189Z,1361818508.188 [Reporter](INFO): platform_buoyancy_position 558.946515 cc
2013-02-25T18:55:08.586Z,1361818508.586 [Reporter](INFO): platform_buoyancy_position 556.932006 cc
2013-02-25T18:55:09.427Z,1361818509.427 [Reporter](INFO): platform_buoyancy_position 554.783212 cc
2013-02-25T18:55:10.541Z,1361818510.541 [Reporter](INFO): platform_buoyancy_position 552.634418 cc
2013-02-25T18:55:10.871Z,1361818510.871 [Reporter](INFO): platform_buoyancy_position 550.351338 cc
2013-02-25T18:55:11.267Z,1361818511.267 [Reporter](INFO): platform_buoyancy_position 548.202486 cc
2013-02-25T18:55:12.111Z,1361818512.111 [Reporter](INFO): platform_buoyancy_position 546.053692 cc
2013-02-25T18:55:12.486Z,1361818512.486 [Reporter](INFO): platform_buoyancy_position 544.576440 cc
2013-02-25T18:55:12.875Z,1361818512.875 [Reporter](INFO): platform_buoyancy_position 543.904898 cc
2013-02-25T18:55:13.319Z,1361818513.319 [Reporter](INFO): platform_buoyancy_position 541.890447 cc
2013-02-25T18:55:13.683Z,1361818513.683 [Reporter](INFO): platform_buoyancy_position 541.621819 cc
2013-02-25T18:55:14.067Z,1361818514.067 [Reporter](INFO): platform_buoyancy_position 539.607310 cc
2013-02-25T18:55:14.467Z,1361818514.467 [Reporter](INFO): platform_buoyancy_position 537.727086 cc
2013-02-25T18:55:14.871Z,1361818514.871 [Reporter](INFO): platform_buoyancy_position 537.592859 cc
2013-02-25T18:55:15.351Z,1361818515.351 [Reporter](INFO): platform_buoyancy_position 535.444007 cc
2013-02-25T18:55:15.712Z,1361818515.712 [Reporter](INFO): platform_buoyancy_position 534.101040 cc
2013-02-25T18:55:16.159Z,1361818516.159 [Reporter](INFO): platform_buoyancy_position 533.160928 cc
2013-02-25T18:55:16.468Z,1361818516.467 [Reporter](INFO): platform_buoyancy_position 531.012134 cc
2013-02-25T18:55:17.296Z,1361818517.296 [Reporter](INFO): platform_buoyancy_position 528.997625 cc
2013-02-25T18:55:17.628Z,1361818517.628 [Reporter](INFO): platform_buoyancy_position 527.117460 cc
2013-02-25T18:55:18.043Z,1361818518.043 [Reporter](INFO): platform_buoyancy_position 526.714546 cc
2013-02-25T18:55:18.443Z,1361818518.443 [Reporter](INFO): platform_buoyancy_position 524.834264 cc
2013-02-25T18:55:18.843Z,1361818518.843 [Reporter](INFO): platform_buoyancy_position 524.565752 cc
2013-02-25T18:55:19.243Z,1361818519.243 [Reporter](INFO): platform_buoyancy_position 522.551185 cc
2013-02-25T18:55:19.667Z,1361818519.667 [Reporter](INFO): platform_buoyancy_position 520.402391 cc
2013-02-25T18:55:20.443Z,1361818520.443 [Reporter](INFO): platform_buoyancy_position 518.253597 cc
2013-02-25T18:55:20.855Z,1361818520.855 [Reporter](INFO): platform_buoyancy_position 518.119312 cc
2013-02-25T18:55:21.243Z,1361818521.243 [CBIT](IMPORTANT): No ground fault detected
2013-02-25T18:55:21.244Z,1361818521.244 [Reporter](INFO): platform_buoyancy_position 515.970518 cc
2013-02-25T18:55:21.640Z,1361818521.640 [Reporter](INFO): platform_buoyancy_position 513.956009 cc
2013-02-25T18:55:22.096Z,1361818522.096 [Reporter](INFO): platform_buoyancy_position 513.821724 cc
2013-02-25T18:55:22.443Z,1361818522.443 [Reporter](INFO): platform_buoyancy_position 511.807215 cc
2013-02-25T18:55:22.887Z,1361818522.887 [Reporter](INFO): platform_buoyancy_position 509.792764 cc
2013-02-25T18:55:23.240Z,1361818523.240 [Reporter](INFO): platform_buoyancy_position 509.524136 cc
2013-02-25T18:55:23.643Z,1361818523.643 [Reporter](INFO): platform_buoyancy_position 507.509685 cc
2013-02-25T18:55:24.062Z,1361818524.062 [Reporter](INFO): platform_buoyancy_position 507.375342 cc
2013-02-25T18:55:24.511Z,1361818524.511 [Reporter](INFO): platform_buoyancy_position 505.226548 cc
2013-02-25T18:55:24.796Z,1361818524.796 [Reporter](INFO): platform_buoyancy_position 503.212039 cc
2013-02-25T18:55:25.596Z,1361818525.596 [Reporter](INFO): platform_buoyancy_position 501.197530 cc
2013-02-25T18:55:26.044Z,1361818526.044 [Reporter](INFO): platform_buoyancy_position 500.794675 cc
2013-02-25T18:55:26.392Z,1361818526.392 [Reporter](INFO): platform_buoyancy_position 498.914451 cc
2013-02-25T18:55:26.796Z,1361818526.796 [Reporter](INFO): platform_buoyancy_position 496.765657 cc
2013-02-25T18:55:27.588Z,1361818527.588 [Reporter](INFO): platform_buoyancy_position 494.616863 cc
2013-02-25T18:55:27.996Z,1361818527.996 [Reporter](INFO): platform_buoyancy_position 494.482578 cc
2013-02-25T18:55:28.396Z,1361818528.396 [Reporter](INFO): platform_buoyancy_position 492.333784 cc
2013-02-25T18:55:28.792Z,1361818528.792 [Reporter](INFO): platform_buoyancy_position 490.184990 cc
2013-02-25T18:55:29.596Z,1361818529.596 [Reporter](INFO): platform_buoyancy_position 488.170452 cc
2013-02-25T18:55:29.992Z,1361818529.992 [Reporter](INFO): platform_buoyancy_position 487.364654 cc
2013-02-25T18:55:30.396Z,1361818530.396 [Reporter](INFO): platform_buoyancy_position 486.021629 cc
2013-02-25T18:55:30.796Z,1361818530.796 [Reporter](INFO): platform_buoyancy_position 483.738550 cc
2013-02-25T18:55:31.596Z,1361818531.596 [Reporter](INFO): platform_buoyancy_position 481.724041 cc
2013-02-25T18:55:31.992Z,1361818531.992 [Reporter](INFO): platform_buoyancy_position 479.709561 cc
2013-02-25T18:55:32.487Z,1361818532.487 [Reporter](INFO): platform_buoyancy_position 479.440961 cc
2013-02-25T18:55:32.796Z,1361818532.796 [Reporter](INFO): platform_buoyancy_position 477.426423 cc
2013-02-25T18:55:33.588Z,1361818533.588 [Reporter](INFO): platform_buoyancy_position 475.277629 cc
2013-02-25T18:55:33.996Z,1361818533.996 [Reporter](INFO): platform_buoyancy_position 473.128865 cc
2013-02-25T18:55:34.396Z,1361818534.396 [Reporter](INFO): platform_buoyancy_position 472.994550 cc
2013-02-25T18:55:34.792Z,1361818534.792 [Reporter](INFO): platform_buoyancy_position 470.980071 cc
2013-02-25T18:55:35.196Z,1361818535.196 [Reporter](INFO): platform_buoyancy_position 470.845727 cc
2013-02-25T18:55:35.610Z,1361818535.611 [Reporter](INFO): platform_buoyancy_position 468.696933 cc
2013-02-25T18:55:36.048Z,1361818536.048 [Reporter](INFO): platform_buoyancy_position 466.682453 cc
2013-02-25T18:55:36.563Z,1361818536.563 [Reporter](INFO): platform_buoyancy_position 466.548139 cc
2013-02-25T18:55:37.431Z,1361818537.431 [Reporter](INFO): platform_buoyancy_position 464.399316 cc
2013-02-25T18:55:37.813Z,1361818537.813 [Reporter](INFO): platform_buoyancy_position 462.384865 cc
2013-02-25T18:55:38.159Z,1361818538.159 [Reporter](INFO): platform_buoyancy_position 460.101728 cc
2013-02-25T18:55:38.559Z,1361818538.559 [Reporter](INFO): platform_buoyancy_position 459.833158 cc
2013-02-25T18:55:38.970Z,1361818538.970 [Reporter](INFO): platform_buoyancy_position 457.952963 cc
2013-02-25T18:55:39.467Z,1361818539.467 [Reporter](INFO): platform_buoyancy_position 455.938454 cc
2013-02-25T18:55:40.255Z,1361818540.255 [Reporter](INFO): platform_buoyancy_position 453.655375 cc
2013-02-25T18:55:40.655Z,1361818540.655 [Reporter](INFO): platform_buoyancy_position 451.775122 cc
2013-02-25T18:55:41.055Z,1361818541.055 [Reporter](INFO): platform_buoyancy_position 451.506552 cc
2013-02-25T18:55:41.455Z,1361818541.455 [Reporter](INFO): platform_buoyancy_position 449.492043 cc
2013-02-25T18:55:42.356Z,1361818542.356 [Reporter](INFO): platform_buoyancy_position 447.343220 cc
2013-02-25T18:55:42.655Z,1361818542.655 [Reporter](INFO): platform_buoyancy_position 445.194426 cc
2013-02-25T18:55:43.055Z,1361818543.055 [Reporter](INFO): platform_buoyancy_position 445.060141 cc
2013-02-25T18:55:43.455Z,1361818543.455 [Reporter](INFO): platform_buoyancy_position 443.045632 cc
2013-02-25T18:55:43.855Z,1361818543.855 [Reporter](INFO): platform_buoyancy_position 441.299781 cc
2013-02-25T18:55:44.255Z,1361818544.255 [Reporter](INFO): platform_buoyancy_position 440.762553 cc
2013-02-25T18:55:44.655Z,1361818544.655 [Reporter](INFO): platform_buoyancy_position 438.613730 cc
2013-02-25T18:55:45.055Z,1361818545.055 [Reporter](INFO): platform_buoyancy_position 438.479474 cc
2013-02-25T18:55:45.488Z,1361818545.488 [Reporter](INFO): platform_buoyancy_position 436.464936 cc
2013-02-25T18:55:45.940Z,1361818545.940 [Reporter](INFO): platform_buoyancy_position 434.316142 cc
2013-02-25T18:55:46.217Z,1361818546.217 [Reporter](INFO): platform_buoyancy_position 434.450456 cc
2013-02-25T18:55:46.619Z,1361818546.619 [Reporter](INFO): platform_buoyancy_position 432.301662 cc
2013-02-25T18:55:47.460Z,1361818547.460 [Reporter](INFO): platform_buoyancy_position 430.018525 cc
2013-02-25T18:55:47.820Z,1361818547.820 [Reporter](INFO): platform_buoyancy_position 428.004045 cc
2013-02-25T18:55:48.213Z,1361818548.213 [SBIT](IMPORTANT): SBIT PASSED
2013-02-25T18:55:48.216Z,1361818548.216 [Reporter](INFO): platform_buoyancy_position 427.869731 cc
2013-02-25T18:55:48.613Z,1361818548.613 [MissionManager](IMPORTANT): Started mission Startup
2013-02-25T18:55:48.613Z,1361818548.613 [Startup] Running Loop=1
2013-02-25T18:55:48.613Z,1361818548.613 [Startup](INFO): Aggregate::initialize Startup
2013-02-25T18:55:48.613Z,1361818548.613 [Startup:A.GoToSurface] Running Loop=1
2013-02-25T18:55:48.613Z,1361818548.613 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-02-25T18:55:48.619Z,1361818548.619 [Startup:StartupSatComms] Running Loop=1
2013-02-25T18:55:48.619Z,1361818548.619 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2013-02-25T18:55:48.619Z,1361818548.619 [Startup:StartupSatComms:A] Running Loop=1
2013-02-25T18:55:48.656Z,1361818548.656 [Reporter](INFO): platform_buoyancy_position 425.855251 cc
2013-02-25T18:55:48.970Z,1361818548.970 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2013-02-25T18:55:49.022Z,1361818549.022 [Reporter](INFO): platform_buoyancy_position 425.318023 cc
2013-02-25T18:55:49.417Z,1361818549.417 [Reporter](INFO): platform_buoyancy_position 423.706457 cc
2013-02-25T18:55:49.858Z,1361818549.858 [Reporter](INFO): platform_buoyancy_position 421.557634 cc
2013-02-25T18:55:50.803Z,1361818550.803 [Reporter](INFO): platform_buoyancy_position 421.691919 cc
2013-02-25T18:55:51.086Z,1361818551.086 [Reporter](INFO): platform_buoyancy_position 417.528645 cc
2013-02-25T18:55:51.485Z,1361818551.485 [Reporter](INFO): platform_buoyancy_position 417.125761 cc
2013-02-25T18:55:51.917Z,1361818551.917 [Reporter](INFO): platform_buoyancy_position 415.111223 cc
2013-02-25T18:55:52.743Z,1361818552.743 [Reporter](INFO): platform_buoyancy_position 412.828143 cc
2013-02-25T18:55:53.087Z,1361818553.087 [Reporter](INFO): platform_buoyancy_position 410.813635 cc
2013-02-25T18:55:53.485Z,1361818553.485 [Reporter](INFO): platform_buoyancy_position 410.679349 cc
2013-02-25T18:55:53.883Z,1361818553.883 [Reporter](INFO): platform_buoyancy_position 408.664870 cc
2013-02-25T18:55:54.287Z,1361818554.287 [Reporter](INFO): platform_buoyancy_position 406.516046 cc
2013-02-25T18:55:55.116Z,1361818555.116 [Reporter](INFO): platform_buoyancy_position 404.367252 cc
2013-02-25T18:55:55.487Z,1361818555.487 [Reporter](INFO): platform_buoyancy_position 404.232938 cc
2013-02-25T18:55:55.883Z,1361818555.883 [Reporter](INFO): platform_buoyancy_position 402.084144 cc
2013-02-25T18:55:56.282Z,1361818556.283 [Reporter](INFO): platform_buoyancy_position 400.338235 cc
2013-02-25T18:55:56.687Z,1361818556.687 [Reporter](INFO): platform_buoyancy_position 399.935321 cc
2013-02-25T18:55:57.083Z,1361818557.083 [Reporter](INFO): platform_buoyancy_position 397.920841 cc
2013-02-25T18:55:57.485Z,1361818557.485 [Reporter](INFO): platform_buoyancy_position 397.517957 cc
2013-02-25T18:55:57.943Z,1361818557.943 [Reporter](INFO): platform_buoyancy_position 395.637733 cc
2013-02-25T18:55:58.307Z,1361818558.307 [Reporter](INFO): platform_buoyancy_position 393.623224 cc
2013-02-25T18:55:59.087Z,1361818559.087 [Reporter](INFO): platform_buoyancy_position 391.340145 cc
2013-02-25T18:55:59.883Z,1361818559.883 [Reporter](INFO): platform_buoyancy_position 389.325665 cc
2013-02-25T18:56:00.287Z,1361818560.287 [Reporter](INFO): platform_buoyancy_position 387.042528 cc
2013-02-25T18:56:01.083Z,1361818561.083 [Reporter](INFO): platform_buoyancy_position 384.893734 cc
2013-02-25T18:56:01.516Z,1361818561.516 [Reporter](INFO): platform_buoyancy_position 383.282139 cc
2013-02-25T18:56:01.887Z,1361818561.887 [Reporter](INFO): platform_buoyancy_position 382.744940 cc
2013-02-25T18:56:02.287Z,1361818562.287 [Reporter](INFO): platform_buoyancy_position 380.730431 cc
2013-02-25T18:56:02.747Z,1361818562.747 [Reporter](INFO): platform_buoyancy_position 380.327547 cc
2013-02-25T18:56:03.083Z,1361818563.083 [Reporter](INFO): platform_buoyancy_position 378.715951 cc
2013-02-25T18:56:03.485Z,1361818563.485 [Reporter](INFO): platform_buoyancy_position 376.298558 cc
2013-02-25T18:56:03.887Z,1361818563.887 [Reporter](INFO): platform_buoyancy_position 376.432843 cc
2013-02-25T18:56:04.283Z,1361818564.283 [Reporter](INFO): platform_buoyancy_position 374.284020 cc
2013-02-25T18:56:04.715Z,1361818564.715 [Reporter](INFO): platform_buoyancy_position 373.881136 cc
2013-02-25T18:56:05.087Z,1361818565.087 [Reporter](INFO): platform_buoyancy_position 372.135255 cc
2013-02-25T18:56:05.485Z,1361818565.485 [Reporter](INFO): platform_buoyancy_position 369.986461 cc
2013-02-25T18:56:05.966Z,1361818565.966 [Reporter](INFO): platform_buoyancy_position 369.852147 cc
2013-02-25T18:56:06.247Z,1361818566.247 [Reporter](INFO): platform_buoyancy_position 367.837638 cc
2013-02-25T18:56:06.647Z,1361818566.647 [Reporter](INFO): platform_buoyancy_position 365.823158 cc
2013-02-25T18:56:07.047Z,1361818567.047 [Reporter](INFO): platform_buoyancy_position 365.688844 cc
2013-02-25T18:56:07.447Z,1361818567.447 [Reporter](INFO): platform_buoyancy_position 363.405736 cc
2013-02-25T18:56:08.248Z,1361818568.247 [Reporter](INFO): platform_buoyancy_position 361.391227 cc
2013-02-25T18:56:08.647Z,1361818568.647 [Reporter](INFO): platform_buoyancy_position 360.719714 cc
2013-02-25T18:56:09.047Z,1361818569.047 [Reporter](INFO): platform_buoyancy_position 359.242433 cc
2013-02-25T18:56:09.447Z,1361818569.447 [Reporter](INFO): platform_buoyancy_position 357.093639 cc
2013-02-25T18:56:09.851Z,1361818569.851 [Reporter](INFO): platform_buoyancy_position 356.825039 cc
2013-02-25T18:56:10.243Z,1361818570.243 [Reporter](INFO): platform_buoyancy_position 355.079130 cc
2013-02-25T18:56:10.647Z,1361818570.648 [Reporter](INFO): platform_buoyancy_position 352.796051 cc
2013-02-25T18:56:11.071Z,1361818571.071 [Reporter](INFO): platform_buoyancy_position 352.661737 cc
2013-02-25T18:56:11.443Z,1361818571.443 [Reporter](INFO): platform_buoyancy_position 350.647257 cc
2013-02-25T18:56:11.848Z,1361818571.848 [Reporter](INFO): platform_buoyancy_position 350.512943 cc
2013-02-25T18:56:12.248Z,1361818572.248 [Reporter](INFO): platform_buoyancy_position 348.498434 cc
2013-02-25T18:56:12.648Z,1361818572.648 [Reporter](INFO): platform_buoyancy_position 346.215325 cc
2013-02-25T18:56:13.088Z,1361818573.088 [Reporter](INFO): platform_buoyancy_position 346.081011 cc
2013-02-25T18:56:13.448Z,1361818573.448 [Reporter](INFO): platform_buoyancy_position 344.335131 cc
2013-02-25T18:56:13.848Z,1361818573.848 [Reporter](INFO): platform_buoyancy_position 344.066531 cc
2013-02-25T18:56:14.272Z,1361818574.272 [Reporter](INFO): platform_buoyancy_position 341.917737 cc
2013-02-25T18:56:14.647Z,1361818574.647 [Reporter](INFO): platform_buoyancy_position 339.768943 cc
2013-02-25T18:56:15.447Z,1361818575.447 [Reporter](INFO): platform_buoyancy_position 337.754434 cc
2013-02-25T18:56:15.847Z,1361818575.847 [Reporter](INFO): platform_buoyancy_position 335.605611 cc
2013-02-25T18:56:16.243Z,1361818576.243 [Reporter](INFO): platform_buoyancy_position 335.471355 cc
2013-02-25T18:56:16.647Z,1361818576.648 [Reporter](INFO): platform_buoyancy_position 333.322532 cc
2013-02-25T18:56:17.047Z,1361818577.047 [Reporter](INFO): platform_buoyancy_position 333.188218 cc
2013-02-25T18:56:17.472Z,1361818577.472 [Reporter](INFO): platform_buoyancy_position 331.173738 cc
2013-02-25T18:56:17.848Z,1361818577.848 [Reporter](INFO): platform_buoyancy_position 329.159229 cc
2013-02-25T18:56:18.288Z,1361818578.288 [Reporter](INFO): platform_buoyancy_position 329.293543 cc
2013-02-25T18:56:18.643Z,1361818578.643 [Reporter](INFO): platform_buoyancy_position 327.010435 cc
2013-02-25T18:56:19.047Z,1361818579.047 [Reporter](INFO): platform_buoyancy_position 326.876121 cc
2013-02-25T18:56:19.447Z,1361818579.447 [Reporter](INFO): platform_buoyancy_position 324.861641 cc
2013-02-25T18:56:19.847Z,1361818579.847 [Reporter](INFO): platform_buoyancy_position 322.981447 cc
2013-02-25T18:56:20.247Z,1361818580.247 [Reporter](INFO): platform_buoyancy_position 322.309934 cc
2013-02-25T18:56:20.667Z,1361818580.667 [Reporter](INFO): platform_buoyancy_position 320.564024 cc
2013-02-25T18:56:21.047Z,1361818581.047 [Reporter](INFO): platform_buoyancy_position 318.415230 cc
2013-02-25T18:56:21.447Z,1361818581.447 [Reporter](INFO): platform_buoyancy_position 318.280945 cc
2013-02-25T18:56:21.847Z,1361818581.847 [Reporter](INFO): platform_buoyancy_position 316.266436 cc
2013-02-25T18:56:22.243Z,1361818582.243 [Reporter](INFO): platform_buoyancy_position 316.132151 cc
2013-02-25T18:56:22.647Z,1361818582.648 [Reporter](INFO): platform_buoyancy_position 314.117642 cc
2013-02-25T18:56:23.047Z,1361818583.047 [Reporter](INFO): platform_buoyancy_position 313.983328 cc
2013-02-25T18:56:23.488Z,1361818583.488 [Reporter](INFO): platform_buoyancy_position 311.968848 cc
2013-02-25T18:56:23.872Z,1361818583.872 [Reporter](INFO): platform_buoyancy_position 310.357253 cc
2013-02-25T18:56:24.247Z,1361818584.247 [Reporter](INFO): platform_buoyancy_position 309.820025 cc
2013-02-25T18:56:24.647Z,1361818584.647 [Reporter](INFO): platform_buoyancy_position 307.536917 cc
2013-02-25T18:56:25.047Z,1361818585.047 [Reporter](INFO): platform_buoyancy_position 305.522437 cc
2013-02-25T18:56:25.443Z,1361818585.443 [Reporter](INFO): platform_buoyancy_position 305.388123 cc
2013-02-25T18:56:25.847Z,1361818585.847 [Reporter](INFO): platform_buoyancy_position 303.239329 cc
2013-02-25T18:56:26.247Z,1361818586.247 [Reporter](INFO): platform_buoyancy_position 302.970730 cc
2013-02-25T18:56:26.647Z,1361818586.647 [Reporter](INFO): platform_buoyancy_position 301.224820 cc
2013-02-25T18:56:27.071Z,1361818587.071 [Reporter](INFO): platform_buoyancy_position 299.210340 cc
2013-02-25T18:56:27.447Z,1361818587.447 [Reporter](INFO): platform_buoyancy_position 299.076026 cc
2013-02-25T18:56:27.847Z,1361818587.847 [Reporter](INFO): platform_buoyancy_position 296.927232 cc
2013-02-25T18:56:28.284Z,1361818588.284 [Reporter](INFO): platform_buoyancy_position 296.792947 cc
2013-02-25T18:56:28.647Z,1361818588.648 [Reporter](INFO): platform_buoyancy_position 294.778438 cc
2013-02-25T18:56:28.670Z,1361818588.670 [CommandLine](IMPORTANT): got command maintain
2013-02-25T18:56:28.671Z,1361818588.671 [Maintain_VerticalControl.buoyancyAction](INFO): VerticalControl.buoyancyAction maintaining 99.999997 cc
2013-02-25T18:56:29.047Z,1361818589.047 [Reporter](INFO): platform_buoyancy_position 292.763958 cc
2013-02-25T18:56:29.447Z,1361818589.447 [Reporter](INFO): platform_buoyancy_position 292.495330 cc
2013-02-25T18:56:29.848Z,1361818589.848 [Reporter](INFO): platform_buoyancy_position 290.480821 cc
2013-02-25T18:56:30.271Z,1361818590.272 [Reporter](INFO): platform_buoyancy_position 289.943622 cc
2013-02-25T18:56:30.647Z,1361818590.647 [Reporter](INFO): platform_buoyancy_position 288.332027 cc
2013-02-25T18:56:31.047Z,1361818591.047 [Reporter](INFO): platform_buoyancy_position 286.317547 cc
2013-02-25T18:56:31.447Z,1361818591.447 [Reporter](INFO): platform_buoyancy_position 286.048918 cc
2013-02-25T18:56:31.847Z,1361818591.847 [Reporter](INFO): platform_buoyancy_position 283.900154 cc
2013-02-25T18:56:32.247Z,1361818592.247 [Reporter](INFO): platform_buoyancy_position 281.885616 cc
2013-02-25T18:56:32.647Z,1361818592.647 [Reporter](INFO): platform_buoyancy_position 281.751330 cc
2013-02-25T18:56:33.047Z,1361818593.047 [Reporter](INFO): platform_buoyancy_position 279.736851 cc
2013-02-25T18:56:33.520Z,1361818593.520 [Reporter](INFO): platform_buoyancy_position 277.722313 cc
2013-02-25T18:56:33.848Z,1361818593.848 [Reporter](INFO): platform_buoyancy_position 277.453742 cc
2013-02-25T18:56:34.247Z,1361818594.247 [Reporter](INFO): platform_buoyancy_position 275.439234 cc
2013-02-25T18:56:34.647Z,1361818594.648 [Reporter](INFO): platform_buoyancy_position 275.304919 cc
2013-02-25T18:56:35.043Z,1361818595.043 [Reporter](INFO): platform_buoyancy_position 273.290440 cc
2013-02-25T18:56:35.443Z,1361818595.443 [Reporter](INFO): platform_buoyancy_position 272.484613 cc
2013-02-25T18:56:35.848Z,1361818595.848 [Reporter](INFO): platform_buoyancy_position 271.141645 cc
2013-02-25T18:56:36.247Z,1361818596.247 [Reporter](INFO): platform_buoyancy_position 268.992822 cc
2013-02-25T18:56:36.647Z,1361818596.647 [Reporter](INFO): platform_buoyancy_position 266.844028 cc
2013-02-25T18:56:37.443Z,1361818597.443 [Reporter](INFO): platform_buoyancy_position 264.829519 cc
2013-02-25T18:56:37.847Z,1361818597.847 [Reporter](INFO): platform_buoyancy_position 264.560949 cc
2013-02-25T18:56:38.248Z,1361818598.247 [Reporter](INFO): platform_buoyancy_position 262.546411 cc
2013-02-25T18:56:38.688Z,1361818598.688 [Reporter](INFO): platform_buoyancy_position 262.143527 cc
2013-02-25T18:56:39.047Z,1361818599.047 [Reporter](INFO): platform_buoyancy_position 260.397646 cc
2013-02-25T18:56:39.447Z,1361818599.447 [Reporter](INFO): platform_buoyancy_position 258.248852 cc
2013-02-25T18:56:39.867Z,1361818599.867 [Reporter](INFO): platform_buoyancy_position 258.114538 cc
2013-02-25T18:56:40.243Z,1361818600.243 [Reporter](INFO): platform_buoyancy_position 256.100029 cc
2013-02-25T18:56:40.647Z,1361818600.648 [Reporter](INFO): platform_buoyancy_position 255.831430 cc
2013-02-25T18:56:41.047Z,1361818601.047 [Reporter](INFO): platform_buoyancy_position 253.951235 cc
2013-02-25T18:56:41.443Z,1361818601.443 [Reporter](INFO): platform_buoyancy_position 251.802441 cc
2013-02-25T18:56:41.848Z,1361818601.848 [Reporter](INFO): platform_buoyancy_position 251.668127 cc
2013-02-25T18:56:42.247Z,1361818602.247 [Reporter](INFO): platform_buoyancy_position 249.519304 cc
2013-02-25T18:56:42.643Z,1361818602.643 [Reporter](INFO): platform_buoyancy_position 247.504824 cc
2013-02-25T18:56:43.472Z,1361818603.471 [Reporter](INFO): platform_buoyancy_position 245.356030 cc
2013-02-25T18:56:43.887Z,1361818603.888 [Reporter](INFO): platform_buoyancy_position 245.221745 cc
2013-02-25T18:56:44.247Z,1361818604.247 [Reporter](INFO): platform_buoyancy_position 243.072936 cc
2013-02-25T18:56:44.647Z,1361818604.647 [Reporter](INFO): platform_buoyancy_position 241.864225 cc
2013-02-25T18:56:45.047Z,1361818605.047 [Reporter](INFO): platform_buoyancy_position 240.924128 cc
2013-02-25T18:56:45.447Z,1361818605.447 [Reporter](INFO): platform_buoyancy_position 238.909633 cc
2013-02-25T18:56:45.847Z,1361818605.847 [Reporter](INFO): platform_buoyancy_position 238.775334 cc
2013-02-25T18:56:46.247Z,1361818606.247 [Reporter](INFO): platform_buoyancy_position 236.895139 cc
2013-02-25T18:56:46.668Z,1361818606.668 [Reporter](INFO): platform_buoyancy_position 234.612031 cc
2013-02-25T18:56:47.047Z,1361818607.047 [Reporter](INFO): platform_buoyancy_position 234.477717 cc
2013-02-25T18:56:47.443Z,1361818607.443 [Reporter](INFO): platform_buoyancy_position 232.328923 cc
2013-02-25T18:56:48.247Z,1361818608.247 [Reporter](INFO): platform_buoyancy_position 230.180114 cc
2013-02-25T18:56:48.647Z,1361818608.647 [Reporter](INFO): platform_buoyancy_position 228.165620 cc
2013-02-25T18:56:49.048Z,1361818609.048 [Startup:StartupSatComms:A](INFO): Timed out from 2013-02-25T18:55:48.6Z
2013-02-25T18:56:49.048Z,1361818609.048 [Startup:StartupSatComms:A:A_Timeout] Running Loop=1
2013-02-25T18:56:49.048Z,1361818609.048 [Startup:StartupSatComms:A:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:A:A_Timeout
2013-02-25T18:56:49.048Z,1361818609.048 [Startup:StartupSatComms:A:A_Timeout](INFO): Completed Startup:StartupSatComms:A:A_Timeout
2013-02-25T18:56:49.048Z,1361818609.048 [Startup:StartupSatComms:A] Stopped
2013-02-25T18:56:49.048Z,1361818609.048 [Startup:StartupSatComms:B] Running Loop=1
2013-02-25T18:56:49.409Z,1361818609.409 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2013-02-25T18:56:49.447Z,1361818609.447 [Reporter](INFO): platform_buoyancy_position 226.016811 cc
2013-02-25T18:56:49.867Z,1361818609.867 [Reporter](INFO): platform_buoyancy_position 225.748227 cc
2013-02-25T18:56:50.248Z,1361818610.248 [Reporter](INFO): platform_buoyancy_position 223.868046 cc
2013-02-25T18:56:50.647Z,1361818610.647 [Reporter](INFO): platform_buoyancy_position 221.719238 cc
2013-02-25T18:56:51.047Z,1361818611.047 [Reporter](INFO): platform_buoyancy_position 221.584924 cc
2013-02-25T18:56:51.448Z,1361818611.448 [Reporter](INFO): platform_buoyancy_position 219.570429 cc
2013-02-25T18:56:51.848Z,1361818611.848 [Reporter](INFO): platform_buoyancy_position 217.421635 cc
2013-02-25T18:56:52.243Z,1361818612.243 [Reporter](INFO): platform_buoyancy_position 217.287321 cc
2013-02-25T18:56:52.648Z,1361818612.648 [Reporter](INFO): platform_buoyancy_position 215.272827 cc
2013-02-25T18:56:53.072Z,1361818613.072 [Reporter](INFO): platform_buoyancy_position 215.004242 cc
2013-02-25T18:56:53.491Z,1361818613.491 [Reporter](INFO): platform_buoyancy_position 212.989718 cc
2013-02-25T18:56:53.920Z,1361818613.920 [Reporter](INFO): platform_buoyancy_position 211.109524 cc
2013-02-25T18:56:54.247Z,1361818614.247 [Reporter](INFO): platform_buoyancy_position 210.840910 cc
2013-02-25T18:56:54.588Z,1361818614.588 [NAL9602](INFO): Sent 112 bytes from file Logs/20130224T202239/shore0003.lzma
2013-02-25T18:56:54.588Z,1361818614.588 [NAL9602](INFO): Packets left to send: 0
2013-02-25T18:56:54.590Z,1361818614.590 [NAL9602](INFO): Stored copy of sent data in Logs/20130224T202239/shore0003.lzma.parts/0000.sbd
2013-02-25T18:56:54.655Z,1361818614.655 [Reporter](INFO): platform_buoyancy_position 208.826415 cc
2013-02-25T18:56:55.116Z,1361818615.116 [Reporter](INFO): platform_buoyancy_position 207.886318 cc
2013-02-25T18:56:55.447Z,1361818615.447 [Reporter](INFO): platform_buoyancy_position 206.677607 cc
2013-02-25T18:56:55.781Z,1361818615.781 [NAL9602](INFO): Sent 332 bytes from file Logs/20130225T174959/shore0000.lzma
2013-02-25T18:56:55.781Z,1361818615.781 [NAL9602](INFO): Packets left to send: 2
2013-02-25T18:56:55.783Z,1361818615.783 [NAL9602](INFO): Stored copy of sent data in Logs/20130225T174959/shore0000.lzma.parts/0002.sbd
2013-02-25T18:56:55.855Z,1361818615.855 [Reporter](INFO): platform_buoyancy_position 204.528842 cc
2013-02-25T18:56:56.272Z,1361818616.272 [Reporter](INFO): platform_buoyancy_position 204.394528 cc
2013-02-25T18:56:56.647Z,1361818616.647 [Reporter](INFO): platform_buoyancy_position 202.380033 cc
2013-02-25T18:56:56.984Z,1361818616.984 [NAL9602](INFO): Sent 332 bytes from file Logs/20130225T174959/shore0000.lzma
2013-02-25T18:56:56.984Z,1361818616.984 [NAL9602](INFO): Packets left to send: 1
2013-02-25T18:56:56.985Z,1361818616.985 [NAL9602](INFO): Stored copy of sent data in Logs/20130225T174959/shore0000.lzma.parts/0001.sbd
2013-02-25T18:56:57.055Z,1361818617.055 [Reporter](INFO): platform_buoyancy_position 201.977105 cc
2013-02-25T18:56:57.447Z,1361818617.447 [Reporter](INFO): platform_buoyancy_position 200.096925 cc
2013-02-25T18:56:57.847Z,1361818617.847 [Reporter](INFO): platform_buoyancy_position 198.082431 cc
2013-02-25T18:56:58.181Z,1361818618.181 [NAL9602](INFO): Sent 70 bytes from file Logs/20130225T174959/shore0000.lzma
2013-02-25T18:56:58.181Z,1361818618.181 [NAL9602](INFO): Packets left to send: 0
2013-02-25T18:56:58.182Z,1361818618.182 [NAL9602](INFO): Stored copy of sent data in Logs/20130225T174959/shore0000.lzma.parts/0000.sbd
2013-02-25T18:56:58.259Z,1361818618.259 [Reporter](INFO): platform_buoyancy_position 197.948117 cc
2013-02-25T18:56:58.660Z,1361818618.659 [Reporter](INFO): platform_buoyancy_position 195.665038 cc
2013-02-25T18:56:59.092Z,1361818619.092 [Reporter](INFO): platform_buoyancy_position 193.784814 cc
2013-02-25T18:56:59.420Z,1361818619.420 [NAL9602](INFO): Sent 332 bytes from file Logs/20130225T185336/shore0000.lzma
2013-02-25T18:56:59.420Z,1361818619.420 [NAL9602](INFO): Packets left to send: 2
2013-02-25T18:56:59.424Z,1361818619.424 [NAL9602](INFO): Stored copy of sent data in Logs/20130225T185336/shore0000.lzma.parts/0002.sbd
2013-02-25T18:56:59.521Z,1361818619.521 [Reporter](INFO): platform_buoyancy_position 193.650514 cc
2013-02-25T18:56:59.848Z,1361818619.848 [Reporter](INFO): platform_buoyancy_position 191.501735 cc
2013-02-25T18:57:00.588Z,1361818620.588 [NAL9602](INFO): Sent 332 bytes from file Logs/20130225T185336/shore0000.lzma
2013-02-25T18:57:00.588Z,1361818620.588 [NAL9602](INFO): Packets left to send: 1
2013-02-25T18:57:00.589Z,1361818620.589 [NAL9602](INFO): Stored copy of sent data in Logs/20130225T185336/shore0000.lzma.parts/0001.sbd
2013-02-25T18:57:00.655Z,1361818620.655 [Reporter](INFO): platform_buoyancy_position 189.352941 cc
2013-02-25T18:57:01.047Z,1361818621.047 [Reporter](INFO): platform_buoyancy_position 187.607031 cc
2013-02-25T18:57:01.443Z,1361818621.443 [Reporter](INFO): platform_buoyancy_position 187.204132 cc
2013-02-25T18:57:01.784Z,1361818621.784 [NAL9602](INFO): Sent 35 bytes from file Logs/20130225T185336/shore0000.lzma
2013-02-25T18:57:01.784Z,1361818621.784 [NAL9602](INFO): Packets left to send: 0
2013-02-25T18:57:01.785Z,1361818621.785 [NAL9602](INFO): Stored copy of sent data in Logs/20130225T185336/shore0000.lzma.parts/0000.sbd
2013-02-25T18:57:01.856Z,1361818621.856 [Reporter](INFO): platform_buoyancy_position 185.189638 cc
2013-02-25T18:57:02.259Z,1361818622.260 [Reporter](INFO): platform_buoyancy_position 184.518125 cc
2013-02-25T18:57:02.675Z,1361818622.675 [Reporter](INFO): platform_buoyancy_position 183.040829 cc
2013-02-25T18:57:02.984Z,1361818622.984 [NAL9602](INFO): Sent 332 bytes from file Logs/20130225T185430/shore0000.lzma
2013-02-25T18:57:02.984Z,1361818622.984 [NAL9602](INFO): Packets left to send: 2
2013-02-25T18:57:02.985Z,1361818622.986 [NAL9602](INFO): Stored copy of sent data in Logs/20130225T185430/shore0000.lzma.parts/0002.sbd
2013-02-25T18:57:03.055Z,1361818623.055 [Reporter](INFO): platform_buoyancy_position 180.892035 cc
2013-02-25T18:57:03.447Z,1361818623.447 [Reporter](INFO): platform_buoyancy_position 180.757721 cc
2013-02-25T18:57:03.847Z,1361818623.847 [Reporter](INFO): platform_buoyancy_position 178.743227 cc
2013-02-25T18:57:04.232Z,1361818624.232 [NAL9602](INFO): Sent 332 bytes from file Logs/20130225T185430/shore0000.lzma
2013-02-25T18:57:04.233Z,1361818624.233 [NAL9602](INFO): Packets left to send: 1
2013-02-25T18:57:04.234Z,1361818624.234 [NAL9602](INFO): Stored copy of sent data in Logs/20130225T185430/shore0000.lzma.parts/0001.sbd
2013-02-25T18:57:04.288Z,1361818624.288 [Reporter](INFO): platform_buoyancy_position 178.340328 cc
2013-02-25T18:57:04.656Z,1361818624.656 [Reporter](INFO): platform_buoyancy_position 176.325833 cc
2013-02-25T18:57:05.047Z,1361818625.047 [Reporter](INFO): platform_buoyancy_position 174.311310 cc
2013-02-25T18:57:05.384Z,1361818625.384 [NAL9602](INFO): Sent 63 bytes from file Logs/20130225T185430/shore0000.lzma
2013-02-25T18:57:05.384Z,1361818625.384 [NAL9602](INFO): Packets left to send: 0
2013-02-25T18:57:05.385Z,1361818625.385 [NAL9602](INFO): Stored copy of sent data in Logs/20130225T185430/shore0000.lzma.parts/0000.sbd
2013-02-25T18:57:05.455Z,1361818625.455 [Reporter](INFO): platform_buoyancy_position 174.445624 cc
2013-02-25T18:57:05.884Z,1361818625.884 [Reporter](INFO): platform_buoyancy_position 172.162530 cc
2013-02-25T18:57:06.209Z,1361818626.209 [Startup:StartupSatComms:B] Stopped
2013-02-25T18:57:06.210Z,1361818626.210 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2013-02-25T18:57:06.210Z,1361818626.210 [Startup:StartupSatComms] Stopped
2013-02-25T18:57:06.210Z,1361818626.210 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2013-02-25T18:57:06.211Z,1361818626.211 [Startup](INFO): Completed Startup
2013-02-25T18:57:06.211Z,1361818626.211 [Startup] Stopped
2013-02-25T18:57:06.211Z,1361818626.211 [Startup](INFO): Aggregate::uninitialize Startup
2013-02-25T18:57:06.211Z,1361818626.211 [Startup:A.GoToSurface] Stopped
2013-02-25T18:57:06.211Z,1361818626.211 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-02-25T18:57:06.247Z,1361818626.247 [Reporter](INFO): platform_buoyancy_position 170.013736 cc
2013-02-25T18:57:06.596Z,1361818626.596 [MissionManager](IMPORTANT): Started mission Default
2013-02-25T18:57:06.596Z,1361818626.596 [Default] Running Loop=1
2013-02-25T18:57:06.596Z,1361818626.596 [Default](INFO): Aggregate::initialize Default
2013-02-25T18:57:06.596Z,1361818626.596 [Default:D.SetSpeed] Running Loop=1
2013-02-25T18:57:06.597Z,1361818626.597 [Default:D.SetSpeed](DEBUG): Initialize.
2013-02-25T18:57:06.597Z,1361818626.597 [Default:E.GoToSurface] Running Loop=1
2013-02-25T18:57:06.597Z,1361818626.597 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-02-25T18:57:06.597Z,1361818626.597 [Default:Iridium] Running Loop=1
2013-02-25T18:57:06.597Z,1361818626.597 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-02-25T18:57:06.597Z,1361818626.597 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-02-25T18:57:06.597Z,1361818626.597 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-02-25T18:57:06.598Z,1361818626.598 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-02-25T18:57:06.598Z,1361818626.598 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-02-25T18:57:06.613Z,1361818626.613 [Default:E.GoToSurface] Running Loop=1
2013-02-25T18:57:06.619Z,1361818626.619 [Default:D.SetSpeed] Running Loop=1
2013-02-25T18:57:06.641Z,1361818626.641 [Default:Iridium:B.GoToSurface] Stopped
2013-02-25T18:57:06.641Z,1361818626.641 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-02-25T18:57:06.642Z,1361818626.642 [Default:Iridium:Read_Iridium] Running Loop=1
2013-02-25T18:57:06.642Z,1361818626.642 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-02-25T18:57:06.650Z,1361818626.650 [Default:GPS] Running Loop=1
2013-02-25T18:57:06.650Z,1361818626.650 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-02-25T18:57:06.650Z,1361818626.650 [Default:GPS:A.SetSpeed] Running Loop=1
2013-02-25T18:57:06.650Z,1361818626.650 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-02-25T18:57:06.651Z,1361818626.651 [Default:GPS:B.GoToSurface] Running Loop=1
2013-02-25T18:57:06.651Z,1361818626.651 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-02-25T18:57:06.656Z,1361818626.656 [Default:GPS:B.GoToSurface] Stopped
2013-02-25T18:57:06.656Z,1361818626.656 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-02-25T18:57:06.656Z,1361818626.656 [Default:GPS:Read_GPS] Running Loop=1
2013-02-25T18:57:06.656Z,1361818626.656 [Default:GPS:A.SetSpeed] Running Loop=1
2013-02-25T18:57:07.010Z,1361818627.010 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2013-02-25T18:57:07.013Z,1361818627.013 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2013-02-25T18:57:07.052Z,1361818627.052 [Reporter](INFO): platform_buoyancy_position 168.267827 cc
2013-02-25T18:57:07.447Z,1361818627.447 [Reporter](INFO): platform_buoyancy_position 167.864928 cc
2013-02-25T18:57:07.847Z,1361818627.847 [Reporter](INFO): platform_buoyancy_position 165.984704 cc
2013-02-25T18:57:08.248Z,1361818628.247 [Reporter](INFO): platform_buoyancy_position 164.104524 cc
2013-02-25T18:57:08.647Z,1361818628.647 [Reporter](INFO): platform_buoyancy_position 163.433011 cc
2013-02-25T18:57:09.131Z,1361818629.131 [Reporter](INFO): platform_buoyancy_position 161.418517 cc
2013-02-25T18:57:09.447Z,1361818629.447 [Reporter](INFO): platform_buoyancy_position 161.552831 cc
2013-02-25T18:57:09.851Z,1361818629.851 [Reporter](INFO): platform_buoyancy_position 159.269708 cc
2013-02-25T18:57:10.247Z,1361818630.247 [Reporter](INFO): platform_buoyancy_position 157.255214 cc
2013-02-25T18:57:10.647Z,1361818630.648 [Reporter](INFO): platform_buoyancy_position 157.120914 cc
2013-02-25T18:57:11.075Z,1361818631.075 [Reporter](INFO): platform_buoyancy_position 154.972106 cc
2013-02-25T18:57:11.451Z,1361818631.451 [Reporter](INFO): platform_buoyancy_position 154.434907 cc
2013-02-25T18:57:11.851Z,1361818631.851 [Reporter](INFO): platform_buoyancy_position 152.823297 cc
2013-02-25T18:57:12.220Z,1361818632.220 [NAL9602](INFO): Sent 85 bytes from file Logs/20130225T185430/shore0001.lzma
2013-02-25T18:57:12.220Z,1361818632.220 [NAL9602](INFO): Packets left to send: 0
2013-02-25T18:57:12.222Z,1361818632.222 [NAL9602](INFO): Stored copy of sent data in Logs/20130225T185430/shore0001.lzma.parts/0000.sbd
2013-02-25T18:57:12.275Z,1361818632.276 [Reporter](INFO): platform_buoyancy_position 150.943117 cc
2013-02-25T18:57:12.655Z,1361818632.655 [Reporter](INFO): platform_buoyancy_position 150.674532 cc
2013-02-25T18:57:13.010Z,1361818633.010 [Default:Iridium:Read_Iridium] Stopped
2013-02-25T18:57:13.010Z,1361818633.010 [Default:Iridium](INFO): Completed Default:Iridium
2013-02-25T18:57:13.011Z,1361818633.011 [Default:Iridium] Stopped
2013-02-25T18:57:13.011Z,1361818633.011 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-02-25T18:57:13.011Z,1361818633.011 [Default:Iridium:A.SetSpeed] Stopped
2013-02-25T18:57:13.011Z,1361818633.011 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-02-25T18:57:13.011Z,1361818633.011 [Default:F.Wait] Running Loop=1
2013-02-25T18:57:13.011Z,1361818633.011 [Default:F.Wait](DEBUG): Initialize Wait Component.
2013-02-25T18:57:13.047Z,1361818633.047 [Reporter](INFO): platform_buoyancy_position 148.660009 cc
2013-02-25T18:57:13.451Z,1361818633.451 [Reporter](INFO): platform_buoyancy_position 146.779814 cc
2013-02-25T18:57:13.847Z,1361818633.847 [Reporter](INFO): platform_buoyancy_position 146.376929 cc
2013-02-25T18:57:14.288Z,1361818634.288 [Reporter](INFO): platform_buoyancy_position 144.362421 cc
2013-02-25T18:57:14.647Z,1361818634.648 [Reporter](INFO): platform_buoyancy_position 142.213627 cc
2013-02-25T18:57:15.043Z,1361818635.043 [Reporter](INFO): platform_buoyancy_position 142.079312 cc
2013-02-25T18:57:15.448Z,1361818635.448 [Reporter](INFO): platform_buoyancy_position 140.199132 cc
2013-02-25T18:57:15.872Z,1361818635.872 [Reporter](INFO): platform_buoyancy_position 139.930518 cc
2013-02-25T18:57:16.247Z,1361818636.247 [Reporter](INFO): platform_buoyancy_position 138.050324 cc
2013-02-25T18:57:16.651Z,1361818636.651 [Reporter](INFO): platform_buoyancy_position 137.647396 cc
2013-02-25T18:57:17.047Z,1361818637.047 [Reporter](INFO): platform_buoyancy_position 135.632901 cc
2013-02-25T18:57:17.443Z,1361818637.443 [Reporter](INFO): platform_buoyancy_position 133.752721 cc
2013-02-25T18:57:17.851Z,1361818637.851 [Reporter](INFO): platform_buoyancy_position 133.618407 cc
2013-02-25T18:57:18.247Z,1361818638.247 [Reporter](INFO): platform_buoyancy_position 131.469598 cc
2013-02-25T18:57:18.647Z,1361818638.647 [Reporter](INFO): platform_buoyancy_position 131.201014 cc
2013-02-25T18:57:19.072Z,1361818639.072 [Reporter](INFO): platform_buoyancy_position 129.052220 cc
2013-02-25T18:57:19.522Z,1361818639.522 [Reporter](INFO): platform_buoyancy_position 127.172025 cc
2013-02-25T18:57:19.851Z,1361818639.851 [Reporter](INFO): platform_buoyancy_position 126.634826 cc
2013-02-25T18:57:20.248Z,1361818640.247 [Reporter](INFO): platform_buoyancy_position 124.888902 cc
2013-02-25T18:57:20.647Z,1361818640.647 [Reporter](INFO): platform_buoyancy_position 123.277307 cc
2013-02-25T18:57:21.043Z,1361818641.043 [Reporter](INFO): platform_buoyancy_position 122.874408 cc
2013-02-25T18:57:21.447Z,1361818641.447 [Reporter](INFO): platform_buoyancy_position 120.725606 cc
2013-02-25T18:57:21.851Z,1361818641.851 [Reporter](INFO): platform_buoyancy_position 120.457007 cc
2013-02-25T18:57:22.267Z,1361818642.267 [Reporter](INFO): platform_buoyancy_position 118.442513 cc
2013-02-25T18:57:22.647Z,1361818642.648 [Reporter](INFO): platform_buoyancy_position 116.428018 cc
2013-02-25T18:57:23.047Z,1361818643.047 [Reporter](INFO): platform_buoyancy_position 116.293711 cc
2013-02-25T18:57:23.447Z,1361818643.447 [Reporter](INFO): platform_buoyancy_position 114.144903 cc
2013-02-25T18:57:23.851Z,1361818643.852 [Reporter](INFO): platform_buoyancy_position 113.876304 cc
2013-02-25T18:57:24.287Z,1361818644.287 [Reporter](INFO): platform_buoyancy_position 111.996116 cc
2013-02-25T18:57:24.647Z,1361818644.647 [Reporter](INFO): platform_buoyancy_position 110.518806 cc
2013-02-25T18:57:25.048Z,1361818645.048 [Reporter](INFO): platform_buoyancy_position 109.847315 cc
2013-02-25T19:02:13.063Z,1361818933.063 [Default:CallIridium] Running Loop=1
2013-02-25T19:02:13.063Z,1361818933.063 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-02-25T19:02:13.063Z,1361818933.063 [Default:CallIridium:A] Running Loop=1
2013-02-25T19:02:13.065Z,1361818933.065 [Default:CallIridium:A] Stopped
2013-02-25T19:02:13.065Z,1361818933.065 [Default:CallIridium:B] Running Loop=1
2013-02-25T19:02:13.065Z,1361818933.065 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-02-25T19:02:13.429Z,1361818933.429 [Default:Iridium] Running Loop=1
2013-02-25T19:02:13.429Z,1361818933.429 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-02-25T19:02:13.429Z,1361818933.429 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-02-25T19:02:13.429Z,1361818933.429 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-02-25T19:02:13.430Z,1361818933.430 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-02-25T19:02:13.430Z,1361818933.430 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-02-25T19:02:13.430Z,1361818933.430 [Default:Iridium:B.GoToSurface] Stopped
2013-02-25T19:02:13.430Z,1361818933.430 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-02-25T19:02:13.431Z,1361818933.431 [Default:Iridium:Read_Iridium] Running Loop=1
2013-02-25T19:02:18.211Z,1361818938.211 [NAL9602](INFO): Sent 178 bytes from file Logs/20130225T185430/shore0002.lzma
2013-02-25T19:02:18.211Z,1361818938.211 [NAL9602](INFO): Packets left to send: 0
2013-02-25T19:02:18.212Z,1361818938.212 [NAL9602](INFO): Stored copy of sent data in Logs/20130225T185430/shore0002.lzma.parts/0000.sbd
2013-02-25T19:02:19.036Z,1361818939.036 [Default:Iridium:Read_Iridium] Stopped
2013-02-25T19:02:19.037Z,1361818939.037 [Default:Iridium](INFO): Completed Default:Iridium
2013-02-25T19:02:19.037Z,1361818939.037 [Default:Iridium] Stopped
2013-02-25T19:02:19.037Z,1361818939.037 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-02-25T19:02:19.037Z,1361818939.037 [Default:Iridium:A.SetSpeed] Stopped
2013-02-25T19:02:19.037Z,1361818939.037 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-02-25T19:02:19.471Z,1361818939.471 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-02-25T19:02:19.471Z,1361818939.471 [Default:CallIridium:B] Stopped
2013-02-25T19:02:19.471Z,1361818939.471 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-02-25T19:02:19.471Z,1361818939.471 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-02-25T19:02:19.471Z,1361818939.471 [Default:CallIridium] Stopped
2013-02-25T19:02:19.472Z,1361818939.471 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-02-25T19:07:19.046Z,1361819239.046 [Default:CallIridium] Running Loop=1
2013-02-25T19:07:19.047Z,1361819239.047 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-02-25T19:07:19.047Z,1361819239.047 [Default:CallIridium:A] Running Loop=1
2013-02-25T19:07:19.047Z,1361819239.047 [Default:CallIridium:A] Stopped
2013-02-25T19:07:19.047Z,1361819239.047 [Default:CallIridium:B] Running Loop=1
2013-02-25T19:07:19.047Z,1361819239.047 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-02-25T19:07:19.446Z,1361819239.446 [Default:Iridium] Running Loop=1
2013-02-25T19:07:19.446Z,1361819239.446 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-02-25T19:07:19.446Z,1361819239.446 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-02-25T19:07:19.446Z,1361819239.446 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-02-25T19:07:19.447Z,1361819239.447 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-02-25T19:07:19.447Z,1361819239.447 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-02-25T19:07:19.447Z,1361819239.447 [Default:Iridium:B.GoToSurface] Stopped
2013-02-25T19:07:19.447Z,1361819239.447 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-02-25T19:07:19.448Z,1361819239.448 [Default:Iridium:Read_Iridium] Running Loop=1
2013-02-25T19:07:24.214Z,1361819244.214 [NAL9602](INFO): Sent 65 bytes from file Logs/20130225T185430/shore0003.lzma
2013-02-25T19:07:24.215Z,1361819244.215 [NAL9602](INFO): Packets left to send: 0
2013-02-25T19:07:24.217Z,1361819244.217 [NAL9602](INFO): Stored copy of sent data in Logs/20130225T185430/shore0003.lzma.parts/0000.sbd
2013-02-25T19:07:25.047Z,1361819245.047 [Default:Iridium:Read_Iridium] Stopped
2013-02-25T19:07:25.047Z,1361819245.047 [Default:Iridium](INFO): Completed Default:Iridium
2013-02-25T19:07:25.047Z,1361819245.047 [Default:Iridium] Stopped
2013-02-25T19:07:25.048Z,1361819245.048 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-02-25T19:07:25.048Z,1361819245.048 [Default:Iridium:A.SetSpeed] Stopped
2013-02-25T19:07:25.048Z,1361819245.048 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-02-25T19:07:25.429Z,1361819245.429 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-02-25T19:07:25.430Z,1361819245.430 [Default:CallIridium:B] Stopped
2013-02-25T19:07:25.430Z,1361819245.430 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-02-25T19:07:25.430Z,1361819245.430 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-02-25T19:07:25.430Z,1361819245.430 [Default:CallIridium] Stopped
2013-02-25T19:07:25.430Z,1361819245.430 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-02-25T19:12:25.071Z,1361819545.071 [Default:CallIridium] Running Loop=1
2013-02-25T19:12:25.071Z,1361819545.071 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-02-25T19:12:25.071Z,1361819545.071 [Default:CallIridium:A] Running Loop=1
2013-02-25T19:12:25.072Z,1361819545.072 [Default:CallIridium:A] Stopped
2013-02-25T19:12:25.072Z,1361819545.072 [Default:CallIridium:B] Running Loop=1
2013-02-25T19:12:25.072Z,1361819545.072 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-02-25T19:12:25.465Z,1361819545.465 [Default:Iridium] Running Loop=1
2013-02-25T19:12:25.465Z,1361819545.465 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-02-25T19:12:25.465Z,1361819545.466 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-02-25T19:12:25.466Z,1361819545.466 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-02-25T19:12:25.466Z,1361819545.466 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-02-25T19:12:25.466Z,1361819545.466 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-02-25T19:12:25.467Z,1361819545.467 [Default:Iridium:B.GoToSurface] Stopped
2013-02-25T19:12:25.467Z,1361819545.467 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-02-25T19:12:25.467Z,1361819545.467 [Default:Iridium:Read_Iridium] Running Loop=1
2013-02-25T19:12:30.250Z,1361819550.250 [NAL9602](INFO): Sent 64 bytes from file Logs/20130225T185430/shore0004.lzma
2013-02-25T19:12:30.251Z,1361819550.251 [NAL9602](INFO): Packets left to send: 0
2013-02-25T19:12:30.255Z,1361819550.254 [NAL9602](INFO): Stored copy of sent data in Logs/20130225T185430/shore0004.lzma.parts/0000.sbd
2013-02-25T19:12:31.072Z,1361819551.072 [Default:Iridium:Read_Iridium] Stopped
2013-02-25T19:12:31.072Z,1361819551.072 [Default:Iridium](INFO): Completed Default:Iridium
2013-02-25T19:12:31.072Z,1361819551.072 [Default:Iridium] Stopped
2013-02-25T19:12:31.072Z,1361819551.072 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-02-25T19:12:31.073Z,1361819551.073 [Default:Iridium:A.SetSpeed] Stopped
2013-02-25T19:12:31.073Z,1361819551.073 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-02-25T19:12:31.465Z,1361819551.465 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-02-25T19:12:31.465Z,1361819551.465 [Default:CallIridium:B] Stopped
2013-02-25T19:12:31.465Z,1361819551.466 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-02-25T19:12:31.466Z,1361819551.466 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-02-25T19:12:31.466Z,1361819551.466 [Default:CallIridium] Stopped
2013-02-25T19:12:31.466Z,1361819551.466 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-02-25T19:17:31.123Z,1361819851.123 [Default:CallIridium] Running Loop=1
2013-02-25T19:17:31.123Z,1361819851.123 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-02-25T19:17:31.123Z,1361819851.123 [Default:CallIridium:A] Running Loop=1
2013-02-25T19:17:31.123Z,1361819851.124 [Default:CallIridium:A] Stopped
2013-02-25T19:17:31.124Z,1361819851.124 [Default:CallIridium:B] Running Loop=1
2013-02-25T19:17:31.124Z,1361819851.124 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-02-25T19:17:31.517Z,1361819851.517 [Default:Iridium] Running Loop=1
2013-02-25T19:17:31.517Z,1361819851.517 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-02-25T19:17:31.517Z,1361819851.517 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-02-25T19:17:31.517Z,1361819851.517 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-02-25T19:17:31.517Z,1361819851.517 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-02-25T19:17:31.518Z,1361819851.518 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-02-25T19:17:31.518Z,1361819851.518 [Default:Iridium:B.GoToSurface] Stopped
2013-02-25T19:17:31.518Z,1361819851.518 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-02-25T19:17:31.519Z,1361819851.519 [Default:Iridium:Read_Iridium] Running Loop=1
2013-02-25T19:17:36.308Z,1361819856.308 [NAL9602](INFO): Sent 63 bytes from file Logs/20130225T185430/shore0005.lzma
2013-02-25T19:17:36.308Z,1361819856.308 [NAL9602](INFO): Packets left to send: 0
2013-02-25T19:17:36.310Z,1361819856.310 [NAL9602](INFO): Stored copy of sent data in Logs/20130225T185430/shore0005.lzma.parts/0000.sbd
2013-02-25T19:17:37.123Z,1361819857.124 [Default:Iridium:Read_Iridium] Stopped
2013-02-25T19:17:37.124Z,1361819857.124 [Default:Iridium](INFO): Completed Default:Iridium
2013-02-25T19:17:37.124Z,1361819857.124 [Default:Iridium] Stopped
2013-02-25T19:17:37.124Z,1361819857.124 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-02-25T19:17:37.124Z,1361819857.124 [Default:Iridium:A.SetSpeed] Stopped
2013-02-25T19:17:37.124Z,1361819857.124 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-02-25T19:17:37.523Z,1361819857.523 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-02-25T19:17:37.523Z,1361819857.523 [Default:CallIridium:B] Stopped
2013-02-25T19:17:37.523Z,1361819857.523 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-02-25T19:17:37.523Z,1361819857.523 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-02-25T19:17:37.523Z,1361819857.523 [Default:CallIridium] Stopped
2013-02-25T19:17:37.523Z,1361819857.523 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-02-25T19:21:42.135Z,1361820102.135 [NavChartDb](INFO): Done scanning features of Resources/US5CA62M.000
2013-02-25T19:22:37.195Z,1361820157.195 [Default:CallIridium] Running Loop=1
2013-02-25T19:22:37.195Z,1361820157.195 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-02-25T19:22:37.195Z,1361820157.195 [Default:CallIridium:A] Running Loop=1
2013-02-25T19:22:37.196Z,1361820157.196 [Default:CallIridium:A] Stopped
2013-02-25T19:22:37.196Z,1361820157.196 [Default:CallIridium:B] Running Loop=1
2013-02-25T19:22:37.196Z,1361820157.196 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-02-25T19:22:37.589Z,1361820157.589 [Default:Iridium] Running Loop=1
2013-02-25T19:22:37.590Z,1361820157.589 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-02-25T19:22:37.590Z,1361820157.589 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-02-25T19:22:37.590Z,1361820157.590 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-02-25T19:22:37.590Z,1361820157.590 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-02-25T19:22:37.590Z,1361820157.590 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-02-25T19:22:37.591Z,1361820157.591 [Default:Iridium:B.GoToSurface] Stopped
2013-02-25T19:22:37.591Z,1361820157.591 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-02-25T19:22:37.591Z,1361820157.591 [Default:Iridium:Read_Iridium] Running Loop=1
2013-02-25T19:22:42.375Z,1361820162.375 [NAL9602](INFO): Sent 63 bytes from file Logs/20130225T185430/shore0006.lzma
2013-02-25T19:22:42.375Z,1361820162.375 [NAL9602](INFO): Packets left to send: 0
2013-02-25T19:22:42.376Z,1361820162.376 [NAL9602](INFO): Stored copy of sent data in Logs/20130225T185430/shore0006.lzma.parts/0000.sbd
2013-02-25T19:22:43.232Z,1361820163.232 [Default:Iridium:Read_Iridium] Stopped
2013-02-25T19:22:43.232Z,1361820163.232 [Default:Iridium](INFO): Completed Default:Iridium
2013-02-25T19:22:43.232Z,1361820163.232 [Default:Iridium] Stopped
2013-02-25T19:22:43.232Z,1361820163.232 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-02-25T19:22:43.232Z,1361820163.232 [Default:Iridium:A.SetSpeed] Stopped
2013-02-25T19:22:43.232Z,1361820163.232 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-02-25T19:22:43.595Z,1361820163.595 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-02-25T19:22:43.595Z,1361820163.595 [Default:CallIridium:B] Stopped
2013-02-25T19:22:43.595Z,1361820163.595 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-02-25T19:22:43.595Z,1361820163.595 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-02-25T19:22:43.595Z,1361820163.595 [Default:CallIridium] Stopped
2013-02-25T19:22:43.595Z,1361820163.595 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-02-25T19:24:45.215Z,1361820285.216 [NAL9602](FAULT): GPS failed to acquire within timeout.
2013-02-25T19:24:45.216Z,1361820285.216 [NAL9602] Data Fault, FailCount= 1
2013-02-25T19:24:45.216Z,1361820285.216 [NAL9602](ERROR): Data Fault
2013-02-25T19:24:45.231Z,1361820285.231 [Default:CallIridium] Running Loop=1
2013-02-25T19:24:45.231Z,1361820285.231 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-02-25T19:24:45.231Z,1361820285.231 [Default:CallIridium:A] Running Loop=1
2013-02-25T19:24:45.231Z,1361820285.231 [Default:CallIridium:A] Stopped
2013-02-25T19:24:45.231Z,1361820285.231 [Default:CallIridium:B] Running Loop=1
2013-02-25T19:24:45.232Z,1361820285.232 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-02-25T19:24:45.271Z,1361820285.271 [CBIT](ERROR): Data Fault in component: NAL9602
2013-02-25T19:24:45.580Z,1361820285.580 [NAL9602](INFO): Powering down
2013-02-25T19:24:45.596Z,1361820285.596 [Default:Iridium] Running Loop=1
2013-02-25T19:24:45.596Z,1361820285.596 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-02-25T19:24:45.596Z,1361820285.596 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-02-25T19:24:45.596Z,1361820285.596 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-02-25T19:24:45.596Z,1361820285.596 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-02-25T19:24:45.596Z,1361820285.596 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-02-25T19:24:45.597Z,1361820285.597 [Default:Iridium:B.GoToSurface] Stopped
2013-02-25T19:24:45.597Z,1361820285.597 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-02-25T19:24:45.597Z,1361820285.597 [Default:Iridium:Read_Iridium] Running Loop=1
2013-02-25T19:24:46.467Z,1361820286.467 [CBIT](INFO): Clearing failed state for component NAL9602
2013-02-25T19:24:46.467Z,1361820286.467 [NAL9602] No Fault, FailCount= 1
2013-02-25T19:24:49.980Z,1361820289.980 [NAL9602](INFO): Sent 134 bytes from file Logs/20130225T185430/shore0007.lzma
2013-02-25T19:24:49.980Z,1361820289.980 [NAL9602](INFO): Packets left to send: 0
2013-02-25T19:24:49.982Z,1361820289.981 [NAL9602](INFO): Stored copy of sent data in Logs/20130225T185430/shore0007.lzma.parts/0000.sbd
2013-02-25T19:24:50.792Z,1361820290.792 [Default:Iridium:Read_Iridium] Stopped
2013-02-25T19:24:50.793Z,1361820290.793 [Default:Iridium](INFO): Completed Default:Iridium
2013-02-25T19:24:50.793Z,1361820290.793 [Default:Iridium] Stopped
2013-02-25T19:24:50.793Z,1361820290.793 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-02-25T19:24:50.793Z,1361820290.793 [Default:Iridium:A.SetSpeed] Stopped
2013-02-25T19:24:50.793Z,1361820290.793 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-02-25T19:24:51.194Z,1361820291.194 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-02-25T19:24:51.194Z,1361820291.194 [Default:CallIridium:B] Stopped
2013-02-25T19:24:51.194Z,1361820291.194 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-02-25T19:24:51.195Z,1361820291.195 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-02-25T19:24:51.195Z,1361820291.195 [Default:CallIridium] Stopped
2013-02-25T19:24:51.195Z,1361820291.195 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-02-25T19:26:34.286Z,1361820394.286 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2013-02-25T19:26:34.287Z,1361820394.287 [AHRS_sp3003D](ERROR): readHeadingMagBin got 0x00
2013-02-25T19:26:34.287Z,1361820394.287 [AHRS_sp3003D](FAULT): Read Heading Failure.
2013-02-25T19:26:34.287Z,1361820394.287 [AHRS_sp3003D] Communications Fault, FailCount= 1
2013-02-25T19:26:34.287Z,1361820394.287 [AHRS_sp3003D](ERROR): Communications Fault
2013-02-25T19:26:34.289Z,1361820394.289 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-02-25T19:26:34.289Z,1361820394.289 [DVL_micro](INFO): resume:Powering up
2013-02-25T19:26:34.289Z,1361820394.289 [DVL_micro](INFO): Cycling power to configure device.
2013-02-25T19:26:34.321Z,1361820394.321 [CBIT](ERROR): Communications Fault in component: AHRS_sp3003D
2013-02-25T19:26:34.612Z,1361820394.612 [AHRS_sp3003D](INFO): Powering down
2013-02-25T19:26:35.881Z,1361820395.881 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D
2013-02-25T19:26:35.881Z,1361820395.881 [AHRS_sp3003D] No Fault, FailCount= 1
2013-02-25T19:26:36.212Z,1361820396.212 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-02-25T19:26:36.302Z,1361820396.302 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-02-25T19:26:36.303Z,1361820396.303 [DVL_micro](INFO): Querying output modes
2013-02-25T19:26:36.303Z,1361820396.303 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-02-25T19:26:37.146Z,1361820397.146 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2013-02-25T19:26:37.146Z,1361820397.146 [AHRS_sp3003D](ERROR): readHeadingMagBin got 0xA409A0
2013-02-25T19:26:37.146Z,1361820397.146 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2013-02-25T19:26:37.147Z,1361820397.147 [AHRS_sp3003D] Hardware Fault, FailCount= 2
2013-02-25T19:26:37.147Z,1361820397.147 [AHRS_sp3003D](ERROR): Hardware Fault
2013-02-25T19:26:37.175Z,1361820397.175 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2013-02-25T19:26:37.412Z,1361820397.412 [AHRS_sp3003D](INFO): Powering down
2013-02-25T19:26:38.314Z,1361820398.314 [DVL_micro](DEBUG): cmdResponse: 
2013-02-25T19:26:38.314Z,1361820398.314 [DVL_micro](INFO): Output Modes: No Response
2013-02-25T19:26:38.314Z,1361820398.314 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-02-25T19:26:38.697Z,1361820398.697 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D
2013-02-25T19:26:38.697Z,1361820398.697 [AHRS_sp3003D] No Fault, FailCount= 2
2013-02-25T19:26:39.012Z,1361820399.012 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-02-25T19:26:39.935Z,1361820399.935 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2013-02-25T19:26:39.936Z,1361820399.935 [AHRS_sp3003D](ERROR): readHeadingMagBin got 0xA409A0
2013-02-25T19:26:39.936Z,1361820399.936 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2013-02-25T19:26:39.936Z,1361820399.936 [AHRS_sp3003D] Hardware Fault, FailCount= 3
2013-02-25T19:26:39.936Z,1361820399.936 [AHRS_sp3003D](ERROR): Hardware Fault
2013-02-25T19:26:39.968Z,1361820399.968 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2013-02-25T19:26:40.212Z,1361820400.212 [AHRS_sp3003D](INFO): Powering down
2013-02-25T19:26:40.326Z,1361820400.326 [DVL_micro](DEBUG): cmdResponse: 
2013-02-25T19:26:41.456Z,1361820401.456 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D
2013-02-25T19:26:41.456Z,1361820401.456 [AHRS_sp3003D] No Fault, FailCount= 3
2013-02-25T19:26:41.815Z,1361820401.815 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-02-25T19:26:42.352Z,1361820402.352 [DVL_micro](INFO): pause:Powering down
2013-02-25T19:26:42.735Z,1361820402.736 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2013-02-25T19:26:42.736Z,1361820402.736 [AHRS_sp3003D](ERROR): readHeadingMagBin got 0xA409A0
2013-02-25T19:26:42.736Z,1361820402.736 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2013-02-25T19:26:42.736Z,1361820402.736 [AHRS_sp3003D] Hardware Fault, FailCount= 4
2013-02-25T19:26:42.736Z,1361820402.736 [AHRS_sp3003D](ERROR): Hardware Fault
2013-02-25T19:26:42.755Z,1361820402.755 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-02-25T19:26:42.755Z,1361820402.755 [DVL_micro](INFO): resume:Powering up
2013-02-25T19:26:42.755Z,1361820402.755 [DVL_micro](INFO): Cycling power to configure device.
2013-02-25T19:26:42.775Z,1361820402.776 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2013-02-25T19:26:43.013Z,1361820403.013 [AHRS_sp3003D](INFO): Powering down
2013-02-25T19:26:44.256Z,1361820404.256 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D
2013-02-25T19:26:44.256Z,1361820404.256 [AHRS_sp3003D] No Fault, FailCount= 4
2013-02-25T19:26:44.612Z,1361820404.612 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-02-25T19:26:44.762Z,1361820404.762 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-02-25T19:26:44.763Z,1361820404.763 [DVL_micro](INFO): Querying output modes
2013-02-25T19:26:44.763Z,1361820404.763 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-02-25T19:26:45.536Z,1361820405.536 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2013-02-25T19:26:45.536Z,1361820405.536 [AHRS_sp3003D](ERROR): readHeadingMagBin got 0xA409A0
2013-02-25T19:26:45.536Z,1361820405.536 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2013-02-25T19:26:45.536Z,1361820405.536 [AHRS_sp3003D] Hardware Fault, FailCount= 5
2013-02-25T19:26:45.536Z,1361820405.536 [AHRS_sp3003D](ERROR): Hardware Fault
2013-02-25T19:26:45.597Z,1361820405.597 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2013-02-25T19:26:45.597Z,1361820405.597 [CBIT](CRITICAL): Hardware Fault in component: AHRS_sp3003D
2013-02-25T19:26:45.815Z,1361820405.815 [AHRS_sp3003D](INFO): Powering down
2013-02-25T19:26:46.774Z,1361820406.774 [DVL_micro](DEBUG): cmdResponse: 
2013-02-25T19:26:46.774Z,1361820406.774 [DVL_micro](INFO): Output Modes: No Response
2013-02-25T19:26:46.774Z,1361820406.774 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-02-25T19:26:48.786Z,1361820408.786 [DVL_micro](DEBUG): cmdResponse: 
2013-02-25T19:26:54.813Z,1361820414.813 [DVL_micro](ERROR): No DVL communication! Re-initializing
2013-02-25T19:26:54.813Z,1361820414.813 [DVL_micro] Communications Fault, FailCount= 1
2013-02-25T19:26:54.813Z,1361820414.813 [DVL_micro](ERROR): Communications Fault
2013-02-25T19:26:54.815Z,1361820414.815 [DVL_micro](INFO): uninitialize:Powering down
2013-02-25T19:26:55.073Z,1361820415.073 [CBIT](ERROR): Communications Fault in component: DVL_micro
2013-02-25T19:26:55.458Z,1361820415.458 [CBIT](INFO): Clearing failed state for component DVL_micro
2013-02-25T19:26:55.458Z,1361820415.458 [DVL_micro] No Fault, FailCount= 1
2013-02-25T19:26:55.630Z,1361820415.630 [DVL_micro](INFO): Initializing
2013-02-25T19:26:55.630Z,1361820415.630 [DVL_micro](INFO): start:Powering up
2013-02-25T19:26:55.631Z,1361820415.631 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-02-25T19:26:55.631Z,1361820415.631 [DVL_micro](INFO): Cycling power to configure device.
2013-02-25T19:26:57.646Z,1361820417.646 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-02-25T19:26:57.647Z,1361820417.647 [DVL_micro](INFO): Querying output modes
2013-02-25T19:26:57.647Z,1361820417.647 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-02-25T19:26:59.658Z,1361820419.658 [DVL_micro](DEBUG): cmdResponse: 
2013-02-25T19:26:59.658Z,1361820419.658 [DVL_micro](INFO): Output Modes: No Response
2013-02-25T19:26:59.658Z,1361820419.658 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-02-25T19:27:01.666Z,1361820421.666 [DVL_micro](DEBUG): cmdResponse: 
2013-02-25T19:27:06.918Z,1361820426.918 [DVL_micro](ERROR): No DVL communication! Re-initializing
2013-02-25T19:27:06.919Z,1361820426.918 [DVL_micro] Communications Fault, FailCount= 2
2013-02-25T19:27:06.919Z,1361820426.918 [DVL_micro](ERROR): Communications Fault
2013-02-25T19:27:06.920Z,1361820426.920 [DVL_micro](INFO): uninitialize:Powering down
2013-02-25T19:27:07.058Z,1361820427.058 [CBIT](ERROR): Communications Fault in component: DVL_micro
2013-02-25T19:27:07.456Z,1361820427.456 [CBIT](INFO): Clearing failed state for component DVL_micro
2013-02-25T19:27:07.456Z,1361820427.456 [DVL_micro] No Fault, FailCount= 2
2013-02-25T19:27:07.734Z,1361820427.734 [DVL_micro](INFO): Initializing
2013-02-25T19:27:07.734Z,1361820427.734 [DVL_micro](INFO): start:Powering up
2013-02-25T19:27:07.741Z,1361820427.741 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-02-25T19:27:07.742Z,1361820427.741 [DVL_micro](INFO): Cycling power to configure device.
2013-02-25T19:27:09.750Z,1361820429.750 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-02-25T19:27:09.751Z,1361820429.751 [DVL_micro](INFO): Querying output modes
2013-02-25T19:27:09.751Z,1361820429.751 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-02-25T19:27:11.758Z,1361820431.758 [DVL_micro](DEBUG): cmdResponse: 
2013-02-25T19:27:11.758Z,1361820431.758 [DVL_micro](INFO): Output Modes: No Response
2013-02-25T19:27:11.758Z,1361820431.758 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-02-25T19:27:13.766Z,1361820433.766 [DVL_micro](DEBUG): cmdResponse: 
2013-02-25T19:27:19.026Z,1361820439.026 [DVL_micro](ERROR): No DVL communication! Re-initializing
2013-02-25T19:27:19.026Z,1361820439.026 [DVL_micro] Communications Fault, FailCount= 3
2013-02-25T19:27:19.027Z,1361820439.027 [DVL_micro](ERROR): Communications Fault
2013-02-25T19:27:19.028Z,1361820439.028 [DVL_micro](INFO): uninitialize:Powering down
2013-02-25T19:27:19.070Z,1361820439.070 [CBIT](ERROR): Communications Fault in component: DVL_micro
2013-02-25T19:27:19.500Z,1361820439.500 [CBIT](INFO): Clearing failed state for component DVL_micro
2013-02-25T19:27:19.500Z,1361820439.500 [DVL_micro] No Fault, FailCount= 3
2013-02-25T19:27:19.851Z,1361820439.851 [DVL_micro](INFO): Initializing
2013-02-25T19:27:19.851Z,1361820439.851 [DVL_micro](INFO): start:Powering up
2013-02-25T19:27:19.852Z,1361820439.852 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-02-25T19:27:19.852Z,1361820439.852 [DVL_micro](INFO): Cycling power to configure device.
2013-02-25T19:27:21.859Z,1361820441.859 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-02-25T19:27:21.859Z,1361820441.859 [DVL_micro](INFO): Querying output modes
2013-02-25T19:27:21.859Z,1361820441.859 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-02-25T19:27:23.862Z,1361820443.862 [DVL_micro](DEBUG): cmdResponse: 
2013-02-25T19:27:23.862Z,1361820443.862 [DVL_micro](INFO): Output Modes: No Response
2013-02-25T19:27:23.862Z,1361820443.862 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-02-25T19:27:25.866Z,1361820445.866 [DVL_micro](DEBUG): cmdResponse: 
2013-02-25T19:27:31.118Z,1361820451.118 [DVL_micro](ERROR): No DVL communication! Re-initializing
2013-02-25T19:27:31.119Z,1361820451.118 [DVL_micro] Communications Fault, FailCount= 4
2013-02-25T19:27:31.119Z,1361820451.119 [DVL_micro](ERROR): Communications Fault
2013-02-25T19:27:31.120Z,1361820451.120 [DVL_micro](INFO): uninitialize:Powering down
2013-02-25T19:27:31.458Z,1361820451.458 [CBIT](ERROR): Communications Fault in component: DVL_micro
2013-02-25T19:27:31.858Z,1361820451.858 [CBIT](INFO): Clearing failed state for component DVL_micro
2013-02-25T19:27:31.858Z,1361820451.858 [DVL_micro] No Fault, FailCount= 4
2013-02-25T19:27:31.933Z,1361820451.934 [DVL_micro](INFO): Initializing
2013-02-25T19:27:31.934Z,1361820451.934 [DVL_micro](INFO): start:Powering up
2013-02-25T19:27:31.953Z,1361820451.954 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-02-25T19:27:31.954Z,1361820451.954 [DVL_micro](INFO): Cycling power to configure device.
2013-02-25T19:27:33.962Z,1361820453.962 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-02-25T19:27:33.963Z,1361820453.963 [DVL_micro](INFO): Querying output modes
2013-02-25T19:27:33.963Z,1361820453.963 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-02-25T19:27:35.966Z,1361820455.966 [DVL_micro](DEBUG): cmdResponse: 
2013-02-25T19:27:35.966Z,1361820455.966 [DVL_micro](INFO): Output Modes: No Response
2013-02-25T19:27:35.966Z,1361820455.966 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-02-25T19:27:37.974Z,1361820457.974 [DVL_micro](DEBUG): cmdResponse: 
2013-02-25T19:27:43.226Z,1361820463.226 [DVL_micro](ERROR): No DVL communication! Re-initializing
2013-02-25T19:27:43.227Z,1361820463.227 [DVL_micro] Communications Fault, FailCount= 5
2013-02-25T19:27:43.227Z,1361820463.227 [DVL_micro](ERROR): Communications Fault
2013-02-25T19:27:43.228Z,1361820463.228 [DVL_micro](INFO): uninitialize:Powering down
2013-02-25T19:27:43.473Z,1361820463.473 [CBIT](ERROR): Communications Fault in component: DVL_micro
2013-02-25T19:27:43.474Z,1361820463.474 [CBIT](CRITICAL): Communications Fault in component: DVL_micro
2013-02-25T19:29:51.058Z,1361820591.058 [Default:CallIridium] Running Loop=1
2013-02-25T19:29:51.058Z,1361820591.058 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-02-25T19:29:51.058Z,1361820591.058 [Default:CallIridium:A] Running Loop=1
2013-02-25T19:29:51.058Z,1361820591.059 [Default:CallIridium:A] Stopped
2013-02-25T19:29:51.059Z,1361820591.059 [Default:CallIridium:B] Running Loop=1
2013-02-25T19:29:51.059Z,1361820591.059 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-02-25T19:29:51.458Z,1361820591.458 [Default:Iridium] Running Loop=1
2013-02-25T19:29:51.458Z,1361820591.458 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-02-25T19:29:51.458Z,1361820591.458 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-02-25T19:29:51.458Z,1361820591.458 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-02-25T19:29:51.458Z,1361820591.458 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-02-25T19:29:51.458Z,1361820591.458 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-02-25T19:29:51.459Z,1361820591.459 [Default:Iridium:B.GoToSurface] Stopped
2013-02-25T19:29:51.459Z,1361820591.459 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-02-25T19:29:51.460Z,1361820591.460 [Default:Iridium:Read_Iridium] Running Loop=1
2013-02-25T19:29:55.820Z,1361820595.820 [NAL9602](INFO): Sent 190 bytes from file Logs/20130225T185430/shore0008.lzma
2013-02-25T19:29:55.820Z,1361820595.820 [NAL9602](INFO): Packets left to send: 0
2013-02-25T19:29:55.822Z,1361820595.822 [NAL9602](INFO): Stored copy of sent data in Logs/20130225T185430/shore0008.lzma.parts/0000.sbd
2013-02-25T19:29:56.664Z,1361820596.664 [Default:Iridium:Read_Iridium] Stopped
2013-02-25T19:29:56.664Z,1361820596.664 [Default:Iridium](INFO): Completed Default:Iridium
2013-02-25T19:29:56.664Z,1361820596.664 [Default:Iridium] Stopped
2013-02-25T19:29:56.664Z,1361820596.664 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-02-25T19:29:56.664Z,1361820596.664 [Default:Iridium:A.SetSpeed] Stopped
2013-02-25T19:29:56.664Z,1361820596.664 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-02-25T19:29:57.058Z,1361820597.058 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-02-25T19:29:57.058Z,1361820597.058 [Default:CallIridium:B] Stopped
2013-02-25T19:29:57.058Z,1361820597.058 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-02-25T19:29:57.059Z,1361820597.059 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-02-25T19:29:57.059Z,1361820597.059 [Default:CallIridium] Stopped
2013-02-25T19:29:57.059Z,1361820597.059 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium