2013-03-02T22:54:43.592Z,1362264883.592 [Supervisor](DEBUG): Initializing supervisor.
2013-03-02T22:54:43.595Z,1362264883.595 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0
2013-03-02T22:54:43.596Z,1362264883.596 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2013-03-02T22:54:43.597Z,1362264883.597 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0
2013-03-02T22:54:43.601Z,1362264883.601 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2013-03-02T22:54:43.612Z,1362264883.612 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2013-03-02T22:54:43.613Z,1362264883.613 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0
2013-03-02T22:54:43.614Z,1362264883.614 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2013-03-02T22:54:43.615Z,1362264883.615 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0
2013-03-02T22:54:43.616Z,1362264883.616 [Supervisor](INFO): Looking for Config files in directory: Config/
2013-03-02T22:54:43.617Z,1362264883.617 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2013-03-02T22:54:43.893Z,1362264883.893 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2013-03-02T22:54:43.893Z,1362264883.893 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2013-03-02T22:54:44.075Z,1362264884.075 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2013-03-02T22:54:44.075Z,1362264884.075 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2013-03-02T22:54:44.153Z,1362264884.153 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2013-03-02T22:54:44.154Z,1362264884.154 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2013-03-02T22:54:44.349Z,1362264884.349 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2013-03-02T22:54:44.350Z,1362264884.350 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2013-03-02T22:54:44.476Z,1362264884.476 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2013-03-02T22:54:44.477Z,1362264884.477 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2013-03-02T22:54:44.709Z,1362264884.709 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2013-03-02T22:54:44.709Z,1362264884.709 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2013-03-02T22:54:44.874Z,1362264884.874 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2013-03-02T22:54:44.875Z,1362264884.875 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2013-03-02T22:54:45.128Z,1362264885.128 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2013-03-02T22:54:45.129Z,1362264885.129 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2013-03-02T22:54:45.221Z,1362264885.221 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2013-03-02T22:54:45.221Z,1362264885.221 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2013-03-02T22:54:45.626Z,1362264885.626 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2013-03-02T22:54:45.626Z,1362264885.626 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2013-03-02T22:54:45.734Z,1362264885.734 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2013-03-02T22:54:45.735Z,1362264885.735 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2013-03-02T22:54:45.814Z,1362264885.814 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2013-03-02T22:54:45.815Z,1362264885.815 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2013-03-02T22:54:45.909Z,1362264885.909 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2013-03-02T22:54:46.031Z,1362264886.031 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2013-03-02T22:54:46.110Z,1362264886.110 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2013-03-02T22:54:46.204Z,1362264886.204 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2013-03-02T22:54:46.299Z,1362264886.299 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2013-03-02T22:54:46.412Z,1362264886.412 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2013-03-02T22:54:46.499Z,1362264886.499 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2013-03-02T22:54:46.580Z,1362264886.580 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2013-03-02T22:54:46.611Z,1362264886.611 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2013-03-02T22:54:46.764Z,1362264886.764 [InternalSim] Loaded
2013-03-02T22:54:46.764Z,1362264886.764 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2013-03-02T22:54:46.765Z,1362264886.765 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2013-03-02T22:54:46.766Z,1362264886.766 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2013-03-02T22:54:46.823Z,1362264886.823 [SBIT](DEBUG): Construct Startup Built In Test.
2013-03-02T22:54:46.852Z,1362264886.852 [SBIT] Loaded
2013-03-02T22:54:46.852Z,1362264886.852 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2013-03-02T22:54:46.853Z,1362264886.853 [IBIT](DEBUG): Construct Initiated Built In Test.
2013-03-02T22:54:46.882Z,1362264886.882 [IBIT] Loaded
2013-03-02T22:54:46.882Z,1362264886.882 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2013-03-02T22:54:46.886Z,1362264886.886 [CBIT](DEBUG): Construct CBIT Built In Test.
2013-03-02T22:54:47.006Z,1362264887.006 [CBIT] Loaded
2013-03-02T22:54:47.006Z,1362264887.006 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2013-03-02T22:54:47.007Z,1362264887.007 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2013-03-02T22:54:47.007Z,1362264887.007 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2013-03-02T22:54:47.156Z,1362264887.156 [BuoyancyServo] Loaded
2013-03-02T22:54:47.156Z,1362264887.157 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2013-03-02T22:54:47.169Z,1362264887.169 [ElevatorServo] Loaded
2013-03-02T22:54:47.169Z,1362264887.169 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2013-03-02T22:54:47.181Z,1362264887.181 [MassServo] Loaded
2013-03-02T22:54:47.181Z,1362264887.181 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2013-03-02T22:54:47.194Z,1362264887.194 [RudderServo] Loaded
2013-03-02T22:54:47.194Z,1362264887.194 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2013-03-02T22:54:47.206Z,1362264887.206 [ThrusterServo] Loaded
2013-03-02T22:54:47.206Z,1362264887.206 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2013-03-02T22:54:47.207Z,1362264887.207 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2013-03-02T22:54:47.207Z,1362264887.207 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2013-03-02T22:54:47.224Z,1362264887.224 [DepthRateCalculator] Loaded
2013-03-02T22:54:47.224Z,1362264887.224 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2013-03-02T22:54:50.709Z,1362264890.708 [HFRadarModelCalc] Loaded
2013-03-02T22:54:50.709Z,1362264890.709 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2013-03-02T22:54:50.725Z,1362264890.725 [NavChart] Loaded
2013-03-02T22:54:50.725Z,1362264890.725 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2013-03-02T22:54:50.732Z,1362264890.732 [PitchRateCalculator] Loaded
2013-03-02T22:54:50.732Z,1362264890.732 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2013-03-02T22:54:50.739Z,1362264890.739 [SpeedCalculator] Loaded
2013-03-02T22:54:50.739Z,1362264890.739 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2013-03-02T22:54:50.754Z,1362264890.754 [TempGradientCalculator] Loaded
2013-03-02T22:54:50.754Z,1362264890.754 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2013-03-02T22:54:50.760Z,1362264890.760 [YawRateCalculator] Loaded
2013-03-02T22:54:50.761Z,1362264890.761 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2013-03-02T22:54:50.802Z,1362264890.802 [Navigation] Loaded
2013-03-02T22:54:50.802Z,1362264890.802 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread.
2013-03-02T22:54:50.803Z,1362264890.803 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2013-03-02T22:54:50.803Z,1362264890.803 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2013-03-02T22:54:51.025Z,1362264891.025 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2013-03-02T22:54:51.025Z,1362264891.026 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2013-03-02T22:54:51.047Z,1362264891.047 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2013-03-02T22:54:51.047Z,1362264891.047 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2013-03-02T22:54:51.087Z,1362264891.087 [VerticalControl](DEBUG): Construct VerticalControl.
2013-03-02T22:54:51.182Z,1362264891.182 [VerticalControl] Loaded
2013-03-02T22:54:51.183Z,1362264891.182 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2013-03-02T22:54:51.184Z,1362264891.184 [HorizontalControl](DEBUG): Construct HorizontalControl.
2013-03-02T22:54:51.241Z,1362264891.241 [HorizontalControl] Loaded
2013-03-02T22:54:51.241Z,1362264891.241 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2013-03-02T22:54:51.242Z,1362264891.242 [SpeedControl](DEBUG): Construct SpeedControl.
2013-03-02T22:54:51.244Z,1362264891.244 [SpeedControl] Loaded
2013-03-02T22:54:51.244Z,1362264891.244 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2013-03-02T22:54:51.245Z,1362264891.245 [LoopControl](DEBUG): Construct LoopControl.
2013-03-02T22:54:51.245Z,1362264891.245 [LoopControl] Loaded
2013-03-02T22:54:51.246Z,1362264891.246 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2013-03-02T22:54:51.246Z,1362264891.246 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2013-03-02T22:54:51.247Z,1362264891.247 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2013-03-02T22:54:51.252Z,1362264891.252 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator.
2013-03-02T22:54:51.257Z,1362264891.257 [AsyncPiEstimator] Loaded
2013-03-02T22:54:51.257Z,1362264891.257 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread.
2013-03-02T22:54:51.258Z,1362264891.258 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406A44E0
2013-03-02T22:54:51.259Z,1362264891.259 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2013-03-02T22:54:51.259Z,1362264891.259 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2013-03-02T22:54:51.386Z,1362264891.386 [AHRS_sp3003D] Loaded
2013-03-02T22:54:51.387Z,1362264891.386 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2013-03-02T22:54:51.652Z,1362264891.652 [Batt_Ocean_Server] Loaded
2013-03-02T22:54:51.653Z,1362264891.653 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2013-03-02T22:54:51.667Z,1362264891.667 [Depth_Keller] Loaded
2013-03-02T22:54:51.667Z,1362264891.667 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2013-03-02T22:54:51.673Z,1362264891.673 [DropWeight] Loaded
2013-03-02T22:54:51.674Z,1362264891.674 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2013-03-02T22:54:51.851Z,1362264891.851 [DVL_micro] Loaded
2013-03-02T22:54:51.851Z,1362264891.851 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread.
2013-03-02T22:54:51.852Z,1362264891.852 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 407284E0
2013-03-02T22:54:51.937Z,1362264891.937 [NAL9602] Loaded
2013-03-02T22:54:51.937Z,1362264891.937 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2013-03-02T22:54:51.988Z,1362264891.988 [Onboard] Loaded
2013-03-02T22:54:51.989Z,1362264891.989 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2013-03-02T22:54:51.996Z,1362264891.996 [Radio_Freewave] Loaded
2013-03-02T22:54:51.997Z,1362264891.997 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread.
2013-03-02T22:54:51.997Z,1362264891.997 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2013-03-02T22:54:51.998Z,1362264891.998 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2013-03-02T22:54:52.054Z,1362264892.054 [Aanderaa_O2] Loaded
2013-03-02T22:54:52.055Z,1362264892.055 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2013-03-02T22:54:52.088Z,1362264892.088 [CTD_NeilBrown] Loaded
2013-03-02T22:54:52.088Z,1362264892.088 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2013-03-02T22:54:52.090Z,1362264892.089 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4077A4E0
2013-03-02T22:54:52.103Z,1362264892.103 [ISUS] Loaded
2013-03-02T22:54:52.103Z,1362264892.103 [ComponentRegistry](DEBUG): SyncComponent "ISUS" handled in the control thread.
2013-03-02T22:54:52.119Z,1362264892.119 [PAR_Licor] Loaded
2013-03-02T22:54:52.119Z,1362264892.119 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2013-03-02T22:54:52.151Z,1362264892.151 [WetLabsBB2FL] Loaded
2013-03-02T22:54:52.151Z,1362264892.151 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2013-03-02T22:54:52.152Z,1362264892.152 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407AA4E0
2013-03-02T22:54:52.153Z,1362264892.153 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2013-03-02T22:54:52.155Z,1362264892.155 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2013-03-02T22:54:52.156Z,1362264892.156 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2013-03-02T22:54:52.162Z,1362264892.162 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2013-03-02T22:54:52.164Z,1362264892.164 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 407DA4E0
2013-03-02T22:54:52.168Z,1362264892.168 [Supervisor](DEBUG): Running supervisor.
2013-03-02T22:54:52.169Z,1362264892.169 [CommandLine](INFO): Thread ID is 1735
2013-03-02T22:54:52.173Z,1362264892.173 [controlThread](INFO): Thread ID is 1734
2013-03-02T22:54:52.173Z,1362264892.173 [controlThread](DEBUG): Initializing ControlThread
2013-03-02T22:54:52.174Z,1362264892.174 [CycleStarter](INFO): Thread ID is 1733
2013-03-02T22:54:52.174Z,1362264892.174 [InternalSim](DEBUG):  InternalSim initializing...
2013-03-02T22:54:52.207Z,1362264892.207 [logger](INFO): Thread ID is 1736
2013-03-02T22:54:52.236Z,1362264892.236 [SBIT](INFO): Initialize SBIT Component.
2013-03-02T22:54:52.237Z,1362264892.237 [SBIT](IMPORTANT): Tethys CM Info:
$Rev: 10204
2013-03-02T22:54:52.237Z,1362264892.237 [IBIT](INFO): Initialize IBIT Component.
2013-03-02T22:54:52.238Z,1362264892.238 [CBIT](DEBUG): Initialize CBIT Component.
2013-03-02T22:54:52.239Z,1362264892.239 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2013-03-02T22:54:52.251Z,1362264892.251 [AsyncPiEstimator](INFO): Thread ID is 1797
2013-03-02T22:54:52.252Z,1362264892.251 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator.
2013-03-02T22:54:52.264Z,1362264892.264 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2013-03-02T22:54:52.264Z,1362264892.264 [NavChart](DEBUG): Initialize NavChart Derivation.
2013-03-02T22:54:52.265Z,1362264892.265 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2013-03-02T22:54:52.265Z,1362264892.265 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2013-03-02T22:54:52.266Z,1362264892.266 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2013-03-02T22:54:52.267Z,1362264892.267 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2013-03-02T22:54:52.267Z,1362264892.267 [Navigation](DEBUG): Initializing Navigation.
2013-03-02T22:54:52.268Z,1362264892.268 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2013-03-02T22:54:52.269Z,1362264892.270 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2013-03-02T22:54:52.270Z,1362264892.270 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2013-03-02T22:54:52.271Z,1362264892.271 [LoopControl](DEBUG): Initialize LoopControlComponent.
2013-03-02T22:54:52.274Z,1362264892.274 [DVL_micro](INFO): Thread ID is 1798
2013-03-02T22:54:52.283Z,1362264892.283 [DVL_micro](INFO): Initializing
2013-03-02T22:54:52.284Z,1362264892.284 [DVL_micro](INFO): start:Powering up
2013-03-02T22:54:52.285Z,1362264892.284 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-03-02T22:54:52.285Z,1362264892.285 [DVL_micro](INFO): Cycling power to configure device.
2013-03-02T22:54:52.296Z,1362264892.296 [CTD_NeilBrown](INFO): Thread ID is 1799
2013-03-02T22:54:52.296Z,1362264892.296 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2013-03-02T22:54:52.299Z,1362264892.299 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2013-03-02T22:54:52.305Z,1362264892.305 [WetLabsBB2FL](INFO): Thread ID is 1800
2013-03-02T22:54:52.306Z,1362264892.306 [WetLabsBB2FL](INFO): Powering down
2013-03-02T22:54:52.352Z,1362264892.352 [NavChartDb](INFO): Thread ID is 1801
2013-03-02T22:54:52.355Z,1362264892.355 [NavChartDb](FAULT): Change detected in ENC collection. Wiping NavChart Directory
2013-03-02T22:54:52.358Z,1362264892.358 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2013-03-02T22:54:52.360Z,1362264892.360 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA50M.000
2013-03-02T22:54:52.362Z,1362264892.362 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US2WC11M.000
2013-03-02T22:54:52.364Z,1362264892.364 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US1WC07M.000
2013-03-02T22:54:52.366Z,1362264892.366 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US3CA52M.000
2013-03-02T22:54:52.368Z,1362264892.368 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA61M.000
2013-03-02T22:54:52.369Z,1362264892.369 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA83M.000
2013-03-02T22:54:52.379Z,1362264892.379 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA62M.000
2013-03-02T22:54:52.381Z,1362264892.381 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4CA60M.000
2013-03-02T22:54:52.559Z,1362264892.559 [NavChartDb](INFO): Setup scan of Resources/US5CA62M.000
2013-03-02T22:54:53.609Z,1362264893.609 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2013-03-02T22:54:53.660Z,1362264893.660 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2013-03-02T22:54:53.672Z,1362264893.672 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2013-03-02T22:54:53.682Z,1362264893.682 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://aosn.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface RunIn="Progression"/>

    <Aggregate Id="StartupSatComms" >

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

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

    </Aggregate>

</Mission>


2013-03-02T22:54:53.683Z,1362264893.683 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2013-03-02T22:54:53.733Z,1362264893.733 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2013-03-02T22:54:53.740Z,1362264893.740 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2013-03-02T22:54:53.748Z,1362264893.749 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-03-02T22:54:53.769Z,1362264893.769 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2013-03-02T22:54:53.774Z,1362264893.774 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-03-02T22:54:53.785Z,1362264893.785 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2013-03-02T22:54:53.799Z,1362264893.799 [Default:D.SetSpeed](DEBUG): Construct.
2013-03-02T22:54:53.802Z,1362264893.802 [Default:E.GoToSurface](DEBUG): Construct GoToSurface.
2013-03-02T22:54:53.807Z,1362264893.807 [Default:F.Wait](DEBUG): Construct Wait.
2013-03-02T22:54:53.810Z,1362264893.810 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
xmlns:Control="Tethys/Control"
xmlns:Guidance="Tethys/Guidance" 
xmlns:Units="Tethys/Units"
xmlns:Universal="Tethys/Universal"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="Tethys http://aosn.mbari.org/tethys/Xml/Tethys.xsd
Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
Id="Default">

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

    <Aggregate Id="GPS" >

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

<!-- Run at high speed -->

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

<!-- Get to the surface -->

        <Guidance:GoToSurface RunIn="Sequence"/>

<!-- Get GPS fix -->

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

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

    </Aggregate>

    <Aggregate Id="Iridium" >

<!-- Run at high speed -->

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

<!-- Get to the surface -->

        <Guidance:GoToSurface RunIn="Sequence"/>

<!-- Do data comms -->

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

    </Aggregate>

    <Aggregate Id="CallIridium" >

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

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

        <Call RefId="Iridium"/>

    </Aggregate>

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

<!-- Run at low speed -->

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

    <Guidance:GoToSurface RunIn="Parallel"/>

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

</Mission>


2013-03-02T22:54:53.835Z,1362264893.835 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,NAL9602,Onboard,Radio_Freewave,Aanderaa_O2,ISUS,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,
2013-03-02T22:54:53.868Z,1362264893.868 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-03-02T22:54:53.882Z,1362264893.882 [Depth_Keller](ERROR): Pressure reading out of range: 1831.078247 decibar
2013-03-02T22:54:53.907Z,1362264893.907 [Radio_Freewave](INFO): Powering up
2013-03-02T22:54:54.187Z,1362264894.187 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2013-03-02T22:54:54.189Z,1362264894.189 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2013-03-02T22:54:54.196Z,1362264894.196 [ElevatorServo](DEBUG): Initializing EZServoServo.
2013-03-02T22:54:54.197Z,1362264894.197 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2013-03-02T22:54:54.204Z,1362264894.204 [MassServo](DEBUG): Initializing EZServoServo.
2013-03-02T22:54:54.205Z,1362264894.205 [MassServo](DEBUG): Initializing MassServo.
2013-03-02T22:54:54.227Z,1362264894.227 [RudderServo](DEBUG): Initializing EZServoServo.
2013-03-02T22:54:54.232Z,1362264894.232 [RudderServo](DEBUG): Initializing RudderServo.
2013-03-02T22:54:54.242Z,1362264894.242 [ThrusterServo](DEBUG): Initializing EZServoServo.
2013-03-02T22:54:54.243Z,1362264894.243 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2013-03-02T22:54:54.395Z,1362264894.395 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-03-02T22:54:54.395Z,1362264894.395 [DVL_micro](INFO): Querying output modes
2013-03-02T22:54:54.396Z,1362264894.396 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-03-02T22:54:54.407Z,1362264894.407 [DVL_micro](DEBUG): cmdResponse: 01
2013-03-02T22:54:54.407Z,1362264894.407 [DVL_micro](INFO): NQ1 output enabled
2013-03-02T22:54:54.407Z,1362264894.407 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-03-02T22:54:54.419Z,1362264894.419 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 
2013-03-02T22:54:54.424Z,1362264894.424 [DVL_micro](INFO): pause:Powering down
2013-03-02T22:54:56.323Z,1362264896.323 [Aanderaa_O2](INFO): Powering down
2013-03-02T22:54:57.090Z,1362264897.090 [NAL9602](INFO): Powering up NAL9602
2013-03-02T22:55:09.758Z,1362264909.759 [NAL9602](ERROR): NAL9602 initialize uart error: serial timeout
2013-03-02T22:55:09.759Z,1362264909.759 [NAL9602] Communications Fault, FailCount= 1
2013-03-02T22:55:09.759Z,1362264909.759 [NAL9602](ERROR): Communications Fault
2013-03-02T22:55:09.901Z,1362264909.901 [SBIT](IMPORTANT): Beginning Startup BIT
2013-03-02T22:55:09.903Z,1362264909.903 [CBIT](ERROR): Communications Fault in component: NAL9602
2013-03-02T22:55:09.904Z,1362264909.904 [CBIT](IMPORTANT): Beginning GF scan
2013-03-02T22:55:10.188Z,1362264910.188 [NAL9602](INFO): Powering down
2013-03-02T22:55:11.094Z,1362264911.095 [CBIT](INFO): Clearing failed state for component NAL9602
2013-03-02T22:55:11.095Z,1362264911.095 [NAL9602] No Fault, FailCount= 1
2013-03-02T22:55:15.437Z,1362264915.437 [NAL9602](INFO): Powering up NAL9602
2013-03-02T22:55:28.414Z,1362264928.414 [NAL9602](ERROR): NAL9602 initialize uart error: serial timeout
2013-03-02T22:55:28.415Z,1362264928.415 [NAL9602] Communications Fault, FailCount= 2
2013-03-02T22:55:28.415Z,1362264928.415 [NAL9602](ERROR): Communications Fault
2013-03-02T22:55:28.534Z,1362264928.534 [CBIT](ERROR): Communications Fault in component: NAL9602
2013-03-02T22:55:28.535Z,1362264928.535 [CBIT](CRITICAL): Communications Fault in component: NAL9602
2013-03-02T22:55:28.825Z,1362264928.825 [NAL9602](INFO): Powering down
2013-03-02T22:55:36.471Z,1362264936.471 [CBIT](IMPORTANT): No ground fault detected
2013-03-02T22:55:41.832Z,1362264941.832 [CommandLine](IMPORTANT): got command report periodic 5.000000 Onboard.Pressure
2013-03-02T22:55:41.980Z,1362264941.980 [Reporter](INFO): Onboard.Pressure 16.575219 psi
2013-03-02T22:55:47.181Z,1362264947.181 [Reporter](INFO): Onboard.Pressure 17.106229 psi
2013-03-02T22:55:52.631Z,1362264952.631 [Reporter](INFO): Onboard.Pressure 16.575219 psi
2013-03-02T22:55:54.938Z,1362264954.938 [CommandLine](IMPORTANT): got command report periodic 5.000000 Onboard.Humidity
2013-03-02T22:55:55.143Z,1362264955.143 [Reporter](INFO): Onboard.Humidity 14.312352 %
2013-03-02T22:55:57.796Z,1362264957.796 [Reporter](INFO): Onboard.Pressure 17.637237 psi
2013-03-02T22:56:00.180Z,1362264960.180 [Reporter](INFO): Onboard.Humidity 13.441910 %
2013-03-02T22:56:02.952Z,1362264962.952 [Reporter](INFO): Onboard.Pressure 17.637237 psi
2013-03-02T22:56:03.744Z,1362264963.744 [SBIT](IMPORTANT): SBIT PASSED
2013-03-02T22:56:04.137Z,1362264964.137 [MissionManager](IMPORTANT): Started mission Startup
2013-03-02T22:56:04.138Z,1362264964.138 [Startup] Running Loop=1
2013-03-02T22:56:04.138Z,1362264964.138 [Startup](INFO): Aggregate::initialize Startup
2013-03-02T22:56:04.138Z,1362264964.138 [Startup:A.GoToSurface] Running Loop=1
2013-03-02T22:56:04.138Z,1362264964.138 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-02T22:56:04.144Z,1362264964.144 [Startup:StartupSatComms] Running Loop=1
2013-03-02T22:56:04.144Z,1362264964.144 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2013-03-02T22:56:04.144Z,1362264964.144 [Startup:StartupSatComms:A] Running Loop=1
2013-03-02T22:56:04.538Z,1362264964.538 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2013-03-02T22:56:05.443Z,1362264965.443 [Reporter](INFO): Onboard.Humidity 13.441910 %
2013-03-02T22:56:08.171Z,1362264968.171 [Reporter](INFO): Onboard.Pressure 16.575219 psi
2013-03-02T22:56:10.576Z,1362264970.576 [Reporter](INFO): Onboard.Humidity 14.473958 %
2013-03-02T22:56:12.106Z,1362264972.106 [CommandLine](IMPORTANT): got command gfscan
2013-03-02T22:56:12.191Z,1362264972.191 [CBIT](IMPORTANT): Beginning GF scan
2013-03-02T22:56:13.375Z,1362264973.375 [Reporter](INFO): Onboard.Pressure 16.575219 psi
2013-03-02T22:56:15.807Z,1362264975.807 [Reporter](INFO): Onboard.Humidity 13.722068 %
2013-03-02T22:56:18.227Z,1362264978.227 [CommandLine](IMPORTANT): got command report clear
2013-03-02T22:56:38.573Z,1362264998.573 [CBIT](INFO): No ground fault detected
2013-03-02T22:57:04.171Z,1362265024.171 [Startup:StartupSatComms:A](INFO): Timed out from 2013-03-02T22:56:04.1Z
2013-03-02T22:57:04.172Z,1362265024.172 [Startup:StartupSatComms:A:A_Timeout] Running Loop=1
2013-03-02T22:57:04.172Z,1362265024.172 [Startup:StartupSatComms:A:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:A:A_Timeout
2013-03-02T22:57:04.172Z,1362265024.172 [Startup:StartupSatComms:A:A_Timeout](INFO): Completed Startup:StartupSatComms:A:A_Timeout
2013-03-02T22:57:04.172Z,1362265024.172 [Startup:StartupSatComms:A] Stopped
2013-03-02T22:57:04.172Z,1362265024.172 [Startup:StartupSatComms:B] Running Loop=1
2013-03-02T22:57:04.527Z,1362265024.527 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2013-03-02T22:57:28.536Z,1362265048.536 [CBIT](INFO): Clearing failed count for component NAL9602
2013-03-02T22:57:28.536Z,1362265048.536 [NAL9602] No Fault, FailCount= 2
2013-03-02T22:57:28.909Z,1362265048.909 [NAL9602](INFO): Powering up NAL9602
2013-03-02T22:57:41.723Z,1362265061.723 [NAL9602](ERROR): NAL9602 initialize uart error: serial timeout
2013-03-02T22:57:41.723Z,1362265061.723 [NAL9602] Communications Fault, FailCount= 1
2013-03-02T22:57:41.723Z,1362265061.723 [NAL9602](ERROR): Communications Fault
2013-03-02T22:57:41.751Z,1362265061.751 [CBIT](ERROR): Communications Fault in component: NAL9602
2013-03-02T22:57:42.073Z,1362265062.073 [NAL9602](INFO): Powering down
2013-03-02T22:57:42.755Z,1362265062.755 [CBIT](INFO): Clearing failed state for component NAL9602
2013-03-02T22:57:42.755Z,1362265062.755 [NAL9602] No Fault, FailCount= 1
2013-03-02T22:57:47.133Z,1362265067.133 [NAL9602](INFO): Powering up NAL9602
2013-03-02T22:57:59.947Z,1362265079.947 [NAL9602](ERROR): NAL9602 initialize uart error: serial timeout
2013-03-02T22:57:59.947Z,1362265079.947 [NAL9602] Communications Fault, FailCount= 2
2013-03-02T22:57:59.947Z,1362265079.947 [NAL9602](ERROR): Communications Fault
2013-03-02T22:57:59.976Z,1362265079.976 [CBIT](ERROR): Communications Fault in component: NAL9602
2013-03-02T22:57:59.976Z,1362265079.977 [CBIT](CRITICAL): Communications Fault in component: NAL9602
2013-03-02T22:58:00.265Z,1362265080.265 [NAL9602](INFO): Powering down
2013-03-02T22:58:04.209Z,1362265084.210 [Startup:StartupSatComms:B](INFO): Timed out from 2013-03-02T22:57:04.2Z
2013-03-02T22:58:04.210Z,1362265084.210 [Startup:StartupSatComms:B:A_Timeout] Running Loop=1
2013-03-02T22:58:04.210Z,1362265084.210 [Startup:StartupSatComms:B:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:B:A_Timeout
2013-03-02T22:58:04.210Z,1362265084.210 [Startup:StartupSatComms:B:A_Timeout](INFO): Completed Startup:StartupSatComms:B:A_Timeout
2013-03-02T22:58:04.210Z,1362265084.210 [Startup:StartupSatComms:B] Stopped
2013-03-02T22:58:04.246Z,1362265084.246 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2013-03-02T22:58:04.247Z,1362265084.247 [Startup:StartupSatComms] Stopped
2013-03-02T22:58:04.247Z,1362265084.247 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2013-03-02T22:58:04.248Z,1362265084.247 [Startup](INFO): Completed Startup
2013-03-02T22:58:04.248Z,1362265084.248 [Startup] Stopped
2013-03-02T22:58:04.248Z,1362265084.248 [Startup](INFO): Aggregate::uninitialize Startup
2013-03-02T22:58:04.248Z,1362265084.248 [Startup:A.GoToSurface] Stopped
2013-03-02T22:58:04.248Z,1362265084.248 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-02T22:58:04.566Z,1362265084.566 [MissionManager](IMPORTANT): Started mission Default
2013-03-02T22:58:04.566Z,1362265084.566 [Default] Running Loop=1
2013-03-02T22:58:04.566Z,1362265084.566 [Default](INFO): Aggregate::initialize Default
2013-03-02T22:58:04.566Z,1362265084.566 [Default:D.SetSpeed] Running Loop=1
2013-03-02T22:58:04.566Z,1362265084.566 [Default:D.SetSpeed](DEBUG): Initialize.
2013-03-02T22:58:04.566Z,1362265084.566 [Default:E.GoToSurface] Running Loop=1
2013-03-02T22:58:04.566Z,1362265084.566 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-02T22:58:04.566Z,1362265084.566 [Default:Iridium] Running Loop=1
2013-03-02T22:58:04.567Z,1362265084.567 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-03-02T22:58:04.567Z,1362265084.567 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-02T22:58:04.567Z,1362265084.567 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-03-02T22:58:04.567Z,1362265084.567 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-03-02T22:58:04.567Z,1362265084.567 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-02T22:58:04.567Z,1362265084.568 [Default:E.GoToSurface] Running Loop=1
2013-03-02T22:58:04.573Z,1362265084.573 [Default:D.SetSpeed] Running Loop=1
2013-03-02T22:58:04.578Z,1362265084.578 [Default:CallIridium] Running Loop=1
2013-03-02T22:58:04.578Z,1362265084.578 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-03-02T22:58:04.578Z,1362265084.578 [Default:CallIridium:A] Running Loop=1
2013-03-02T22:58:04.580Z,1362265084.580 [Default:CallIridium:A] Stopped
2013-03-02T22:58:04.580Z,1362265084.580 [Default:CallIridium:B] Running Loop=1
2013-03-02T22:58:04.580Z,1362265084.580 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-03-02T22:58:04.585Z,1362265084.585 [Default:Iridium:B.GoToSurface] Stopped
2013-03-02T22:58:04.585Z,1362265084.585 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-02T22:58:04.586Z,1362265084.586 [Default:Iridium:Read_Iridium] Running Loop=1
2013-03-02T22:58:04.586Z,1362265084.586 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-02T22:58:04.593Z,1362265084.593 [Default:GPS] Running Loop=1
2013-03-02T22:58:04.593Z,1362265084.593 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-03-02T22:58:04.593Z,1362265084.593 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-02T22:58:04.594Z,1362265084.593 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-03-02T22:58:04.594Z,1362265084.594 [Default:GPS:B.GoToSurface] Running Loop=1
2013-03-02T22:58:04.594Z,1362265084.594 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-02T22:58:04.599Z,1362265084.599 [Default:GPS:B.GoToSurface] Stopped
2013-03-02T22:58:04.600Z,1362265084.599 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-02T22:58:04.600Z,1362265084.600 [Default:GPS:Read_GPS] Running Loop=1
2013-03-02T22:58:04.600Z,1362265084.600 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-02T22:58:04.967Z,1362265084.967 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2013-03-02T22:58:04.971Z,1362265084.971 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2013-03-02T23:00:00.181Z,1362265200.181 [CBIT](INFO): Clearing failed count for component NAL9602
2013-03-02T23:00:00.181Z,1362265200.181 [NAL9602] No Fault, FailCount= 2
2013-03-02T23:00:00.557Z,1362265200.557 [NAL9602](INFO): Powering up NAL9602
2013-03-02T23:00:13.379Z,1362265213.378 [NAL9602](ERROR): NAL9602 initialize uart error: serial timeout
2013-03-02T23:00:13.379Z,1362265213.379 [NAL9602] Communications Fault, FailCount= 1
2013-03-02T23:00:13.379Z,1362265213.379 [NAL9602](ERROR): Communications Fault
2013-03-02T23:00:13.408Z,1362265213.408 [CBIT](ERROR): Communications Fault in component: NAL9602
2013-03-02T23:00:13.700Z,1362265213.700 [NAL9602](INFO): Powering down
2013-03-02T23:00:14.406Z,1362265214.406 [CBIT](INFO): Clearing failed state for component NAL9602
2013-03-02T23:00:14.407Z,1362265214.407 [NAL9602] No Fault, FailCount= 1
2013-03-02T23:00:18.829Z,1362265218.829 [NAL9602](INFO): Powering up NAL9602
2013-03-02T23:00:31.607Z,1362265231.606 [NAL9602](ERROR): NAL9602 initialize uart error: serial timeout
2013-03-02T23:00:31.607Z,1362265231.607 [NAL9602] Communications Fault, FailCount= 2
2013-03-02T23:00:31.607Z,1362265231.607 [NAL9602](ERROR): Communications Fault
2013-03-02T23:00:31.653Z,1362265231.653 [CBIT](ERROR): Communications Fault in component: NAL9602
2013-03-02T23:00:31.653Z,1362265231.653 [CBIT](CRITICAL): Communications Fault in component: NAL9602
2013-03-02T23:00:31.962Z,1362265231.962 [NAL9602](INFO): Powering down
2013-03-02T23:01:45.136Z,1362265305.136 [CommandLine](IMPORTANT): got command stop
2013-03-02T23:02:31.861Z,1362265351.861 [CBIT](INFO): Clearing failed count for component NAL9602
2013-03-02T23:02:31.861Z,1362265351.861 [NAL9602] No Fault, FailCount= 2
2013-03-02T23:02:32.237Z,1362265352.237 [NAL9602](INFO): Powering up NAL9602
2013-03-02T23:02:45.098Z,1362265365.099 [NAL9602](ERROR): NAL9602 initialize uart error: serial timeout
2013-03-02T23:02:45.099Z,1362265365.099 [NAL9602] Communications Fault, FailCount= 1
2013-03-02T23:02:45.099Z,1362265365.099 [NAL9602](ERROR): Communications Fault
2013-03-02T23:02:45.147Z,1362265365.147 [CBIT](ERROR): Communications Fault in component: NAL9602
2013-03-02T23:02:45.361Z,1362265365.361 [NAL9602](INFO): Powering down
2013-03-02T23:02:46.153Z,1362265366.153 [CBIT](INFO): Clearing failed state for component NAL9602
2013-03-02T23:02:46.154Z,1362265366.154 [NAL9602] No Fault, FailCount= 1
2013-03-02T23:02:50.533Z,1362265370.533 [NAL9602](INFO): Powering up NAL9602
2013-03-02T23:03:03.347Z,1362265383.346 [NAL9602](ERROR): NAL9602 initialize uart error: serial timeout
2013-03-02T23:03:03.347Z,1362265383.347 [NAL9602] Communications Fault, FailCount= 2
2013-03-02T23:03:03.347Z,1362265383.347 [NAL9602](ERROR): Communications Fault
2013-03-02T23:03:03.377Z,1362265383.377 [CBIT](ERROR): Communications Fault in component: NAL9602
2013-03-02T23:03:03.377Z,1362265383.377 [CBIT](CRITICAL): Communications Fault in component: NAL9602
2013-03-02T23:03:03.709Z,1362265383.709 [NAL9602](INFO): Powering down
2013-03-02T23:03:34.194Z,1362265414.194 [CommandLine](IMPORTANT): got command report periodic 5.000000 Onboard.Pressure
2013-03-02T23:03:34.385Z,1362265414.385 [Reporter](INFO): Onboard.Pressure 17.106229 psi
2013-03-02T23:03:39.586Z,1362265419.586 [Reporter](INFO): Onboard.Pressure 17.106229 psi
2013-03-02T23:03:44.789Z,1362265424.789 [Reporter](INFO): Onboard.Pressure 17.637237 psi
2013-03-02T23:03:49.985Z,1362265429.985 [Reporter](INFO): Onboard.Pressure 17.106229 psi
2013-03-02T23:03:55.186Z,1362265435.186 [Reporter](INFO): Onboard.Pressure 17.106229 psi
2013-03-02T23:03:58.626Z,1362265438.626 [CommandLine](IMPORTANT): got command report clear
2013-03-02T23:05:03.580Z,1362265503.580 [CBIT](INFO): Clearing failed count for component NAL9602
2013-03-02T23:05:03.581Z,1362265503.580 [NAL9602] No Fault, FailCount= 2
2013-03-02T23:05:03.962Z,1362265503.962 [NAL9602](INFO): Powering up NAL9602
2013-03-02T23:05:16.786Z,1362265516.786 [NAL9602](ERROR): NAL9602 initialize uart error: serial timeout
2013-03-02T23:05:16.787Z,1362265516.787 [NAL9602] Communications Fault, FailCount= 1
2013-03-02T23:05:16.787Z,1362265516.787 [NAL9602](ERROR): Communications Fault
2013-03-02T23:05:16.837Z,1362265516.837 [CBIT](ERROR): Communications Fault in component: NAL9602
2013-03-02T23:05:17.121Z,1362265517.121 [NAL9602](INFO): Powering down
2013-03-02T23:05:17.874Z,1362265517.874 [CBIT](INFO): Clearing failed state for component NAL9602
2013-03-02T23:05:17.874Z,1362265517.874 [NAL9602] No Fault, FailCount= 1
2013-03-02T23:05:22.221Z,1362265522.221 [NAL9602](INFO): Powering up NAL9602
2013-03-02T23:05:35.039Z,1362265535.039 [NAL9602](ERROR): NAL9602 initialize uart error: serial timeout
2013-03-02T23:05:35.039Z,1362265535.039 [NAL9602] Communications Fault, FailCount= 2
2013-03-02T23:05:35.039Z,1362265535.039 [NAL9602](ERROR): Communications Fault
2013-03-02T23:05:35.069Z,1362265535.069 [CBIT](ERROR): Communications Fault in component: NAL9602
2013-03-02T23:05:35.069Z,1362265535.069 [CBIT](CRITICAL): Communications Fault in component: NAL9602
2013-03-02T23:05:35.369Z,1362265535.369 [NAL9602](INFO): Powering down
2013-03-02T23:07:35.284Z,1362265655.284 [CBIT](INFO): Clearing failed count for component NAL9602
2013-03-02T23:07:35.284Z,1362265655.284 [NAL9602] No Fault, FailCount= 2
2013-03-02T23:07:35.693Z,1362265655.693 [NAL9602](INFO): Powering up NAL9602
2013-03-02T23:07:48.486Z,1362265668.487 [NAL9602](ERROR): NAL9602 initialize uart error: serial timeout
2013-03-02T23:07:48.487Z,1362265668.487 [NAL9602] Communications Fault, FailCount= 1
2013-03-02T23:07:48.487Z,1362265668.487 [NAL9602](ERROR): Communications Fault
2013-03-02T23:07:48.542Z,1362265668.542 [CBIT](ERROR): Communications Fault in component: NAL9602
2013-03-02T23:07:48.845Z,1362265668.845 [NAL9602](INFO): Powering down
2013-03-02T23:07:49.548Z,1362265669.548 [CBIT](INFO): Clearing failed state for component NAL9602
2013-03-02T23:07:49.548Z,1362265669.548 [NAL9602] No Fault, FailCount= 1
2013-03-02T23:07:53.924Z,1362265673.924 [NAL9602](INFO): Powering up NAL9602
2013-03-02T23:08:06.747Z,1362265686.747 [NAL9602](ERROR): NAL9602 initialize uart error: serial timeout
2013-03-02T23:08:06.747Z,1362265686.747 [NAL9602] Communications Fault, FailCount= 2
2013-03-02T23:08:06.747Z,1362265686.747 [NAL9602](ERROR): Communications Fault
2013-03-02T23:08:06.777Z,1362265686.777 [CBIT](ERROR): Communications Fault in component: NAL9602
2013-03-02T23:08:06.777Z,1362265686.777 [CBIT](CRITICAL): Communications Fault in component: NAL9602
2013-03-02T23:08:07.105Z,1362265687.105 [NAL9602](INFO): Powering down
2013-03-02T23:09:24.177Z,1362265764.177 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2013-03-02T23:10:07.033Z,1362265807.033 [CBIT](INFO): Clearing failed count for component NAL9602
2013-03-02T23:10:07.033Z,1362265807.033 [NAL9602] No Fault, FailCount= 2
2013-03-02T23:10:07.362Z,1362265807.362 [NAL9602](INFO): Powering up NAL9602
2013-03-02T23:10:20.178Z,1362265820.178 [NAL9602](ERROR): NAL9602 initialize uart error: serial timeout
2013-03-02T23:10:20.179Z,1362265820.179 [NAL9602] Communications Fault, FailCount= 1
2013-03-02T23:10:20.179Z,1362265820.179 [NAL9602](ERROR): Communications Fault
2013-03-02T23:10:20.208Z,1362265820.208 [CBIT](ERROR): Communications Fault in component: NAL9602
2013-03-02T23:10:20.549Z,1362265820.549 [NAL9602](INFO): Powering down
2013-03-02T23:10:21.208Z,1362265821.208 [CBIT](INFO): Clearing failed state for component NAL9602
2013-03-02T23:10:21.208Z,1362265821.208 [NAL9602] No Fault, FailCount= 1
2013-03-02T23:10:25.592Z,1362265825.592 [NAL9602](INFO): Powering up NAL9602
2013-03-02T23:10:38.438Z,1362265838.438 [NAL9602](ERROR): NAL9602 initialize uart error: serial timeout
2013-03-02T23:10:38.439Z,1362265838.439 [NAL9602] Communications Fault, FailCount= 2
2013-03-02T23:10:38.439Z,1362265838.439 [NAL9602](ERROR): Communications Fault
2013-03-02T23:10:38.469Z,1362265838.469 [CBIT](ERROR): Communications Fault in component: NAL9602
2013-03-02T23:10:38.469Z,1362265838.469 [CBIT](CRITICAL): Communications Fault in component: NAL9602
2013-03-02T23:10:38.725Z,1362265838.725 [NAL9602](INFO): Powering down