2012-10-11T16:56:00.152Z,1349974560.151 [Supervisor](DEBUG): Initializing supervisor.
2012-10-11T16:56:00.154Z,1349974560.154 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0
2012-10-11T16:56:00.159Z,1349974560.159 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2012-10-11T16:56:00.162Z,1349974560.162 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0
2012-10-11T16:56:00.166Z,1349974560.166 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2012-10-11T16:56:00.177Z,1349974560.177 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2012-10-11T16:56:00.178Z,1349974560.178 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0
2012-10-11T16:56:00.179Z,1349974560.179 [ComponentRegistry](DEBUG): SyncComponent "logger" handled in the control thread.
2012-10-11T16:56:00.180Z,1349974560.180 [Supervisor](INFO): Looking for Config files in directory: Config/
2012-10-11T16:56:00.183Z,1349974560.183 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2012-10-11T16:56:00.501Z,1349974560.501 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2012-10-11T16:56:00.503Z,1349974560.503 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2012-10-11T16:56:00.702Z,1349974560.702 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2012-10-11T16:56:00.703Z,1349974560.703 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2012-10-11T16:56:00.798Z,1349974560.798 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2012-10-11T16:56:00.800Z,1349974560.800 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2012-10-11T16:56:01.031Z,1349974561.031 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2012-10-11T16:56:01.032Z,1349974561.032 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2012-10-11T16:56:01.182Z,1349974561.182 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2012-10-11T16:56:01.184Z,1349974561.184 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2012-10-11T16:56:01.444Z,1349974561.444 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2012-10-11T16:56:01.444Z,1349974561.444 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2012-10-11T16:56:01.639Z,1349974561.639 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2012-10-11T16:56:01.641Z,1349974561.641 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2012-10-11T16:56:01.920Z,1349974561.920 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2012-10-11T16:56:01.922Z,1349974561.922 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2012-10-11T16:56:02.035Z,1349974562.035 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2012-10-11T16:56:02.036Z,1349974562.036 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2012-10-11T16:56:02.488Z,1349974562.488 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2012-10-11T16:56:02.488Z,1349974562.488 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2012-10-11T16:56:02.619Z,1349974562.619 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2012-10-11T16:56:02.620Z,1349974562.620 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2012-10-11T16:56:02.716Z,1349974562.716 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2012-10-11T16:56:02.719Z,1349974562.719 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2012-10-11T16:56:02.830Z,1349974562.830 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2012-10-11T16:56:02.976Z,1349974562.976 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2012-10-11T16:56:03.070Z,1349974563.070 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2012-10-11T16:56:03.184Z,1349974563.184 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2012-10-11T16:56:03.294Z,1349974563.294 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2012-10-11T16:56:03.428Z,1349974563.428 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2012-10-11T16:56:03.531Z,1349974563.531 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2012-10-11T16:56:03.681Z,1349974563.681 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2012-10-11T16:56:05.636Z,1349974565.636 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2012-10-11T16:56:05.823Z,1349974565.823 [InternalSim] Loaded
2012-10-11T16:56:05.824Z,1349974565.824 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2012-10-11T16:56:05.824Z,1349974565.824 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2012-10-11T16:56:05.825Z,1349974565.825 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2012-10-11T16:56:05.905Z,1349974565.905 [SBIT](DEBUG): Construct Startup Built In Test.
2012-10-11T16:56:05.919Z,1349974565.919 [SBIT] Loaded
2012-10-11T16:56:05.919Z,1349974565.919 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2012-10-11T16:56:05.920Z,1349974565.920 [IBIT](DEBUG): Construct Initiated Built In Test.
2012-10-11T16:56:05.952Z,1349974565.952 [IBIT] Loaded
2012-10-11T16:56:05.952Z,1349974565.953 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2012-10-11T16:56:05.960Z,1349974565.960 [CBIT](DEBUG): Construct CBIT Built In Test.
2012-10-11T16:56:06.085Z,1349974566.085 [CBIT] Loaded
2012-10-11T16:56:06.085Z,1349974566.085 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2012-10-11T16:56:06.086Z,1349974566.086 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2012-10-11T16:56:06.086Z,1349974566.086 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2012-10-11T16:56:06.253Z,1349974566.253 [BuoyancyServo] Loaded
2012-10-11T16:56:06.253Z,1349974566.253 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2012-10-11T16:56:06.263Z,1349974566.263 [ElevatorServo] Loaded
2012-10-11T16:56:06.263Z,1349974566.263 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2012-10-11T16:56:06.275Z,1349974566.275 [MassServo] Loaded
2012-10-11T16:56:06.275Z,1349974566.275 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2012-10-11T16:56:06.291Z,1349974566.291 [RudderServo] Loaded
2012-10-11T16:56:06.291Z,1349974566.291 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2012-10-11T16:56:06.303Z,1349974566.303 [ThrusterServo] Loaded
2012-10-11T16:56:06.303Z,1349974566.303 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2012-10-11T16:56:06.303Z,1349974566.303 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2012-10-11T16:56:06.304Z,1349974566.304 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2012-10-11T16:56:06.336Z,1349974566.336 [DepthRateCalculator] Loaded
2012-10-11T16:56:06.337Z,1349974566.337 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2012-10-11T16:56:10.196Z,1349974570.195 [HFRadarModelCalc] Loaded
2012-10-11T16:56:10.196Z,1349974570.196 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2012-10-11T16:56:10.211Z,1349974570.211 [NavChart] Loaded
2012-10-11T16:56:10.212Z,1349974570.212 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2012-10-11T16:56:10.217Z,1349974570.217 [PitchRateCalculator] Loaded
2012-10-11T16:56:10.218Z,1349974570.217 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2012-10-11T16:56:10.224Z,1349974570.224 [SpeedCalculator] Loaded
2012-10-11T16:56:10.224Z,1349974570.224 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2012-10-11T16:56:10.238Z,1349974570.238 [TempGradientCalculator] Loaded
2012-10-11T16:56:10.238Z,1349974570.238 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2012-10-11T16:56:10.244Z,1349974570.244 [YawRateCalculator] Loaded
2012-10-11T16:56:10.244Z,1349974570.244 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2012-10-11T16:56:10.264Z,1349974570.264 [Navigation] Loaded
2012-10-11T16:56:10.264Z,1349974570.264 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread.
2012-10-11T16:56:10.265Z,1349974570.265 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2012-10-11T16:56:10.266Z,1349974570.266 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2012-10-11T16:56:10.520Z,1349974570.520 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2012-10-11T16:56:10.520Z,1349974570.520 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2012-10-11T16:56:10.558Z,1349974570.558 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2012-10-11T16:56:10.559Z,1349974570.559 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2012-10-11T16:56:10.616Z,1349974570.616 [VerticalControl](DEBUG): Construct VerticalControl.
2012-10-11T16:56:10.662Z,1349974570.662 [VerticalControl] Loaded
2012-10-11T16:56:10.662Z,1349974570.662 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2012-10-11T16:56:10.663Z,1349974570.663 [HorizontalControl](DEBUG): Construct HorizontalControl.
2012-10-11T16:56:10.685Z,1349974570.685 [HorizontalControl] Loaded
2012-10-11T16:56:10.685Z,1349974570.685 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2012-10-11T16:56:10.686Z,1349974570.686 [SpeedControl](DEBUG): Construct SpeedControl.
2012-10-11T16:56:10.688Z,1349974570.688 [SpeedControl] Loaded
2012-10-11T16:56:10.688Z,1349974570.688 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2012-10-11T16:56:10.689Z,1349974570.689 [LoopControl](DEBUG): Construct LoopControl.
2012-10-11T16:56:10.690Z,1349974570.690 [LoopControl] Loaded
2012-10-11T16:56:10.690Z,1349974570.690 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2012-10-11T16:56:10.691Z,1349974570.691 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2012-10-11T16:56:10.691Z,1349974570.691 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2012-10-11T16:56:10.699Z,1349974570.699 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator.
2012-10-11T16:56:10.704Z,1349974570.704 [AsyncPiEstimator] Loaded
2012-10-11T16:56:10.704Z,1349974570.704 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread.
2012-10-11T16:56:10.705Z,1349974570.705 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406724E0
2012-10-11T16:56:10.706Z,1349974570.706 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2012-10-11T16:56:10.707Z,1349974570.707 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2012-10-11T16:56:10.873Z,1349974570.873 [AHRS_sp3003D] Loaded
2012-10-11T16:56:10.873Z,1349974570.873 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2012-10-11T16:56:11.140Z,1349974571.140 [Batt_Ocean_Server] Loaded
2012-10-11T16:56:11.140Z,1349974571.140 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2012-10-11T16:56:11.153Z,1349974571.153 [Depth_Keller] Loaded
2012-10-11T16:56:11.153Z,1349974571.153 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2012-10-11T16:56:11.158Z,1349974571.158 [DropWeight] Loaded
2012-10-11T16:56:11.159Z,1349974571.159 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2012-10-11T16:56:11.280Z,1349974571.280 [DVL_micro] Loaded
2012-10-11T16:56:11.280Z,1349974571.280 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread.
2012-10-11T16:56:11.281Z,1349974571.281 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 406F34E0
2012-10-11T16:56:11.369Z,1349974571.369 [NAL9602] Loaded
2012-10-11T16:56:11.369Z,1349974571.369 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2012-10-11T16:56:11.420Z,1349974571.420 [Onboard] Loaded
2012-10-11T16:56:11.421Z,1349974571.421 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2012-10-11T16:56:11.427Z,1349974571.427 [Radio_Freewave] Loaded
2012-10-11T16:56:11.428Z,1349974571.428 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread.
2012-10-11T16:56:11.428Z,1349974571.428 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2012-10-11T16:56:11.429Z,1349974571.429 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2012-10-11T16:56:11.521Z,1349974571.521 [CTD_NeilBrown] Loaded
2012-10-11T16:56:11.521Z,1349974571.521 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2012-10-11T16:56:11.522Z,1349974571.522 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4074B4E0
2012-10-11T16:56:11.532Z,1349974571.532 [PAR_Licor] Loaded
2012-10-11T16:56:11.533Z,1349974571.533 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2012-10-11T16:56:11.549Z,1349974571.549 [Turbulence_NPS] Loaded
2012-10-11T16:56:11.550Z,1349974571.550 [ComponentRegistry](DEBUG): Component "Turbulence_NPS" handled in its own thread.
2012-10-11T16:56:11.551Z,1349974571.551 [Turbulence_NPS ThreadHandler](DEBUG): Created PCaller Thread at 4077B4E0
2012-10-11T16:56:11.583Z,1349974571.583 [WetLabsBB2FL] Loaded
2012-10-11T16:56:11.583Z,1349974571.583 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2012-10-11T16:56:11.584Z,1349974571.584 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407AB4E0
2012-10-11T16:56:11.585Z,1349974571.585 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2012-10-11T16:56:11.587Z,1349974571.587 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2012-10-11T16:56:11.588Z,1349974571.588 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2012-10-11T16:56:11.598Z,1349974571.598 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2012-10-11T16:56:11.599Z,1349974571.599 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 407DB4E0
2012-10-11T16:56:11.604Z,1349974571.603 [Supervisor](DEBUG): Running supervisor.
2012-10-11T16:56:11.605Z,1349974571.605 [CommandLine](INFO): Thread ID is 746
2012-10-11T16:56:11.607Z,1349974571.607 [controlThread](INFO): Thread ID is 745
2012-10-11T16:56:11.607Z,1349974571.607 [controlThread](DEBUG): Initializing ControlThread
2012-10-11T16:56:11.608Z,1349974571.608 [CycleStarter](INFO): Thread ID is 744
2012-10-11T16:56:11.608Z,1349974571.608 [InternalSim](DEBUG):  InternalSim initializing...
2012-10-11T16:56:11.635Z,1349974571.635 [AsyncPiEstimator](INFO): Thread ID is 807
2012-10-11T16:56:11.635Z,1349974571.635 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator.
2012-10-11T16:56:11.715Z,1349974571.715 [DVL_micro](INFO): Thread ID is 808
2012-10-11T16:56:11.825Z,1349974571.825 [CTD_NeilBrown](INFO): Thread ID is 809
2012-10-11T16:56:11.825Z,1349974571.825 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2012-10-11T16:56:11.828Z,1349974571.828 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2012-10-11T16:56:11.848Z,1349974571.848 [Turbulence_NPS](INFO): Thread ID is 810
2012-10-11T16:56:11.849Z,1349974571.849 [Turbulence_NPS](DEBUG): Initializing Turbulence_NPS.
2012-10-11T16:56:11.849Z,1349974571.849 [Turbulence_NPS](INFO): Opening uart, block timeout 10ths=1
2012-10-11T16:56:11.875Z,1349974571.875 [DVL_micro](INFO): Initializing
2012-10-11T16:56:11.875Z,1349974571.875 [DVL_micro](INFO): start:Powering up
2012-10-11T16:56:11.876Z,1349974571.876 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2012-10-11T16:56:11.876Z,1349974571.876 [DVL_micro](INFO): Cycling power to configure device.
2012-10-11T16:56:11.898Z,1349974571.898 [WetLabsBB2FL](INFO): Thread ID is 811
2012-10-11T16:56:11.899Z,1349974571.899 [WetLabsBB2FL](INFO): Powering down
2012-10-11T16:56:11.926Z,1349974571.926 [SBIT](INFO): Initialize SBIT Component.
2012-10-11T16:56:11.932Z,1349974571.932 [NavChartDb](INFO): Thread ID is 812
2012-10-11T16:56:11.933Z,1349974571.933 [SBIT](IMPORTANT): Tethys CM Info:
$Rev: 9967
2012-10-11T16:56:11.934Z,1349974571.934 [IBIT](INFO): Initialize IBIT Component.
2012-10-11T16:56:11.942Z,1349974571.942 [CBIT](DEBUG): Initialize CBIT Component.
2012-10-11T16:56:11.942Z,1349974571.942 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2012-10-11T16:56:11.943Z,1349974571.943 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2012-10-11T16:56:11.943Z,1349974571.943 [NavChartDb](FAULT): Change detected in ENC collection. Wiping NavChart Directory
2012-10-11T16:56:11.958Z,1349974571.958 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2012-10-11T16:56:11.968Z,1349974571.968 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2012-10-11T16:56:11.969Z,1349974571.969 [NavChart](DEBUG): Initialize NavChart Derivation.
2012-10-11T16:56:11.969Z,1349974571.969 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2012-10-11T16:56:11.969Z,1349974571.969 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2012-10-11T16:56:11.970Z,1349974571.970 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2012-10-11T16:56:11.974Z,1349974571.974 [Turbulence_NPS](INFO): Pause powering down
2012-10-11T16:56:11.979Z,1349974571.980 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2012-10-11T16:56:11.980Z,1349974571.980 [Navigation](DEBUG): Initializing Navigation.
2012-10-11T16:56:11.980Z,1349974571.980 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2012-10-11T16:56:11.982Z,1349974571.982 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2012-10-11T16:56:11.991Z,1349974571.991 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2012-10-11T16:56:11.992Z,1349974571.991 [LoopControl](DEBUG): Initialize LoopControlComponent.
2012-10-11T16:56:12.001Z,1349974572.001 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA50M.000
2012-10-11T16:56:12.017Z,1349974572.017 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US2WC11M.000
2012-10-11T16:56:12.019Z,1349974572.019 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US1WC07M.000
2012-10-11T16:56:12.020Z,1349974572.020 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US3CA52M.000
2012-10-11T16:56:12.025Z,1349974572.025 [NavChartDb](INFO): Setup scan of Resources/US5CA50M.000
2012-10-11T16:56:13.848Z,1349974573.848 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2012-10-11T16:56:13.876Z,1349974573.875 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2012-10-11T16:56:13.896Z,1349974573.895 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2012-10-11T16:56:13.906Z,1349974573.906 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://aosn.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface RunIn="Progression"/>

    <Aggregate Id="StartupSatComms" >

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

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

    </Aggregate>

</Mission>


2012-10-11T16:56:13.907Z,1349974573.907 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2012-10-11T16:56:13.945Z,1349974573.945 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2012-10-11T16:56:13.947Z,1349974573.947 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2012-10-11T16:56:13.950Z,1349974573.950 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2012-10-11T16:56:13.959Z,1349974573.959 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2012-10-11T16:56:13.962Z,1349974573.962 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2012-10-11T16:56:13.969Z,1349974573.969 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2012-10-11T16:56:13.978Z,1349974573.978 [Default:D.SetSpeed](DEBUG): Construct.
2012-10-11T16:56:13.981Z,1349974573.981 [Default:E.GoToSurface](DEBUG): Construct GoToSurface.
2012-10-11T16:56:13.986Z,1349974573.986 [Default:F.Wait](DEBUG): Construct Wait.
2012-10-11T16:56:13.990Z,1349974573.990 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
xmlns:Control="Tethys/Control"
xmlns:Guidance="Tethys/Guidance" 
xmlns:Units="Tethys/Units"
xmlns:Universal="Tethys/Universal"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="Tethys http://aosn.mbari.org/tethys/Xml/Tethys.xsd
Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
Id="Default">

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

    <Aggregate Id="GPS" >

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

<!-- Run at high speed -->

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

<!-- Get to the surface -->

        <Guidance:GoToSurface RunIn="Sequence"/>

<!-- Get GPS fix -->

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

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

    </Aggregate>

    <Aggregate Id="Iridium" >

<!-- Run at high speed -->

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

<!-- Get to the surface -->

        <Guidance:GoToSurface RunIn="Sequence"/>

<!-- Do data comms -->

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

    </Aggregate>

    <Aggregate Id="CallIridium" >

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

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

        <Call RefId="Iridium"/>

    </Aggregate>

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

<!-- Run at low speed -->

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

    <Guidance:GoToSurface RunIn="Parallel"/>

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

</Mission>


2012-10-11T16:56:13.995Z,1349974573.995 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,NAL9602,Onboard,Radio_Freewave,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,logger,
2012-10-11T16:56:14.015Z,1349974574.015 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2012-10-11T16:56:14.034Z,1349974574.034 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2012-10-11T16:56:14.034Z,1349974574.034 [DVL_micro](INFO): Querying output modes
2012-10-11T16:56:14.034Z,1349974574.034 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2012-10-11T16:56:14.039Z,1349974574.039 [DVL_micro](DEBUG): cmdResponse: 01 03 16
2012-10-11T16:56:14.039Z,1349974574.039 [DVL_micro](INFO): NQ1 output enabled
2012-10-11T16:56:14.039Z,1349974574.039 [DVL_micro](INFO): RSSI output enabled
2012-10-11T16:56:14.039Z,1349974574.039 [DVL_micro](INFO): ADCP output enabled
2012-10-11T16:56:14.040Z,1349974574.040 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2012-10-11T16:56:14.047Z,1349974574.047 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 
2012-10-11T16:56:14.052Z,1349974574.052 [DVL_micro](INFO): pause:Powering down
2012-10-11T16:56:15.176Z,1349974575.176 [Radio_Freewave](INFO): Powering up
2012-10-11T16:56:15.288Z,1349974575.288 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2012-10-11T16:56:15.291Z,1349974575.291 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2012-10-11T16:56:15.297Z,1349974575.297 [ElevatorServo](DEBUG): Initializing EZServoServo.
2012-10-11T16:56:15.299Z,1349974575.299 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2012-10-11T16:56:15.311Z,1349974575.311 [MassServo](DEBUG): Initializing EZServoServo.
2012-10-11T16:56:15.315Z,1349974575.315 [MassServo](DEBUG): Initializing MassServo.
2012-10-11T16:56:15.321Z,1349974575.321 [RudderServo](DEBUG): Initializing EZServoServo.
2012-10-11T16:56:15.322Z,1349974575.322 [RudderServo](DEBUG): Initializing RudderServo.
2012-10-11T16:56:15.328Z,1349974575.328 [ThrusterServo](DEBUG): Initializing EZServoServo.
2012-10-11T16:56:15.332Z,1349974575.332 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2012-10-11T16:56:17.877Z,1349974577.877 [NAL9602](INFO): Powering up NAL9602
2012-10-11T16:56:27.596Z,1349974587.596 [SBIT](IMPORTANT): Beginning Startup BIT
2012-10-11T16:56:27.599Z,1349974587.599 [CBIT](IMPORTANT): Beginning GF scan
2012-10-11T16:56:29.639Z,1349974589.639 [NAL9602](INFO): NAL9602 initialized
2012-10-11T16:56:36.699Z,1349974596.699 [NavChartDb](INFO): Done scanning features of Resources/US5CA50M.000
2012-10-11T16:56:57.207Z,1349974617.207 [CBIT](IMPORTANT): No ground fault detected
2012-10-11T16:57:21.274Z,1349974641.274 [NavChartDb](INFO): # of records loaded: 5000
2012-10-11T16:57:23.580Z,1349974643.580 [SBIT](IMPORTANT): SBIT PASSED
2012-10-11T16:57:24.229Z,1349974644.229 [MissionManager](IMPORTANT): Started mission Startup
2012-10-11T16:57:24.229Z,1349974644.229 [Startup] Running Loop=1
2012-10-11T16:57:24.229Z,1349974644.229 [Startup](INFO): Aggregate::initialize Startup
2012-10-11T16:57:24.229Z,1349974644.229 [Startup:A.GoToSurface] Running Loop=1
2012-10-11T16:57:24.229Z,1349974644.229 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-10-11T16:57:24.239Z,1349974644.239 [Startup:StartupSatComms] Running Loop=1
2012-10-11T16:57:24.240Z,1349974644.240 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2012-10-11T16:57:24.240Z,1349974644.240 [Startup:StartupSatComms:A] Running Loop=1
2012-10-11T16:57:24.473Z,1349974644.473 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2012-10-11T16:57:28.039Z,1349974648.039 [CommandLine](IMPORTANT): got command stop
2012-10-11T16:57:42.928Z,1349974662.928 [NavChartDb](INFO): # of records loaded: 10000
2012-10-11T16:57:43.467Z,1349974663.467 [CommandLine](IMPORTANT): got command failComponent
2012-10-11T16:57:43.467Z,1349974663.467 [CommandLine](IMPORTANT): Failed components:
2012-10-11T16:57:43.467Z,1349974663.467 [CommandLine](IMPORTANT): No failed Components.
2012-10-11T16:58:12.597Z,1349974692.597 [NavChartDb](INFO): # of records loaded: 15000
2012-10-11T16:58:25.129Z,1349974705.129 [Startup:StartupSatComms:A](INFO): Timed out from 2012-10-11T16:57:24.2Z
2012-10-11T16:58:25.129Z,1349974705.129 [Startup:StartupSatComms:A:A_Timeout] Running Loop=1
2012-10-11T16:58:25.129Z,1349974705.129 [Startup:StartupSatComms:A:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:A:A_Timeout
2012-10-11T16:58:25.130Z,1349974705.130 [Startup:StartupSatComms:A:A_Timeout](INFO): Completed Startup:StartupSatComms:A:A_Timeout
2012-10-11T16:58:25.130Z,1349974705.130 [Startup:StartupSatComms:A] Stopped
2012-10-11T16:58:25.130Z,1349974705.130 [Startup:StartupSatComms:B] Running Loop=1
2012-10-11T16:58:26.104Z,1349974706.104 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2012-10-11T16:58:36.360Z,1349974716.360 [NavChartDb](INFO): # of records loaded: 20000
2012-10-11T16:58:58.633Z,1349974738.633 [NavChartDb](INFO): # of records loaded: 25000
2012-10-11T16:59:16.295Z,1349974756.295 [NavChartDb](INFO): # of records loaded: 30000
2012-10-11T16:59:25.269Z,1349974765.269 [Startup:StartupSatComms:B](INFO): Timed out from 2012-10-11T16:58:25.1Z
2012-10-11T16:59:25.269Z,1349974765.269 [Startup:StartupSatComms:B:A_Timeout] Running Loop=1
2012-10-11T16:59:25.269Z,1349974765.269 [Startup:StartupSatComms:B:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:B:A_Timeout
2012-10-11T16:59:25.269Z,1349974765.269 [Startup:StartupSatComms:B:A_Timeout](INFO): Completed Startup:StartupSatComms:B:A_Timeout
2012-10-11T16:59:25.269Z,1349974765.269 [Startup:StartupSatComms:B] Stopped
2012-10-11T16:59:25.269Z,1349974765.269 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2012-10-11T16:59:25.269Z,1349974765.269 [Startup:StartupSatComms] Stopped
2012-10-11T16:59:25.269Z,1349974765.270 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2012-10-11T16:59:25.271Z,1349974765.271 [Startup](INFO): Completed Startup
2012-10-11T16:59:25.271Z,1349974765.271 [Startup] Stopped
2012-10-11T16:59:25.271Z,1349974765.271 [Startup](INFO): Aggregate::uninitialize Startup
2012-10-11T16:59:25.271Z,1349974765.271 [Startup:A.GoToSurface] Stopped
2012-10-11T16:59:25.271Z,1349974765.271 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-10-11T16:59:26.283Z,1349974766.283 [MissionManager](IMPORTANT): Started mission Default
2012-10-11T16:59:26.283Z,1349974766.283 [Default] Running Loop=1
2012-10-11T16:59:26.283Z,1349974766.283 [Default](INFO): Aggregate::initialize Default
2012-10-11T16:59:26.283Z,1349974766.283 [Default:D.SetSpeed] Running Loop=1
2012-10-11T16:59:26.283Z,1349974766.283 [Default:D.SetSpeed](DEBUG): Initialize.
2012-10-11T16:59:26.283Z,1349974766.283 [Default:E.GoToSurface] Running Loop=1
2012-10-11T16:59:26.283Z,1349974766.283 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-10-11T16:59:26.284Z,1349974766.284 [Default:Iridium] Running Loop=1
2012-10-11T16:59:26.284Z,1349974766.284 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2012-10-11T16:59:26.284Z,1349974766.284 [Default:Iridium:A.SetSpeed] Running Loop=1
2012-10-11T16:59:26.284Z,1349974766.284 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2012-10-11T16:59:26.284Z,1349974766.284 [Default:Iridium:B.GoToSurface] Running Loop=1
2012-10-11T16:59:26.284Z,1349974766.284 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-10-11T16:59:26.285Z,1349974766.285 [Default:E.GoToSurface] Running Loop=1
2012-10-11T16:59:26.290Z,1349974766.290 [Default:D.SetSpeed] Running Loop=1
2012-10-11T16:59:26.295Z,1349974766.295 [Default:CallIridium] Running Loop=1
2012-10-11T16:59:26.295Z,1349974766.295 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2012-10-11T16:59:26.295Z,1349974766.295 [Default:CallIridium:A] Running Loop=1
2012-10-11T16:59:26.297Z,1349974766.297 [Default:CallIridium:A] Stopped
2012-10-11T16:59:26.297Z,1349974766.297 [Default:CallIridium:B] Running Loop=1
2012-10-11T16:59:26.297Z,1349974766.297 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2012-10-11T16:59:26.303Z,1349974766.303 [Default:Iridium:B.GoToSurface] Stopped
2012-10-11T16:59:26.303Z,1349974766.303 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-10-11T16:59:26.303Z,1349974766.303 [Default:Iridium:Read_Iridium] Running Loop=1
2012-10-11T16:59:26.303Z,1349974766.303 [Default:Iridium:A.SetSpeed] Running Loop=1
2012-10-11T16:59:26.308Z,1349974766.308 [Default:GPS] Running Loop=1
2012-10-11T16:59:26.308Z,1349974766.308 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2012-10-11T16:59:26.308Z,1349974766.308 [Default:GPS:A.SetSpeed] Running Loop=1
2012-10-11T16:59:26.308Z,1349974766.309 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2012-10-11T16:59:26.309Z,1349974766.309 [Default:GPS:B.GoToSurface] Running Loop=1
2012-10-11T16:59:26.309Z,1349974766.309 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-10-11T16:59:26.318Z,1349974766.318 [Default:GPS:B.GoToSurface] Stopped
2012-10-11T16:59:26.318Z,1349974766.318 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-10-11T16:59:26.319Z,1349974766.319 [Default:GPS:Read_GPS] Running Loop=1
2012-10-11T16:59:26.319Z,1349974766.319 [Default:GPS:A.SetSpeed] Running Loop=1
2012-10-11T16:59:27.898Z,1349974767.898 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2012-10-11T16:59:27.900Z,1349974767.901 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2012-10-11T16:59:43.463Z,1349974783.463 [CommandLine](IMPORTANT): got command failComponent
2012-10-11T16:59:43.463Z,1349974783.463 [CommandLine](IMPORTANT): Failed components:
2012-10-11T16:59:43.463Z,1349974783.464 [CommandLine](IMPORTANT): No failed Components.
2012-10-11T16:59:44.099Z,1349974784.099 [NavChartDb](INFO): # of records loaded: 35000
2012-10-11T16:59:55.631Z,1349974795.631 [CommandLine](IMPORTANT): got command ibit
2012-10-11T16:59:56.141Z,1349974796.141 [IBIT](IMPORTANT): Beginning Initiated BIT
2012-10-11T16:59:56.141Z,1349974796.141 [IBIT](IMPORTANT): Beginning control surface checks.

2012-10-11T16:59:56.142Z,1349974796.142 [CBIT](IMPORTANT): Beginning GF scan
2012-10-11T16:59:56.555Z,1349974796.555 [IBIT](IMPORTANT): Beginning Initiated BIT
2012-10-11T16:59:56.555Z,1349974796.555 [IBIT](IMPORTANT): Beginning control surface checks.

2012-10-11T16:59:56.766Z,1349974796.766 [Radio_Freewave](INFO): Powering down
2012-10-11T16:59:58.103Z,1349974798.103 [Radio_Freewave](INFO): Powering up
2012-10-11T17:00:09.116Z,1349974809.116 [NavChartDb](INFO): # of records loaded: 40000
2012-10-11T17:00:26.804Z,1349974826.804 [CBIT](IMPORTANT): No ground fault detected
2012-10-11T17:00:31.943Z,1349974831.943 [NavChartDb](INFO): # of records loaded: 45000
2012-10-11T17:00:53.240Z,1349974853.240 [NavChartDb](INFO): # of records loaded: 50000
2012-10-11T17:01:22.087Z,1349974882.087 [NavChartDb](INFO): # of records loaded: 55000
2012-10-11T17:01:26.821Z,1349974886.821 [NavChartDb](INFO): Calculating coverage of Resources/US5CA50M.000
2012-10-11T17:01:38.552Z,1349974898.552 [NavChartDb](INFO): Done scanning edges of Resources/US5CA50M.000
2012-10-11T17:01:48.950Z,1349974908.950 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired.
2012-10-11T17:01:49.626Z,1349974909.626 [IBIT](IMPORTANT): batteryCapacityThreshold: 5.000000 Ah
2012-10-11T17:01:49.627Z,1349974909.626 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.500000 V
2012-10-11T17:01:49.627Z,1349974909.627 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 230.399994
Voltage: 16.295624
2012-10-11T17:01:51.155Z,1349974911.155 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2012-10-11T17:01:51.155Z,1349974911.155 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2012-10-11T17:01:51.156Z,1349974911.156 [IBIT](IMPORTANT): Pressure:17.106230 PSI
2012-10-11T17:01:51.156Z,1349974911.156 [IBIT](IMPORTANT): Humidity:23.586622 %
2012-10-11T17:01:52.159Z,1349974912.159 [IBIT](IMPORTANT): surfaceThreshold: 0.500000 m
2012-10-11T17:01:52.160Z,1349974912.159 [IBIT](IMPORTANT): buoyancyDefault: 945.000000 cc
2012-10-11T17:01:52.160Z,1349974912.160 [IBIT](IMPORTANT): stopDepth: 125.000000 m
2012-10-11T17:01:52.160Z,1349974912.160 [IBIT](IMPORTANT): abortDepth: 150.000000 m
2012-10-11T17:01:52.160Z,1349974912.160 [IBIT](IMPORTANT): IBIT FAILED
2012-10-11T17:01:53.222Z,1349974913.222 [NavChartDb](INFO): # of records loaded: 60000
2012-10-11T17:02:25.236Z,1349974945.236 [NavChartDb](INFO): Done scanning nodes of Resources/US5CA50M.000
2012-10-11T17:02:25.273Z,1349974945.273 [NavChartDb](INFO): # of records loaded: 62026
2012-10-11T17:02:25.283Z,1349974945.283 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US5CA50M.000
2012-10-11T17:02:25.284Z,1349974945.284 [NavChartDb](INFO): Setup scan of Resources/US3CA52M.000
2012-10-11T17:02:41.485Z,1349974961.485 [NavChartDb](INFO): Done scanning features of Resources/US3CA52M.000
2012-10-11T17:03:11.713Z,1349974991.713 [NavChartDb](INFO): # of records loaded: 5000
2012-10-11T17:03:39.816Z,1349975019.816 [NavChartDb](INFO): # of records loaded: 10000
2012-10-11T17:03:48.254Z,1349975028.254 [NavChartDb](INFO): # of records loaded: 15000
2012-10-11T17:03:57.673Z,1349975037.673 [NavChartDb](INFO): # of records loaded: 20000
2012-10-11T17:04:10.128Z,1349975050.128 [NavChartDb](INFO): # of records loaded: 25000
2012-10-11T17:04:23.597Z,1349975063.597 [NavChartDb](INFO): # of records loaded: 30000
2012-10-11T17:04:29.574Z,1349975069.574 [NavChartDb](INFO): # of records loaded: 35000
2012-10-11T17:04:43.178Z,1349975083.178 [NavChartDb](INFO): # of records loaded: 40000
2012-10-11T17:05:02.749Z,1349975102.749 [NavChartDb](INFO): # of records loaded: 45000
2012-10-11T17:05:28.532Z,1349975128.532 [NavChartDb](INFO): # of records loaded: 50000
2012-10-11T17:05:48.129Z,1349975148.129 [NavChartDb](INFO): # of records loaded: 55000
2012-10-11T17:06:05.070Z,1349975165.070 [NavChartDb](INFO): # of records loaded: 60000
2012-10-11T17:06:15.161Z,1349975175.161 [NavChartDb](INFO): # of records loaded: 65000
2012-10-11T17:06:28.918Z,1349975188.918 [NavChartDb](INFO): # of records loaded: 70000
2012-10-11T17:06:34.436Z,1349975194.436 [NAL9602](FAULT): GPS failed to acquire within timeout.
2012-10-11T17:06:34.436Z,1349975194.436 [NAL9602] Data Fault, FailCount= 1
2012-10-11T17:06:34.436Z,1349975194.436 [NAL9602](ERROR): Data Fault
2012-10-11T17:06:35.137Z,1349975195.137 [CBIT](ERROR): Data Fault in component: NAL9602
2012-10-11T17:06:35.380Z,1349975195.380 [NAL9602](INFO): Powering down
2012-10-11T17:06:35.789Z,1349975195.789 [CBIT](INFO): Clearing failed state for component NAL9602
2012-10-11T17:06:35.790Z,1349975195.790 [NAL9602] No Fault, FailCount= 1
2012-10-11T17:06:40.389Z,1349975200.389 [NAL9602](INFO): Powering up NAL9602
2012-10-11T17:06:46.297Z,1349975206.297 [NavChartDb](INFO): # of records loaded: 75000
2012-10-11T17:06:51.119Z,1349975211.119 [NAL9602](INFO): NAL9602 initialized
2012-10-11T17:07:07.945Z,1349975227.945 [NavChartDb](INFO): # of records loaded: 80000
2012-10-11T17:07:20.076Z,1349975240.076 [NavChartDb](INFO): # of records loaded: 85000
2012-10-11T17:07:41.786Z,1349975261.786 [NavChartDb](INFO): # of records loaded: 90000
2012-10-11T17:08:02.082Z,1349975282.082 [NavChartDb](INFO): # of records loaded: 95000
2012-10-11T17:08:26.443Z,1349975306.443 [NavChartDb](INFO): # of records loaded: 100000
2012-10-11T17:08:52.623Z,1349975332.623 [NavChartDb](INFO): # of records loaded: 105000
2012-10-11T17:09:13.825Z,1349975353.825 [NavChartDb](INFO): # of records loaded: 110000
2012-10-11T17:09:32.700Z,1349975372.700 [NavChartDb](INFO): Calculating coverage of Resources/US3CA52M.000
2012-10-11T17:09:38.385Z,1349975378.385 [NavChartDb](INFO): Done scanning edges of Resources/US3CA52M.000
2012-10-11T17:09:48.885Z,1349975388.885 [NavChartDb](INFO): # of records loaded: 115000
2012-10-11T17:10:11.172Z,1349975411.172 [NavChartDb](INFO): Done scanning nodes of Resources/US3CA52M.000
2012-10-11T17:10:11.239Z,1349975411.239 [NavChartDb](INFO): # of records loaded: 117290
2012-10-11T17:10:11.246Z,1349975411.246 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US3CA52M.000
2012-10-11T17:10:11.248Z,1349975411.248 [NavChartDb](INFO): Setup scan of Resources/US2WC11M.000
2012-10-11T17:10:21.104Z,1349975421.103 [NavChartDb](INFO): Done scanning features of Resources/US2WC11M.000
2012-10-11T17:10:47.764Z,1349975447.764 [NavChartDb](INFO): # of records loaded: 5000
2012-10-11T17:11:12.038Z,1349975472.038 [NavChartDb](INFO): # of records loaded: 10000
2012-10-11T17:11:36.560Z,1349975496.560 [NavChartDb](INFO): # of records loaded: 15000
2012-10-11T17:12:00.949Z,1349975520.949 [NavChartDb](INFO): # of records loaded: 20000
2012-10-11T17:12:26.926Z,1349975546.926 [NavChartDb](INFO): # of records loaded: 25000
2012-10-11T17:12:52.509Z,1349975572.509 [NavChartDb](INFO): # of records loaded: 30000
2012-10-11T17:13:16.668Z,1349975596.668 [NavChartDb](INFO): # of records loaded: 35000
2012-10-11T17:13:40.869Z,1349975620.869 [NavChartDb](INFO): # of records loaded: 40000
2012-10-11T17:13:44.471Z,1349975624.471 [NavChartDb](INFO): Calculating coverage of Resources/US2WC11M.000
2012-10-11T17:13:47.528Z,1349975627.528 [NavChartDb](INFO): Done scanning edges of Resources/US2WC11M.000
2012-10-11T17:14:10.777Z,1349975650.777 [NavChartDb](INFO): Done scanning nodes of Resources/US2WC11M.000
2012-10-11T17:14:10.827Z,1349975650.827 [NavChartDb](INFO): # of records loaded: 44880
2012-10-11T17:14:10.833Z,1349975650.833 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US2WC11M.000
2012-10-11T17:14:10.836Z,1349975650.836 [NavChartDb](INFO): Setup scan of Resources/US1WC07M.000
2012-10-11T17:14:32.956Z,1349975672.955 [NavChartDb](INFO): Done scanning features of Resources/US1WC07M.000
2012-10-11T17:15:05.954Z,1349975705.954 [NavChartDb](INFO): # of records loaded: 5000
2012-10-11T17:15:30.996Z,1349975730.996 [NavChartDb](INFO): # of records loaded: 10000
2012-10-11T17:15:57.403Z,1349975757.403 [NavChartDb](INFO): # of records loaded: 15000
2012-10-11T17:16:21.921Z,1349975781.921 [NavChartDb](INFO): # of records loaded: 20000
2012-10-11T17:16:28.969Z,1349975788.969 [NavChartDb](INFO): Calculating coverage of Resources/US1WC07M.000
2012-10-11T17:16:36.053Z,1349975796.053 [NavChartDb](INFO): Done scanning edges of Resources/US1WC07M.000
2012-10-11T17:16:55.592Z,1349975815.592 [NAL9602](FAULT): GPS failed to acquire within timeout.
2012-10-11T17:16:55.592Z,1349975815.592 [NAL9602] Data Fault, FailCount= 2
2012-10-11T17:16:55.592Z,1349975815.592 [NAL9602](ERROR): Data Fault
2012-10-11T17:16:56.257Z,1349975816.257 [CBIT](ERROR): Data Fault in component: NAL9602
2012-10-11T17:16:56.258Z,1349975816.258 [CBIT](CRITICAL): Data Fault in component: NAL9602
2012-10-11T17:16:56.468Z,1349975816.468 [NAL9602](INFO): Powering down
2012-10-11T17:17:26.193Z,1349975846.194 [NavChartDb](INFO): Done scanning nodes of Resources/US1WC07M.000
2012-10-11T17:17:26.585Z,1349975846.585 [NavChartDb](INFO): # of records loaded: 24424
2012-10-11T17:17:26.596Z,1349975846.596 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US1WC07M.000
2012-10-11T17:17:30.830Z,1349975850.830 [NavChartDb](INFO): Creating index for soundings
2012-10-11T17:17:42.309Z,1349975862.309 [NavChartDb](INFO): Creating index for 0p0
2012-10-11T17:17:44.744Z,1349975864.744 [NavChartDb](INFO): Creating index for 1p8
2012-10-11T17:17:45.621Z,1349975865.621 [NavChartDb](INFO): Creating index for 3p6
2012-10-11T17:17:48.464Z,1349975868.464 [NavChartDb](INFO): Creating index for 5p4
2012-10-11T17:17:50.057Z,1349975870.057 [NavChartDb](INFO): Creating index for 9p1
2012-10-11T17:17:50.080Z,1349975870.080 [NavChartDb](INFO): Creating index for 10p9
2012-10-11T17:17:51.953Z,1349975871.953 [NavChartDb](INFO): Creating index for 18p2
2012-10-11T17:17:56.212Z,1349975876.212 [NavChartDb](INFO): Creating index for 36p5
2012-10-11T17:18:00.655Z,1349975880.655 [NavChartDb](INFO): Creating index for 54p8
2012-10-11T17:18:04.553Z,1349975884.553 [NavChartDb](INFO): Creating index for 73p1
2012-10-11T17:18:07.627Z,1349975887.627 [NavChartDb](INFO): Creating index for 91p4
2012-10-11T17:18:14.826Z,1349975894.826 [NavChartDb](INFO): Creating index for 182p8
2012-10-11T17:18:20.027Z,1349975900.027 [NavChartDb](INFO): Creating index for 365p7
2012-10-11T17:18:24.078Z,1349975904.078 [NavChartDb](INFO): Creating index for 548p6
2012-10-11T17:18:26.864Z,1349975906.864 [NavChartDb](INFO): Creating index for 731p5
2012-10-11T17:18:34.766Z,1349975914.766 [NavChartDb](INFO): Creating index for 914p4
2012-10-11T17:18:41.032Z,1349975921.032 [NavChartDb](INFO): Creating index for 1097p2
2012-10-11T17:18:43.586Z,1349975923.586 [NavChartDb](INFO): Creating index for 1280p1
2012-10-11T17:18:46.552Z,1349975926.552 [NavChartDb](INFO): Creating index for 1463p0
2012-10-11T17:18:48.739Z,1349975928.739 [NavChartDb](INFO): Creating index for 1645p9
2012-10-11T17:18:56.002Z,1349975936.002 [CBIT](INFO): Clearing failed count for component NAL9602
2012-10-11T17:18:56.002Z,1349975936.002 [NAL9602] No Fault, FailCount= 2
2012-10-11T17:18:56.209Z,1349975936.209 [NAL9602](INFO): Powering up NAL9602
2012-10-11T17:18:57.618Z,1349975937.618 [NavChartDb](INFO): Creating index for 1828p8
2012-10-11T17:19:02.368Z,1349975942.368 [NavChartDb](INFO): Creating index for 2011p6
2012-10-11T17:19:04.152Z,1349975944.152 [NavChartDb](INFO): Creating index for 2194p5
2012-10-11T17:19:04.877Z,1349975944.877 [NavChartDb](INFO): Creating index for 2377p4
2012-10-11T17:19:06.937Z,1349975946.937 [NavChartDb](INFO): Creating index for 2560p3
2012-10-11T17:19:07.467Z,1349975947.467 [NAL9602](INFO): NAL9602 initialized
2012-10-11T17:19:08.055Z,1349975948.055 [NavChartDb](INFO): Creating index for 2743p2
2012-10-11T17:19:11.420Z,1349975951.420 [NavChartDb](INFO): Creating index for 2926p0
2012-10-11T17:19:12.942Z,1349975952.942 [NavChartDb](INFO): Creating index for 3108p9
2012-10-11T17:19:13.412Z,1349975953.412 [NavChartDb](INFO): Creating index for 3291p8
2012-10-11T17:19:14.416Z,1349975954.416 [NavChartDb](INFO): Creating index for 3474p7
2012-10-11T17:19:25.312Z,1349975965.312 [NavChartDb](INFO): Creating index for 3657p6
2012-10-11T17:20:19.946Z,1349976019.945 [NAL9602](INFO): SBD MO Status=2, MOMSN=1554, MT Status=2, MTMSN=0
2012-10-11T17:20:19.946Z,1349976019.946 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:20:46.074Z,1349976046.074 [NAL9602](INFO): SBD MO Status=2, MOMSN=1554, MT Status=2, MTMSN=0
2012-10-11T17:20:46.074Z,1349976046.074 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:21:31.410Z,1349976091.410 [NAL9602](INFO): SBD MO Status=2, MOMSN=1554, MT Status=2, MTMSN=0
2012-10-11T17:21:31.410Z,1349976091.410 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:21:32.612Z,1349976092.612 [NAL9602](IMPORTANT): GPS fix at: 1349976094.00
2012-10-11T17:21:32.628Z,1349976092.628 [Default:GPS:Read_GPS] Stopped
2012-10-11T17:21:32.628Z,1349976092.628 [Default:GPS:D] Running Loop=1
2012-10-11T17:21:33.028Z,1349976093.028 [Default:GPS:D] Stopped
2012-10-11T17:21:33.028Z,1349976093.028 [Default:GPS](INFO): Completed Default:GPS
2012-10-11T17:21:33.028Z,1349976093.028 [Default:GPS] Stopped
2012-10-11T17:21:33.029Z,1349976093.029 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2012-10-11T17:21:33.029Z,1349976093.029 [Default:GPS:A.SetSpeed] Stopped
2012-10-11T17:21:33.029Z,1349976093.029 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2012-10-11T17:21:48.394Z,1349976108.394 [NAL9602](INFO): SBD MO Status=2, MOMSN=1554, MT Status=2, MTMSN=0
2012-10-11T17:21:48.394Z,1349976108.394 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:22:15.204Z,1349976135.204 [NAL9602](INFO): SBD MO Status=2, MOMSN=1554, MT Status=2, MTMSN=0
2012-10-11T17:22:15.204Z,1349976135.204 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:25:38.681Z,1349976338.681 [NAL9602](INFO): SBD MO Status=2, MOMSN=1554, MT Status=2, MTMSN=0
2012-10-11T17:25:38.681Z,1349976338.681 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:25:56.017Z,1349976356.017 [NAL9602](INFO): SBD MO Status=2, MOMSN=1554, MT Status=2, MTMSN=0
2012-10-11T17:25:56.017Z,1349976356.017 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:26:04.584Z,1349976364.584 [NAL9602](INFO): SBD MO Status=2, MOMSN=1554, MT Status=2, MTMSN=0
2012-10-11T17:26:04.584Z,1349976364.584 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:26:21.940Z,1349976381.940 [NAL9602](INFO): SBD MO Status=2, MOMSN=1554, MT Status=2, MTMSN=0
2012-10-11T17:26:21.940Z,1349976381.940 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:26:30.480Z,1349976390.480 [NAL9602](INFO): SBD MO Status=2, MOMSN=1554, MT Status=2, MTMSN=0
2012-10-11T17:26:30.480Z,1349976390.480 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:26:39.056Z,1349976399.056 [NAL9602](INFO): SBD MO Status=2, MOMSN=1554, MT Status=2, MTMSN=0
2012-10-11T17:26:39.056Z,1349976399.056 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:26:47.772Z,1349976407.772 [NAL9602](INFO): SBD MO Status=2, MOMSN=1554, MT Status=2, MTMSN=0
2012-10-11T17:26:47.772Z,1349976407.772 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:26:56.394Z,1349976416.394 [NAL9602](INFO): SBD MO Status=2, MOMSN=1554, MT Status=2, MTMSN=0
2012-10-11T17:26:56.394Z,1349976416.394 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:27:04.912Z,1349976424.912 [NAL9602](INFO): SBD MO Status=2, MOMSN=1554, MT Status=2, MTMSN=0
2012-10-11T17:27:04.912Z,1349976424.912 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:27:13.492Z,1349976433.492 [NAL9602](INFO): SBD MO Status=2, MOMSN=1554, MT Status=2, MTMSN=0
2012-10-11T17:27:13.492Z,1349976433.492 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:27:22.542Z,1349976442.542 [NAL9602](INFO): SBD MO Status=2, MOMSN=1554, MT Status=2, MTMSN=0
2012-10-11T17:27:22.542Z,1349976442.542 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:27:30.832Z,1349976450.832 [NAL9602](INFO): SBD MO Status=2, MOMSN=1554, MT Status=2, MTMSN=0
2012-10-11T17:27:30.832Z,1349976450.832 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:27:44.980Z,1349976464.980 [NAL9602](INFO): SBD MO Status=1, MOMSN=1554, MT Status=0, MTMSN=0
2012-10-11T17:27:45.015Z,1349976465.015 [NAL9602](INFO): Sent 332 bytes from file Logs/20121011T164800/shore0000.lzma
2012-10-11T17:27:45.015Z,1349976465.015 [NAL9602](INFO): Packets left to send: 1
2012-10-11T17:27:45.018Z,1349976465.018 [NAL9602](INFO): Stored copy of sent data in Logs/20121011T164800/shore0000.lzma.parts/0001.sbd
2012-10-11T17:27:53.604Z,1349976473.604 [NAL9602](INFO): SBD MO Status=2, MOMSN=1555, MT Status=2, MTMSN=0
2012-10-11T17:27:53.604Z,1349976473.604 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:28:01.770Z,1349976481.770 [NAL9602](INFO): SBD MO Status=2, MOMSN=1555, MT Status=2, MTMSN=0
2012-10-11T17:28:01.770Z,1349976481.770 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:28:13.737Z,1349976493.737 [NAL9602](INFO): SBD MO Status=1, MOMSN=1555, MT Status=0, MTMSN=0
2012-10-11T17:28:13.775Z,1349976493.775 [NAL9602](INFO): Sent 227 bytes from file Logs/20121011T164800/shore0000.lzma
2012-10-11T17:28:13.775Z,1349976493.775 [NAL9602](INFO): Packets left to send: 0
2012-10-11T17:28:13.776Z,1349976493.776 [NAL9602](INFO): Stored copy of sent data in Logs/20121011T164800/shore0000.lzma.parts/0000.sbd
2012-10-11T17:28:48.041Z,1349976528.041 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:28:48.041Z,1349976528.041 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:28:56.976Z,1349976536.976 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:28:56.976Z,1349976536.976 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:29:05.516Z,1349976545.516 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:29:05.516Z,1349976545.516 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:29:27.294Z,1349976567.294 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:29:27.294Z,1349976567.294 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:30:06.630Z,1349976606.630 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:30:06.630Z,1349976606.630 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:30:08.851Z,1349976608.851 [CommandLine](IMPORTANT): got command failComponent
2012-10-11T17:30:08.851Z,1349976608.851 [CommandLine](IMPORTANT): Failed components:
2012-10-11T17:30:08.851Z,1349976608.851 [CommandLine](IMPORTANT): No failed Components.
2012-10-11T17:30:14.047Z,1349976614.047 [CommandLine](IMPORTANT): got command ibit
2012-10-11T17:30:14.974Z,1349976614.974 [IBIT](IMPORTANT): Beginning Initiated BIT
2012-10-11T17:30:14.974Z,1349976614.974 [IBIT](IMPORTANT): Beginning control surface checks.

2012-10-11T17:30:14.976Z,1349976614.976 [CBIT](IMPORTANT): Beginning GF scan
2012-10-11T17:30:15.592Z,1349976615.592 [Radio_Freewave](INFO): Powering down
2012-10-11T17:30:17.043Z,1349976617.043 [Radio_Freewave](INFO): Powering up
2012-10-11T17:30:31.264Z,1349976631.264 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:30:31.264Z,1349976631.264 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:30:32.465Z,1349976632.465 [NAL9602](IMPORTANT): GPS fix at: 1349976636.00
2012-10-11T17:30:42.047Z,1349976642.047 [CBIT](IMPORTANT): No ground fault detected
2012-10-11T17:30:47.662Z,1349976647.662 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:30:47.662Z,1349976647.662 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:30:48.826Z,1349976648.826 [NAL9602](IMPORTANT): GPS fix at: 1349976652.00
2012-10-11T17:30:56.204Z,1349976656.204 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:30:56.204Z,1349976656.204 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:30:57.407Z,1349976657.407 [NAL9602](IMPORTANT): GPS fix at: 1349976661.00
2012-10-11T17:31:01.393Z,1349976661.393 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 5
Latitude: 36.802834 Longitude: -121.788002
2012-10-11T17:31:01.743Z,1349976661.743 [IBIT](IMPORTANT): batteryCapacityThreshold: 5.000000 Ah
2012-10-11T17:31:01.744Z,1349976661.744 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.500000 V
2012-10-11T17:31:01.744Z,1349976661.744 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 230.149994
Voltage: 16.288437
2012-10-11T17:31:04.176Z,1349976664.176 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2012-10-11T17:31:04.176Z,1349976664.176 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2012-10-11T17:31:04.177Z,1349976664.177 [IBIT](IMPORTANT): Pressure:17.637238 PSI
2012-10-11T17:31:04.177Z,1349976664.177 [IBIT](IMPORTANT): Humidity:22.724665 %
2012-10-11T17:31:04.477Z,1349976664.477 [IBIT](IMPORTANT): surfaceThreshold: 0.500000 m
2012-10-11T17:31:04.478Z,1349976664.478 [IBIT](IMPORTANT): buoyancyDefault: 945.000000 cc
2012-10-11T17:31:04.478Z,1349976664.478 [IBIT](IMPORTANT): stopDepth: 125.000000 m
2012-10-11T17:31:04.479Z,1349976664.479 [IBIT](IMPORTANT): abortDepth: 150.000000 m
2012-10-11T17:31:04.479Z,1349976664.479 [IBIT](IMPORTANT): IBIT PASSED
2012-10-11T17:31:04.788Z,1349976664.788 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:31:04.788Z,1349976664.788 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:31:13.616Z,1349976673.616 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:31:13.616Z,1349976673.616 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:31:22.349Z,1349976682.349 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:31:22.349Z,1349976682.349 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:31:30.896Z,1349976690.896 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:31:30.896Z,1349976690.896 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:31:39.268Z,1349976699.268 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:31:39.268Z,1349976699.268 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:31:48.266Z,1349976708.266 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:31:48.266Z,1349976708.266 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:32:06.028Z,1349976726.028 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:32:06.028Z,1349976726.028 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:33:59.944Z,1349976839.944 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:33:59.944Z,1349976839.944 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:34:16.517Z,1349976856.517 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:34:16.517Z,1349976856.517 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:34:18.283Z,1349976858.283 [CommandLine](IMPORTANT): got command failComponent
2012-10-11T17:34:18.283Z,1349976858.283 [CommandLine](IMPORTANT): Failed components:
2012-10-11T17:34:18.283Z,1349976858.283 [CommandLine](IMPORTANT): No failed Components.
2012-10-11T17:34:25.130Z,1349976865.130 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:34:25.130Z,1349976865.130 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:34:33.697Z,1349976873.697 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:34:33.697Z,1349976873.697 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:34:42.272Z,1349976882.272 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:34:42.272Z,1349976882.272 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:34:50.884Z,1349976890.884 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:34:50.884Z,1349976890.884 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:34:59.481Z,1349976899.480 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:34:59.481Z,1349976899.481 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:35:08.433Z,1349976908.433 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:35:08.433Z,1349976908.434 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:35:17.070Z,1349976917.070 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:35:17.070Z,1349976917.070 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:35:25.540Z,1349976925.540 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:35:25.540Z,1349976925.540 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:35:34.080Z,1349976934.080 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:35:34.080Z,1349976934.080 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:35:43.458Z,1349976943.458 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:35:43.458Z,1349976943.458 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:35:51.833Z,1349976951.833 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:35:51.834Z,1349976951.833 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:36:08.813Z,1349976968.813 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:36:08.813Z,1349976968.813 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:36:17.449Z,1349976977.449 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:36:17.450Z,1349976977.450 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:36:26.034Z,1349976986.034 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:36:26.034Z,1349976986.034 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:36:34.548Z,1349976994.548 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:36:34.548Z,1349976994.548 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:36:43.092Z,1349977003.092 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:36:43.092Z,1349977003.092 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:36:51.692Z,1349977011.692 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:36:51.692Z,1349977011.692 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:37:00.228Z,1349977020.228 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:37:00.228Z,1349977020.228 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:37:16.772Z,1349977036.772 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:37:16.772Z,1349977036.773 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:37:25.348Z,1349977045.348 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:37:25.348Z,1349977045.348 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:37:33.940Z,1349977053.940 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:37:33.940Z,1349977053.940 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:37:42.932Z,1349977062.932 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:37:42.932Z,1349977062.932 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:37:51.476Z,1349977071.476 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:37:51.476Z,1349977071.476 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:38:00.066Z,1349977080.066 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:38:00.066Z,1349977080.066 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:38:17.422Z,1349977097.422 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:38:17.422Z,1349977097.422 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:38:25.944Z,1349977105.944 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:38:25.944Z,1349977105.944 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:38:34.536Z,1349977114.536 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:38:34.536Z,1349977114.536 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:38:43.898Z,1349977123.898 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:38:43.898Z,1349977123.898 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:39:00.042Z,1349977140.042 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:39:00.042Z,1349977140.042 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:39:18.561Z,1349977158.561 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:39:18.561Z,1349977158.561 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:39:39.306Z,1349977179.306 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:39:39.306Z,1349977179.306 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:40:17.025Z,1349977217.026 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:40:17.026Z,1349977217.026 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:40:25.961Z,1349977225.961 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:40:25.961Z,1349977225.961 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:40:44.694Z,1349977244.694 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:40:44.694Z,1349977244.694 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:41:10.938Z,1349977270.938 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:41:10.938Z,1349977270.938 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:41:27.478Z,1349977287.478 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:41:27.478Z,1349977287.478 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:41:36.005Z,1349977296.005 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:41:36.005Z,1349977296.005 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:41:44.722Z,1349977304.722 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:41:44.722Z,1349977304.722 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:41:53.326Z,1349977313.326 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:41:53.326Z,1349977313.326 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:42:19.092Z,1349977339.092 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:42:19.092Z,1349977339.092 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:42:27.720Z,1349977347.720 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:42:27.720Z,1349977347.720 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:42:43.508Z,1349977363.508 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:42:43.508Z,1349977363.508 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:42:51.722Z,1349977371.722 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:42:51.722Z,1349977371.722 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:43:00.486Z,1349977380.486 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:43:00.486Z,1349977380.486 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:43:17.560Z,1349977397.560 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:43:17.560Z,1349977397.560 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:43:26.132Z,1349977406.132 [NAL9602](INFO): SBD MO Status=2, MOMSN=1556, MT Status=2, MTMSN=0
2012-10-11T17:43:26.132Z,1349977406.132 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:43:39.513Z,1349977419.513 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=1556, MT Status=1, MTMSN=144
2012-10-11T17:43:39.551Z,1349977419.551 [NAL9602](INFO): Sent 332 bytes from file Logs/20121011T165600/shore0000.lzma
2012-10-11T17:43:39.551Z,1349977419.551 [NAL9602](INFO): Packets left to send: 2
2012-10-11T17:43:39.555Z,1349977419.556 [NAL9602](INFO): Stored copy of sent data in Logs/20121011T165600/shore0000.lzma.parts/0002.sbd
2012-10-11T17:43:39.991Z,1349977419.991 [NAL9602](INFO): Received command:get CBIT.pressureThreshold
2012-10-11T17:43:40.318Z,1349977420.318 [CommandLine](IMPORTANT): got command get CBIT.pressureThreshold
2012-10-11T17:43:40.319Z,1349977420.319 [CommandLine](IMPORTANT): CBIT.pressureThreshold 0.750000 pound_per_square_inch
2012-10-11T17:43:54.322Z,1349977434.322 [NAL9602](INFO): SBD MO Status=2, MOMSN=1557, MT Status=2, MTMSN=0
2012-10-11T17:43:54.322Z,1349977434.322 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:44:02.889Z,1349977442.889 [NAL9602](INFO): SBD MO Status=2, MOMSN=1557, MT Status=2, MTMSN=0
2012-10-11T17:44:02.890Z,1349977442.890 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:44:11.465Z,1349977451.465 [NAL9602](INFO): SBD MO Status=2, MOMSN=1557, MT Status=2, MTMSN=0
2012-10-11T17:44:11.465Z,1349977451.465 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:44:20.061Z,1349977460.061 [NAL9602](INFO): SBD MO Status=2, MOMSN=1557, MT Status=2, MTMSN=0
2012-10-11T17:44:20.061Z,1349977460.061 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:44:44.601Z,1349977484.601 [NAL9602](INFO): SBD MO Status=2, MOMSN=1557, MT Status=2, MTMSN=0
2012-10-11T17:44:44.601Z,1349977484.601 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:45:00.758Z,1349977500.758 [NAL9602](INFO): SBD MO Status=2, MOMSN=1557, MT Status=2, MTMSN=0
2012-10-11T17:45:00.758Z,1349977500.758 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:45:09.324Z,1349977509.324 [NAL9602](INFO): SBD MO Status=2, MOMSN=1557, MT Status=2, MTMSN=0
2012-10-11T17:45:09.324Z,1349977509.324 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:45:17.898Z,1349977517.898 [NAL9602](INFO): SBD MO Status=2, MOMSN=1557, MT Status=2, MTMSN=0
2012-10-11T17:45:17.898Z,1349977517.898 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:45:26.472Z,1349977526.472 [NAL9602](INFO): SBD MO Status=2, MOMSN=1557, MT Status=2, MTMSN=0
2012-10-11T17:45:26.472Z,1349977526.472 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:45:35.036Z,1349977535.036 [NAL9602](INFO): SBD MO Status=2, MOMSN=1557, MT Status=2, MTMSN=0
2012-10-11T17:45:35.036Z,1349977535.036 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:45:53.182Z,1349977553.182 [NAL9602](INFO): SBD MO Status=2, MOMSN=1557, MT Status=2, MTMSN=0
2012-10-11T17:45:53.182Z,1349977553.182 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:46:01.737Z,1349977561.737 [NAL9602](INFO): SBD MO Status=2, MOMSN=1557, MT Status=2, MTMSN=0
2012-10-11T17:46:01.738Z,1349977561.737 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:46:10.708Z,1349977570.708 [NAL9602](INFO): SBD MO Status=2, MOMSN=1557, MT Status=2, MTMSN=0
2012-10-11T17:46:10.708Z,1349977570.708 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:46:27.945Z,1349977587.945 [NAL9602](INFO): SBD MO Status=2, MOMSN=1557, MT Status=2, MTMSN=0
2012-10-11T17:46:27.945Z,1349977587.945 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:46:36.497Z,1349977596.497 [NAL9602](INFO): SBD MO Status=2, MOMSN=1557, MT Status=2, MTMSN=0
2012-10-11T17:46:36.498Z,1349977596.498 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:46:45.065Z,1349977605.065 [NAL9602](INFO): SBD MO Status=2, MOMSN=1557, MT Status=2, MTMSN=0
2012-10-11T17:46:45.065Z,1349977605.066 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:46:53.620Z,1349977613.620 [NAL9602](INFO): SBD MO Status=2, MOMSN=1557, MT Status=2, MTMSN=0
2012-10-11T17:46:53.620Z,1349977613.620 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:47:02.413Z,1349977622.413 [NAL9602](INFO): SBD MO Status=2, MOMSN=1557, MT Status=2, MTMSN=0
2012-10-11T17:47:02.414Z,1349977622.414 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:47:18.210Z,1349977638.210 [NAL9602](INFO): SBD MO Status=2, MOMSN=1557, MT Status=2, MTMSN=0
2012-10-11T17:47:18.210Z,1349977638.210 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:47:26.988Z,1349977646.988 [NAL9602](INFO): SBD MO Status=2, MOMSN=1557, MT Status=2, MTMSN=0
2012-10-11T17:47:26.988Z,1349977646.988 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:47:42.354Z,1349977662.353 [NAL9602](INFO): SBD MO Status=2, MOMSN=1557, MT Status=2, MTMSN=0
2012-10-11T17:47:42.354Z,1349977662.354 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:47:50.598Z,1349977670.598 [NAL9602](INFO): SBD MO Status=2, MOMSN=1557, MT Status=2, MTMSN=0
2012-10-11T17:47:50.598Z,1349977670.598 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:47:59.837Z,1349977679.837 [NAL9602](INFO): SBD MO Status=2, MOMSN=1557, MT Status=2, MTMSN=0
2012-10-11T17:47:59.837Z,1349977679.837 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:48:16.094Z,1349977696.094 [NAL9602](INFO): SBD MO Status=2, MOMSN=1557, MT Status=2, MTMSN=0
2012-10-11T17:48:16.094Z,1349977696.094 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:48:39.016Z,1349977719.016 [NAL9602](INFO): SBD MO Status=2, MOMSN=1557, MT Status=2, MTMSN=0
2012-10-11T17:48:39.016Z,1349977719.016 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:48:47.162Z,1349977727.162 [NAL9602](INFO): SBD MO Status=2, MOMSN=1557, MT Status=2, MTMSN=0
2012-10-11T17:48:47.163Z,1349977727.163 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:48:56.169Z,1349977736.168 [NAL9602](INFO): SBD MO Status=2, MOMSN=1557, MT Status=2, MTMSN=0
2012-10-11T17:48:56.169Z,1349977736.169 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:49:13.190Z,1349977753.190 [NAL9602](INFO): SBD MO Status=2, MOMSN=1557, MT Status=2, MTMSN=0
2012-10-11T17:49:13.190Z,1349977753.190 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:49:22.161Z,1349977762.161 [NAL9602](INFO): SBD MO Status=2, MOMSN=1557, MT Status=2, MTMSN=0
2012-10-11T17:49:22.162Z,1349977762.162 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:49:34.332Z,1349977774.332 [NAL9602](INFO): SBD MO Status=1, MOMSN=1557, MT Status=0, MTMSN=0
2012-10-11T17:49:34.371Z,1349977774.371 [NAL9602](INFO): Sent 332 bytes from file Logs/20121011T165600/shore0000.lzma
2012-10-11T17:49:34.371Z,1349977774.371 [NAL9602](INFO): Packets left to send: 1
2012-10-11T17:49:34.372Z,1349977774.372 [NAL9602](INFO): Stored copy of sent data in Logs/20121011T165600/shore0000.lzma.parts/0001.sbd
2012-10-11T17:49:42.957Z,1349977782.957 [NAL9602](INFO): SBD MO Status=2, MOMSN=1558, MT Status=2, MTMSN=0
2012-10-11T17:49:42.957Z,1349977782.957 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:49:56.537Z,1349977796.537 [NAL9602](INFO): SBD MO Status=2, MOMSN=1558, MT Status=2, MTMSN=0
2012-10-11T17:49:56.538Z,1349977796.537 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:50:04.400Z,1349977804.400 [NAL9602](INFO): SBD MO Status=2, MOMSN=1558, MT Status=2, MTMSN=0
2012-10-11T17:50:04.400Z,1349977804.400 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:50:13.745Z,1349977813.745 [NAL9602](INFO): SBD MO Status=2, MOMSN=1558, MT Status=2, MTMSN=0
2012-10-11T17:50:13.746Z,1349977813.746 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:51:49.205Z,1349977909.205 [NAL9602](INFO): SBD MO Status=1, MOMSN=1558, MT Status=0, MTMSN=0
2012-10-11T17:51:49.243Z,1349977909.243 [NAL9602](INFO): Sent 31 bytes from file Logs/20121011T165600/shore0000.lzma
2012-10-11T17:51:49.243Z,1349977909.243 [NAL9602](INFO): Packets left to send: 0
2012-10-11T17:51:49.244Z,1349977909.244 [NAL9602](INFO): Stored copy of sent data in Logs/20121011T165600/shore0000.lzma.parts/0000.sbd
2012-10-11T17:51:55.200Z,1349977915.200 [NAL9602](INFO): SBD MO Status=2, MOMSN=1559, MT Status=2, MTMSN=0
2012-10-11T17:51:55.200Z,1349977915.200 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:52:06.354Z,1349977926.354 [NAL9602](INFO): SBD MO Status=0, MOMSN=1559, MT Status=0, MTMSN=0
2012-10-11T17:52:19.354Z,1349977939.354 [NAL9602](INFO): SBD MO Status=1, MOMSN=1560, MT Status=0, MTMSN=0
2012-10-11T17:52:19.395Z,1349977939.395 [NAL9602](INFO): Sent 332 bytes from file Logs/20121011T165600/shore0001.lzma
2012-10-11T17:52:19.395Z,1349977939.395 [NAL9602](INFO): Packets left to send: 4
2012-10-11T17:52:19.397Z,1349977939.397 [NAL9602](INFO): Stored copy of sent data in Logs/20121011T165600/shore0001.lzma.parts/0004.sbd
2012-10-11T17:52:31.049Z,1349977951.049 [NAL9602](INFO): SBD MO Status=1, MOMSN=1561, MT Status=0, MTMSN=0
2012-10-11T17:52:31.087Z,1349977951.087 [NAL9602](INFO): Sent 332 bytes from file Logs/20121011T165600/shore0001.lzma
2012-10-11T17:52:31.087Z,1349977951.087 [NAL9602](INFO): Packets left to send: 3
2012-10-11T17:52:31.088Z,1349977951.088 [NAL9602](INFO): Stored copy of sent data in Logs/20121011T165600/shore0001.lzma.parts/0003.sbd
2012-10-11T17:52:53.674Z,1349977973.674 [NAL9602](INFO): SBD MO Status=2, MOMSN=1562, MT Status=2, MTMSN=0
2012-10-11T17:52:53.674Z,1349977973.674 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-10-11T17:53:11.850Z,1349977991.850 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=1562, MT Status=1, MTMSN=145
2012-10-11T17:53:11.891Z,1349977991.891 [NAL9602](INFO): Sent 332 bytes from file Logs/20121011T165600/shore0001.lzma
2012-10-11T17:53:11.891Z,1349977991.891 [NAL9602](INFO): Packets left to send: 2
2012-10-11T17:53:11.892Z,1349977991.892 [NAL9602](INFO): Stored copy of sent data in Logs/20121011T165600/shore0001.lzma.parts/0002.sbd
2012-10-11T17:53:12.295Z,1349977992.295 [NAL9602](INFO): Received command:get CBIT.pressureThreshold
2012-10-11T17:53:12.622Z,1349977992.622 [CommandLine](IMPORTANT): got command get CBIT.pressureThreshold
2012-10-11T17:53:12.623Z,1349977992.623 [CommandLine](IMPORTANT): CBIT.pressureThreshold 0.750000 pound_per_square_inch
2012-10-11T17:53:33.076Z,1349978013.076 [NAL9602](INFO): SBD MO Status=1, MOMSN=1563, MT Status=0, MTMSN=0
2012-10-11T17:53:33.111Z,1349978013.111 [NAL9602](INFO): Sent 332 bytes from file Logs/20121011T165600/shore0001.lzma
2012-10-11T17:53:33.111Z,1349978013.111 [NAL9602](INFO): Packets left to send: 1
2012-10-11T17:53:33.112Z,1349978013.112 [NAL9602](INFO): Stored copy of sent data in Logs/20121011T165600/shore0001.lzma.parts/0001.sbd
2012-10-11T17:53:43.504Z,1349978023.504 [NAL9602](INFO): SBD MO Status=1, MOMSN=1564, MT Status=0, MTMSN=0
2012-10-11T17:53:43.539Z,1349978023.539 [NAL9602](INFO): Sent 33 bytes from file Logs/20121011T165600/shore0001.lzma
2012-10-11T17:53:43.539Z,1349978023.539 [NAL9602](INFO): Packets left to send: 0
2012-10-11T17:53:43.541Z,1349978023.541 [NAL9602](INFO): Stored copy of sent data in Logs/20121011T165600/shore0001.lzma.parts/0000.sbd
2012-10-11T17:53:54.330Z,1349978034.330 [NAL9602](INFO): SBD MO Status=0, MOMSN=1565, MT Status=0, MTMSN=0
2012-10-11T17:54:06.865Z,1349978046.865 [NAL9602](INFO): SBD MO Status=1, MOMSN=1566, MT Status=0, MTMSN=0
2012-10-11T17:54:06.907Z,1349978046.907 [NAL9602](INFO): Sent 226 bytes from file Logs/20121011T165600/shore0002.lzma
2012-10-11T17:54:06.907Z,1349978046.907 [NAL9602](INFO): Packets left to send: 0
2012-10-11T17:54:06.909Z,1349978046.909 [NAL9602](INFO): Stored copy of sent data in Logs/20121011T165600/shore0002.lzma.parts/0000.sbd
2012-10-11T17:54:17.660Z,1349978057.660 [NAL9602](INFO): SBD MO Status=0, MOMSN=1567, MT Status=0, MTMSN=0
2012-10-11T17:54:17.717Z,1349978057.717 [Default:Iridium:Read_Iridium] Stopped
2012-10-11T17:54:17.717Z,1349978057.717 [Default:Iridium](INFO): Completed Default:Iridium
2012-10-11T17:54:17.717Z,1349978057.717 [Default:Iridium] Stopped
2012-10-11T17:54:17.717Z,1349978057.717 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2012-10-11T17:54:17.717Z,1349978057.717 [Default:Iridium:A.SetSpeed] Stopped
2012-10-11T17:54:17.718Z,1349978057.718 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2012-10-11T17:54:17.718Z,1349978057.718 [Default:F.Wait] Running Loop=1
2012-10-11T17:54:17.718Z,1349978057.718 [Default:F.Wait](DEBUG): Initialize Wait Component.
2012-10-11T17:54:18.079Z,1349978058.079 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2012-10-11T17:54:18.079Z,1349978058.079 [Default:CallIridium:B] Stopped
2012-10-11T17:54:18.079Z,1349978058.079 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2012-10-11T17:54:18.079Z,1349978058.079 [Default:CallIridium](INFO): Completed Default:CallIridium
2012-10-11T17:54:18.079Z,1349978058.079 [Default:CallIridium] Stopped
2012-10-11T17:54:18.079Z,1349978058.079 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2012-10-11T17:54:28.228Z,1349978068.228 [NAL9602](INFO): Powering down
2012-10-11T17:59:18.212Z,1349978358.212 [Default:CallIridium] Running Loop=1
2012-10-11T17:59:18.212Z,1349978358.212 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2012-10-11T17:59:18.212Z,1349978358.212 [Default:CallIridium:A] Running Loop=1
2012-10-11T17:59:18.213Z,1349978358.213 [Default:CallIridium:A] Stopped
2012-10-11T17:59:18.213Z,1349978358.213 [Default:CallIridium:B] Running Loop=1
2012-10-11T17:59:18.213Z,1349978358.213 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2012-10-11T17:59:23.240Z,1349978363.240 [Default:Iridium] Running Loop=1
2012-10-11T17:59:23.240Z,1349978363.240 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2012-10-11T17:59:23.240Z,1349978363.240 [Default:Iridium:A.SetSpeed] Running Loop=1
2012-10-11T17:59:23.240Z,1349978363.240 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2012-10-11T17:59:23.240Z,1349978363.240 [Default:Iridium:B.GoToSurface] Running Loop=1
2012-10-11T17:59:23.241Z,1349978363.240 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-10-11T17:59:23.241Z,1349978363.241 [Default:Iridium:B.GoToSurface] Stopped
2012-10-11T17:59:23.241Z,1349978363.241 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-10-11T17:59:23.241Z,1349978363.241 [Default:Iridium:Read_Iridium] Running Loop=1
2012-10-11T17:59:23.242Z,1349978363.242 [Default:GPS] Running Loop=1
2012-10-11T17:59:23.242Z,1349978363.242 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2012-10-11T17:59:23.242Z,1349978363.242 [Default:GPS:A.SetSpeed] Running Loop=1
2012-10-11T17:59:23.242Z,1349978363.242 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2012-10-11T17:59:23.242Z,1349978363.242 [Default:GPS:B.GoToSurface] Running Loop=1
2012-10-11T17:59:23.242Z,1349978363.242 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-10-11T17:59:23.243Z,1349978363.243 [Default:GPS:B.GoToSurface] Stopped
2012-10-11T17:59:23.243Z,1349978363.243 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-10-11T17:59:23.243Z,1349978363.243 [Default:GPS:Read_GPS] Running Loop=1
2012-10-11T17:59:23.886Z,1349978363.886 [NAL9602](INFO): Powering up
2012-10-11T17:59:34.359Z,1349978374.359 [NAL9602](INFO): NAL9602 initialized
2012-10-11T18:00:03.178Z,1349978403.178 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=1568, MT Status=1, MTMSN=146
2012-10-11T18:00:03.215Z,1349978403.215 [NAL9602](INFO): Sent 101 bytes from file Logs/20121011T165600/shore0003.lzma
2012-10-11T18:00:03.215Z,1349978403.215 [NAL9602](INFO): Packets left to send: 0
2012-10-11T18:00:03.217Z,1349978403.217 [NAL9602](INFO): Stored copy of sent data in Logs/20121011T165600/shore0003.lzma.parts/0000.sbd
2012-10-11T18:00:03.579Z,1349978403.579 [NAL9602](INFO): Received command:Restart app
2012-10-11T18:00:03.611Z,1349978403.611 [CommandLine](IMPORTANT): got command restart application
2012-10-11T18:00:04.806Z,1349978404.806 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2012-10-11T18:00:04.807Z,1349978404.807 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2012-10-11T18:00:04.887Z,1349978404.886 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2012-10-11T18:00:05.255Z,1349978405.255 [WetLabsBB2FL](INFO): Powering down
2012-10-11T18:00:05.275Z,1349978405.274 [ComponentRegistry](INFO): Shutting down Turbulence_NPS ThreadHandler
2012-10-11T18:00:05.663Z,1349978405.663 [Turbulence_NPS](INFO): Uninitialize Powering down
2012-10-11T18:00:05.674Z,1349978405.674 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2012-10-11T18:00:06.047Z,1349978406.047 [CTD_NeilBrown](INFO): Powering down
2012-10-11T18:00:06.054Z,1349978406.055 [ComponentRegistry](INFO): Shutting down DVL_micro ThreadHandler
2012-10-11T18:00:06.067Z,1349978406.067 [DVL_micro](INFO): uninitialize:Powering down
2012-10-11T18:00:06.075Z,1349978406.075 [ComponentRegistry](INFO): Shutting down AsyncPiEstimator ThreadHandler
2012-10-11T18:00:06.335Z,1349978406.335 [AsyncPiEstimator](DEBUG): Uninitialize AsyncPiEstimator.
2012-10-11T18:00:06.355Z,1349978406.355 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2012-10-11T18:00:06.365Z,1349978406.365 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2012-10-11T18:00:06.539Z,1349978406.539 [controlThread](DEBUG): Uninitializing ControlThread
2012-10-11T18:00:06.539Z,1349978406.539 [AHRS_sp3003D](INFO): Powering down
2012-10-11T18:00:06.628Z,1349978406.628 [NAL9602](INFO): Powering down
2012-10-11T18:00:06.629Z,1349978406.629 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2012-10-11T18:00:06.630Z,1349978406.630 [NavChart](DEBUG): Uninitialize NavChart Derivation.
2012-10-11T18:00:06.631Z,1349978406.631 [Default] Stopped
2012-10-11T18:00:06.631Z,1349978406.631 [Default](INFO): Aggregate::uninitialize Default
2012-10-11T18:00:06.631Z,1349978406.631 [Default:GPS] Stopped
2012-10-11T18:00:06.632Z,1349978406.632 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2012-10-11T18:00:06.632Z,1349978406.632 [Default:GPS:A.SetSpeed] Stopped
2012-10-11T18:00:06.632Z,1349978406.632 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2012-10-11T18:00:06.632Z,1349978406.632 [Default:GPS:Read_GPS] Stopped
2012-10-11T18:00:06.632Z,1349978406.632 [Default:Iridium] Stopped
2012-10-11T18:00:06.632Z,1349978406.632 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2012-10-11T18:00:06.632Z,1349978406.632 [Default:Iridium:A.SetSpeed] Stopped
2012-10-11T18:00:06.632Z,1349978406.632 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2012-10-11T18:00:06.632Z,1349978406.632 [Default:Iridium:Read_Iridium] Stopped
2012-10-11T18:00:06.632Z,1349978406.632 [Default:CallIridium] Stopped
2012-10-11T18:00:06.632Z,1349978406.632 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2012-10-11T18:00:06.632Z,1349978406.632 [Default:CallIridium:B] Stopped
2012-10-11T18:00:06.632Z,1349978406.632 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2012-10-11T18:00:06.633Z,1349978406.633 [Default:D.SetSpeed] Stopped
2012-10-11T18:00:06.633Z,1349978406.633 [Default:D.SetSpeed](DEBUG): Uninitialize.
2012-10-11T18:00:06.633Z,1349978406.633 [Default:E.GoToSurface] Stopped
2012-10-11T18:00:06.633Z,1349978406.633 [Default:E.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-10-11T18:00:06.633Z,1349978406.633 [Default:F.Wait] Stopped
2012-10-11T18:00:06.633Z,1349978406.633 [Default:F.Wait](DEBUG): Uninitialize Wait Component.
2012-10-11T18:00:06.637Z,1349978406.637 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2012-10-11T18:00:06.637Z,1349978406.638 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2012-10-11T18:00:06.638Z,1349978406.638 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2012-10-11T18:00:06.638Z,1349978406.638 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2012-10-11T18:00:06.638Z,1349978406.638 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2012-10-11T18:00:06.639Z,1349978406.639 [BuoyancyServo](INFO): Powering down
2012-10-11T18:00:06.643Z,1349978406.643 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2012-10-11T18:00:06.643Z,1349978406.643 [ElevatorServo](INFO): Powering down
2012-10-11T18:00:06.644Z,1349978406.644 [MassServo](DEBUG): Uninitialize Mass Servo.
2012-10-11T18:00:06.644Z,1349978406.644 [MassServo](INFO): Powering down
2012-10-11T18:00:06.645Z,1349978406.645 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2012-10-11T18:00:06.645Z,1349978406.645 [RudderServo](INFO): Powering down
2012-10-11T18:00:06.646Z,1349978406.645 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2012-10-11T18:00:06.646Z,1349978406.646 [ThrusterServo](INFO): Powering down
2012-10-11T18:00:06.646Z,1349978406.647 [SBIT](DEBUG): Uninitialize SBIT Component.
2012-10-11T18:00:06.647Z,1349978406.647 [IBIT](DEBUG): Uninitialize IBIT Component.
2012-10-11T18:00:06.647Z,1349978406.647 [CBIT](DEBUG): Uninitialize CBIT Component.