2012-11-12T18:30:47.039Z,1352745047.039 [Supervisor](DEBUG): Initializing supervisor.
2012-11-12T18:30:47.042Z,1352745047.042 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0
2012-11-12T18:30:47.043Z,1352745047.043 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2012-11-12T18:30:47.046Z,1352745047.046 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0
2012-11-12T18:30:47.050Z,1352745047.050 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2012-11-12T18:30:47.060Z,1352745047.060 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2012-11-12T18:30:47.062Z,1352745047.062 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0
2012-11-12T18:30:47.063Z,1352745047.063 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2012-11-12T18:30:47.066Z,1352745047.066 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0
2012-11-12T18:30:47.067Z,1352745047.067 [Supervisor](INFO): Looking for Config files in directory: Config/
2012-11-12T18:30:47.070Z,1352745047.070 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2012-11-12T18:30:47.386Z,1352745047.386 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2012-11-12T18:30:47.388Z,1352745047.388 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2012-11-12T18:30:47.593Z,1352745047.593 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2012-11-12T18:30:47.594Z,1352745047.594 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2012-11-12T18:30:47.690Z,1352745047.690 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2012-11-12T18:30:47.692Z,1352745047.692 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2012-11-12T18:30:47.915Z,1352745047.915 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2012-11-12T18:30:47.916Z,1352745047.916 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2012-11-12T18:30:48.067Z,1352745048.067 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2012-11-12T18:30:48.069Z,1352745048.069 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2012-11-12T18:30:48.319Z,1352745048.319 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2012-11-12T18:30:48.320Z,1352745048.320 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2012-11-12T18:30:48.515Z,1352745048.515 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2012-11-12T18:30:48.517Z,1352745048.517 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2012-11-12T18:30:48.800Z,1352745048.800 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2012-11-12T18:30:48.802Z,1352745048.802 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2012-11-12T18:30:48.915Z,1352745048.915 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2012-11-12T18:30:48.916Z,1352745048.916 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2012-11-12T18:30:49.366Z,1352745049.366 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2012-11-12T18:30:49.366Z,1352745049.366 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2012-11-12T18:30:49.495Z,1352745049.495 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2012-11-12T18:30:49.496Z,1352745049.496 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2012-11-12T18:30:49.591Z,1352745049.592 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2012-11-12T18:30:49.595Z,1352745049.595 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2012-11-12T18:30:49.706Z,1352745049.706 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2012-11-12T18:30:49.852Z,1352745049.852 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2012-11-12T18:30:49.950Z,1352745049.950 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2012-11-12T18:30:50.062Z,1352745050.062 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2012-11-12T18:30:50.176Z,1352745050.175 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2012-11-12T18:30:50.312Z,1352745050.312 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2012-11-12T18:30:50.418Z,1352745050.418 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2012-11-12T18:30:50.524Z,1352745050.524 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2012-11-12T18:30:51.469Z,1352745051.469 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2012-11-12T18:30:52.359Z,1352745052.359 [InternalSim] Loaded
2012-11-12T18:30:52.360Z,1352745052.360 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2012-11-12T18:30:52.361Z,1352745052.361 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2012-11-12T18:30:52.361Z,1352745052.361 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2012-11-12T18:30:52.447Z,1352745052.447 [SBIT](DEBUG): Construct Startup Built In Test.
2012-11-12T18:30:52.475Z,1352745052.475 [SBIT] Loaded
2012-11-12T18:30:52.475Z,1352745052.475 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2012-11-12T18:30:52.476Z,1352745052.476 [IBIT](DEBUG): Construct Initiated Built In Test.
2012-11-12T18:30:52.508Z,1352745052.508 [IBIT] Loaded
2012-11-12T18:30:52.508Z,1352745052.508 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2012-11-12T18:30:52.512Z,1352745052.512 [CBIT](DEBUG): Construct CBIT Built In Test.
2012-11-12T18:30:52.647Z,1352745052.647 [CBIT] Loaded
2012-11-12T18:30:52.647Z,1352745052.648 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2012-11-12T18:30:52.648Z,1352745052.648 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2012-11-12T18:30:52.649Z,1352745052.649 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2012-11-12T18:30:52.827Z,1352745052.827 [BuoyancyServo] Loaded
2012-11-12T18:30:52.827Z,1352745052.827 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2012-11-12T18:30:52.839Z,1352745052.839 [ElevatorServo] Loaded
2012-11-12T18:30:52.839Z,1352745052.839 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2012-11-12T18:30:52.855Z,1352745052.855 [MassServo] Loaded
2012-11-12T18:30:52.855Z,1352745052.855 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2012-11-12T18:30:52.867Z,1352745052.867 [RudderServo] Loaded
2012-11-12T18:30:52.867Z,1352745052.867 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2012-11-12T18:30:52.879Z,1352745052.879 [ThrusterServo] Loaded
2012-11-12T18:30:52.879Z,1352745052.879 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2012-11-12T18:30:52.880Z,1352745052.880 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2012-11-12T18:30:52.881Z,1352745052.881 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2012-11-12T18:30:52.917Z,1352745052.917 [DepthRateCalculator] Loaded
2012-11-12T18:30:52.917Z,1352745052.917 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2012-11-12T18:30:57.243Z,1352745057.243 [HFRadarModelCalc] Loaded
2012-11-12T18:30:57.243Z,1352745057.243 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2012-11-12T18:30:57.259Z,1352745057.259 [NavChart] Loaded
2012-11-12T18:30:57.259Z,1352745057.259 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2012-11-12T18:30:57.265Z,1352745057.265 [PitchRateCalculator] Loaded
2012-11-12T18:30:57.265Z,1352745057.265 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2012-11-12T18:30:57.271Z,1352745057.272 [SpeedCalculator] Loaded
2012-11-12T18:30:57.272Z,1352745057.272 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2012-11-12T18:30:57.287Z,1352745057.287 [TempGradientCalculator] Loaded
2012-11-12T18:30:57.287Z,1352745057.287 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2012-11-12T18:30:57.293Z,1352745057.293 [YawRateCalculator] Loaded
2012-11-12T18:30:57.293Z,1352745057.293 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2012-11-12T18:30:57.333Z,1352745057.333 [Navigation] Loaded
2012-11-12T18:30:57.333Z,1352745057.333 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread.
2012-11-12T18:30:57.334Z,1352745057.334 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2012-11-12T18:30:57.334Z,1352745057.334 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2012-11-12T18:30:57.595Z,1352745057.595 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2012-11-12T18:30:57.596Z,1352745057.596 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2012-11-12T18:30:57.636Z,1352745057.636 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2012-11-12T18:30:57.636Z,1352745057.636 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2012-11-12T18:30:57.696Z,1352745057.696 [VerticalControl](DEBUG): Construct VerticalControl.
2012-11-12T18:30:57.788Z,1352745057.788 [VerticalControl] Loaded
2012-11-12T18:30:57.789Z,1352745057.789 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2012-11-12T18:30:57.790Z,1352745057.790 [HorizontalControl](DEBUG): Construct HorizontalControl.
2012-11-12T18:30:57.846Z,1352745057.846 [HorizontalControl] Loaded
2012-11-12T18:30:57.846Z,1352745057.846 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2012-11-12T18:30:57.847Z,1352745057.847 [SpeedControl](DEBUG): Construct SpeedControl.
2012-11-12T18:30:57.849Z,1352745057.849 [SpeedControl] Loaded
2012-11-12T18:30:57.849Z,1352745057.849 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2012-11-12T18:30:57.850Z,1352745057.850 [LoopControl](DEBUG): Construct LoopControl.
2012-11-12T18:30:57.851Z,1352745057.851 [LoopControl] Loaded
2012-11-12T18:30:57.851Z,1352745057.851 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2012-11-12T18:30:57.851Z,1352745057.851 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2012-11-12T18:30:57.852Z,1352745057.852 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2012-11-12T18:30:57.860Z,1352745057.860 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator.
2012-11-12T18:30:57.865Z,1352745057.865 [AsyncPiEstimator] Loaded
2012-11-12T18:30:57.865Z,1352745057.865 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread.
2012-11-12T18:30:57.866Z,1352745057.866 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406A14E0
2012-11-12T18:30:57.867Z,1352745057.867 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2012-11-12T18:30:57.868Z,1352745057.868 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2012-11-12T18:30:58.034Z,1352745058.034 [AHRS_sp3003D] Loaded
2012-11-12T18:30:58.034Z,1352745058.034 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2012-11-12T18:30:58.291Z,1352745058.291 [Batt_Ocean_Server] Loaded
2012-11-12T18:30:58.291Z,1352745058.291 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2012-11-12T18:30:58.304Z,1352745058.304 [Depth_Keller] Loaded
2012-11-12T18:30:58.304Z,1352745058.304 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2012-11-12T18:30:58.310Z,1352745058.310 [DropWeight] Loaded
2012-11-12T18:30:58.310Z,1352745058.310 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2012-11-12T18:30:58.471Z,1352745058.471 [DVL_micro] Loaded
2012-11-12T18:30:58.471Z,1352745058.471 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread.
2012-11-12T18:30:58.472Z,1352745058.472 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 407234E0
2012-11-12T18:30:58.554Z,1352745058.554 [NAL9602] Loaded
2012-11-12T18:30:58.554Z,1352745058.554 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2012-11-12T18:30:58.605Z,1352745058.605 [Onboard] Loaded
2012-11-12T18:30:58.606Z,1352745058.606 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2012-11-12T18:30:58.612Z,1352745058.612 [Radio_Freewave] Loaded
2012-11-12T18:30:58.613Z,1352745058.613 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread.
2012-11-12T18:30:58.613Z,1352745058.613 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2012-11-12T18:30:58.614Z,1352745058.614 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2012-11-12T18:30:58.710Z,1352745058.710 [CTD_NeilBrown] Loaded
2012-11-12T18:30:58.710Z,1352745058.710 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2012-11-12T18:30:58.711Z,1352745058.711 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4077C4E0
2012-11-12T18:30:58.728Z,1352745058.728 [PAR_Licor] Loaded
2012-11-12T18:30:58.728Z,1352745058.728 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2012-11-12T18:30:58.780Z,1352745058.780 [Turbulence_NPS] Loaded
2012-11-12T18:30:58.780Z,1352745058.780 [ComponentRegistry](DEBUG): Component "Turbulence_NPS" handled in its own thread.
2012-11-12T18:30:58.781Z,1352745058.782 [Turbulence_NPS ThreadHandler](DEBUG): Created PCaller Thread at 407AC4E0
2012-11-12T18:30:58.811Z,1352745058.811 [WetLabsBB2FL] Loaded
2012-11-12T18:30:58.812Z,1352745058.812 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2012-11-12T18:30:58.813Z,1352745058.813 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407DC4E0
2012-11-12T18:30:58.813Z,1352745058.813 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2012-11-12T18:30:58.816Z,1352745058.816 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2012-11-12T18:30:58.817Z,1352745058.817 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2012-11-12T18:30:58.827Z,1352745058.827 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2012-11-12T18:30:58.828Z,1352745058.828 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 4080C4E0
2012-11-12T18:30:58.832Z,1352745058.832 [Supervisor](DEBUG): Running supervisor.
2012-11-12T18:30:58.833Z,1352745058.833 [CommandLine](INFO): Thread ID is 747
2012-11-12T18:30:58.836Z,1352745058.836 [controlThread](INFO): Thread ID is 746
2012-11-12T18:30:58.836Z,1352745058.836 [controlThread](DEBUG): Initializing ControlThread
2012-11-12T18:30:58.836Z,1352745058.836 [CycleStarter](INFO): Thread ID is 745
2012-11-12T18:30:58.837Z,1352745058.837 [InternalSim](DEBUG): InternalSim initializing...
2012-11-12T18:30:58.938Z,1352745058.938 [logger](INFO): Thread ID is 748
2012-11-12T18:30:59.025Z,1352745059.025 [AsyncPiEstimator](INFO): Thread ID is 809
2012-11-12T18:30:59.025Z,1352745059.025 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator.
2012-11-12T18:30:59.034Z,1352745059.034 [DVL_micro](INFO): Thread ID is 810
2012-11-12T18:30:59.132Z,1352745059.132 [CTD_NeilBrown](INFO): Thread ID is 811
2012-11-12T18:30:59.132Z,1352745059.132 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2012-11-12T18:30:59.135Z,1352745059.135 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2012-11-12T18:30:59.184Z,1352745059.184 [Turbulence_NPS](INFO): Thread ID is 812
2012-11-12T18:30:59.184Z,1352745059.184 [Turbulence_NPS](DEBUG): Initializing Turbulence_NPS.
2012-11-12T18:30:59.185Z,1352745059.185 [Turbulence_NPS](INFO): Opening uart, block timeout 10ths=1
2012-11-12T18:30:59.193Z,1352745059.194 [DVL_micro](INFO): Initializing
2012-11-12T18:30:59.194Z,1352745059.194 [DVL_micro](INFO): start:Powering up
2012-11-12T18:30:59.195Z,1352745059.195 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2012-11-12T18:30:59.195Z,1352745059.195 [DVL_micro](INFO): Cycling power to configure device.
2012-11-12T18:30:59.201Z,1352745059.201 [SBIT](INFO): Initialize SBIT Component.
2012-11-12T18:30:59.202Z,1352745059.202 [SBIT](IMPORTANT): Tethys CM Info:
$Rev: 10057
2012-11-12T18:30:59.203Z,1352745059.203 [IBIT](INFO): Initialize IBIT Component.
2012-11-12T18:30:59.204Z,1352745059.204 [CBIT](DEBUG): Initialize CBIT Component.
2012-11-12T18:30:59.204Z,1352745059.204 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2012-11-12T18:30:59.204Z,1352745059.204 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2012-11-12T18:30:59.205Z,1352745059.205 [WetLabsBB2FL](INFO): Thread ID is 813
2012-11-12T18:30:59.206Z,1352745059.206 [WetLabsBB2FL](INFO): Powering down
2012-11-12T18:30:59.231Z,1352745059.231 [NavChartDb](INFO): Thread ID is 814
2012-11-12T18:30:59.237Z,1352745059.237 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2012-11-12T18:30:59.237Z,1352745059.237 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2012-11-12T18:30:59.238Z,1352745059.238 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2012-11-12T18:30:59.238Z,1352745059.238 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2012-11-12T18:30:59.243Z,1352745059.243 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2012-11-12T18:30:59.251Z,1352745059.251 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2012-11-12T18:30:59.252Z,1352745059.252 [NavChart](DEBUG): Initialize NavChart Derivation.
2012-11-12T18:30:59.252Z,1352745059.252 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2012-11-12T18:30:59.252Z,1352745059.252 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2012-11-12T18:30:59.253Z,1352745059.253 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2012-11-12T18:30:59.254Z,1352745059.254 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2012-11-12T18:30:59.259Z,1352745059.259 [Navigation](DEBUG): Initializing Navigation.
2012-11-12T18:30:59.259Z,1352745059.259 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2012-11-12T18:30:59.261Z,1352745059.261 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2012-11-12T18:30:59.262Z,1352745059.262 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2012-11-12T18:30:59.262Z,1352745059.262 [LoopControl](DEBUG): Initialize LoopControlComponent.
2012-11-12T18:30:59.327Z,1352745059.327 [Turbulence_NPS](INFO): Pause powering down
2012-11-12T18:31:01.331Z,1352745061.331 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2012-11-12T18:31:01.331Z,1352745061.331 [DVL_micro](INFO): Querying output modes
2012-11-12T18:31:01.331Z,1352745061.332 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606
2012-11-12T18:31:01.343Z,1352745061.343 [DVL_micro](DEBUG): cmdResponse: 01 03 16
2012-11-12T18:31:01.343Z,1352745061.343 [DVL_micro](INFO): NQ1 output enabled
2012-11-12T18:31:01.343Z,1352745061.343 [DVL_micro](INFO): RSSI output enabled
2012-11-12T18:31:01.343Z,1352745061.343 [DVL_micro](INFO): ADCP output enabled
2012-11-12T18:31:01.343Z,1352745061.343 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525
2012-11-12T18:31:01.355Z,1352745061.355 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON
2012-11-12T18:31:01.359Z,1352745061.359 [DVL_micro](INFO): pause:Powering down
2012-11-12T18:31:01.361Z,1352745061.361 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2012-11-12T18:31:01.403Z,1352745061.403 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2012-11-12T18:31:01.433Z,1352745061.433 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2012-11-12T18:31:01.479Z,1352745061.479 [MissionManager](DEBUG):
2012-11-12T18:31:01.480Z,1352745061.480 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2012-11-12T18:31:01.555Z,1352745061.555 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2012-11-12T18:31:01.557Z,1352745061.557 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2012-11-12T18:31:01.561Z,1352745061.560 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2012-11-12T18:31:01.584Z,1352745061.584 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2012-11-12T18:31:01.597Z,1352745061.597 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2012-11-12T18:31:01.603Z,1352745061.603 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2012-11-12T18:31:01.624Z,1352745061.624 [Default:D.SetSpeed](DEBUG): Construct.
2012-11-12T18:31:01.627Z,1352745061.627 [Default:E.GoToSurface](DEBUG): Construct GoToSurface.
2012-11-12T18:31:01.676Z,1352745061.676 [Default:F.Wait](DEBUG): Construct Wait.
2012-11-12T18:31:01.679Z,1352745061.679 [MissionManager](DEBUG):
400
400
Burn 300
Dropped drop weight due to communications timeout
5.0
1.0
5
2012-11-12T18:31:01.684Z,1352745061.684 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,NAL9602,Onboard,Radio_Freewave,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,
2012-11-12T18:31:01.725Z,1352745061.725 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2012-11-12T18:31:01.923Z,1352745061.923 [Radio_Freewave](INFO): Powering up
2012-11-12T18:31:02.235Z,1352745062.235 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2012-11-12T18:31:02.259Z,1352745062.259 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2012-11-12T18:31:02.265Z,1352745062.265 [ElevatorServo](DEBUG): Initializing EZServoServo.
2012-11-12T18:31:02.271Z,1352745062.271 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2012-11-12T18:31:02.293Z,1352745062.293 [MassServo](DEBUG): Initializing EZServoServo.
2012-11-12T18:31:02.299Z,1352745062.299 [MassServo](DEBUG): Initializing MassServo.
2012-11-12T18:31:02.305Z,1352745062.305 [RudderServo](DEBUG): Initializing EZServoServo.
2012-11-12T18:31:02.311Z,1352745062.311 [RudderServo](DEBUG): Initializing RudderServo.
2012-11-12T18:31:02.316Z,1352745062.316 [ThrusterServo](DEBUG): Initializing EZServoServo.
2012-11-12T18:31:02.323Z,1352745062.323 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2012-11-12T18:31:03.915Z,1352745063.915 [NAL9602](INFO): Powering up NAL9602
2012-11-12T18:31:14.431Z,1352745074.431 [NAL9602](INFO): NAL9602 initialized
2012-11-12T18:31:14.800Z,1352745074.800 [SBIT](IMPORTANT): Beginning Startup BIT
2012-11-12T18:31:14.803Z,1352745074.803 [CBIT](IMPORTANT): Beginning GF scan
2012-11-12T18:31:27.817Z,1352745087.817 [SBIT](FAULT): Elevator: EXPECTED:15.000000 ACTUAL:14.797676
2012-11-12T18:31:41.500Z,1352745101.500 [CBIT](IMPORTANT): No ground fault detected
2012-11-12T18:32:08.424Z,1352745128.424 [SBIT](CRITICAL): SBIT FAILED
2012-11-12T18:32:08.817Z,1352745128.817 [MissionManager](IMPORTANT): Started mission Startup
2012-11-12T18:32:08.817Z,1352745128.817 [Startup] Running Loop=1
2012-11-12T18:32:08.817Z,1352745128.817 [Startup](INFO): Aggregate::initialize Startup
2012-11-12T18:32:08.817Z,1352745128.817 [Startup:A.GoToSurface] Running Loop=1
2012-11-12T18:32:08.817Z,1352745128.817 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-11-12T18:32:08.823Z,1352745128.823 [Startup:StartupSatComms] Running Loop=1
2012-11-12T18:32:08.823Z,1352745128.823 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2012-11-12T18:32:08.823Z,1352745128.823 [Startup:StartupSatComms:A] Running Loop=1
2012-11-12T18:32:09.205Z,1352745129.205 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2012-11-12T18:33:08.834Z,1352745188.834 [Startup:StartupSatComms:A](INFO): Timed out from 2012-11-12T18:32:08.8Z
2012-11-12T18:33:08.834Z,1352745188.834 [Startup:StartupSatComms:A:A_Timeout] Running Loop=1
2012-11-12T18:33:08.834Z,1352745188.834 [Startup:StartupSatComms:A:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:A:A_Timeout
2012-11-12T18:33:08.835Z,1352745188.835 [Startup:StartupSatComms:A:A_Timeout](INFO): Completed Startup:StartupSatComms:A:A_Timeout
2012-11-12T18:33:08.835Z,1352745188.835 [Startup:StartupSatComms:A] Stopped
2012-11-12T18:33:08.835Z,1352745188.835 [Startup:StartupSatComms:B] Running Loop=1
2012-11-12T18:33:09.230Z,1352745189.230 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2012-11-12T18:33:36.502Z,1352745216.501 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:33:36.502Z,1352745216.502 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:34:08.972Z,1352745248.972 [Startup:StartupSatComms:B](INFO): Timed out from 2012-11-12T18:33:08.8Z
2012-11-12T18:34:08.973Z,1352745248.973 [Startup:StartupSatComms:B:A_Timeout] Running Loop=1
2012-11-12T18:34:08.973Z,1352745248.973 [Startup:StartupSatComms:B:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:B:A_Timeout
2012-11-12T18:34:08.973Z,1352745248.973 [Startup:StartupSatComms:B:A_Timeout](INFO): Completed Startup:StartupSatComms:B:A_Timeout
2012-11-12T18:34:08.973Z,1352745248.973 [Startup:StartupSatComms:B] Stopped
2012-11-12T18:34:08.973Z,1352745248.973 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2012-11-12T18:34:08.973Z,1352745248.973 [Startup:StartupSatComms] Stopped
2012-11-12T18:34:08.973Z,1352745248.973 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2012-11-12T18:34:08.974Z,1352745248.974 [Startup](INFO): Completed Startup
2012-11-12T18:34:08.974Z,1352745248.974 [Startup] Stopped
2012-11-12T18:34:08.975Z,1352745248.974 [Startup](INFO): Aggregate::uninitialize Startup
2012-11-12T18:34:08.975Z,1352745248.975 [Startup:A.GoToSurface] Stopped
2012-11-12T18:34:08.975Z,1352745248.975 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-11-12T18:34:09.380Z,1352745249.380 [MissionManager](IMPORTANT): Started mission Default
2012-11-12T18:34:09.380Z,1352745249.380 [Default] Running Loop=1
2012-11-12T18:34:09.380Z,1352745249.380 [Default](INFO): Aggregate::initialize Default
2012-11-12T18:34:09.380Z,1352745249.380 [Default:D.SetSpeed] Running Loop=1
2012-11-12T18:34:09.380Z,1352745249.380 [Default:D.SetSpeed](DEBUG): Initialize.
2012-11-12T18:34:09.380Z,1352745249.381 [Default:E.GoToSurface] Running Loop=1
2012-11-12T18:34:09.381Z,1352745249.381 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-11-12T18:34:09.381Z,1352745249.381 [Default:Iridium] Running Loop=1
2012-11-12T18:34:09.381Z,1352745249.381 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2012-11-12T18:34:09.381Z,1352745249.381 [Default:Iridium:A.SetSpeed] Running Loop=1
2012-11-12T18:34:09.381Z,1352745249.381 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2012-11-12T18:34:09.381Z,1352745249.381 [Default:Iridium:B.GoToSurface] Running Loop=1
2012-11-12T18:34:09.381Z,1352745249.381 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-11-12T18:34:09.382Z,1352745249.382 [Default:E.GoToSurface] Running Loop=1
2012-11-12T18:34:09.387Z,1352745249.387 [Default:D.SetSpeed] Running Loop=1
2012-11-12T18:34:09.392Z,1352745249.392 [Default:CallIridium] Running Loop=1
2012-11-12T18:34:09.393Z,1352745249.392 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2012-11-12T18:34:09.393Z,1352745249.393 [Default:CallIridium:A] Running Loop=1
2012-11-12T18:34:09.395Z,1352745249.395 [Default:CallIridium:A] Stopped
2012-11-12T18:34:09.395Z,1352745249.395 [Default:CallIridium:B] Running Loop=1
2012-11-12T18:34:09.395Z,1352745249.395 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2012-11-12T18:34:09.400Z,1352745249.400 [Default:Iridium:B.GoToSurface] Stopped
2012-11-12T18:34:09.400Z,1352745249.400 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-11-12T18:34:09.400Z,1352745249.400 [Default:Iridium:Read_Iridium] Running Loop=1
2012-11-12T18:34:09.400Z,1352745249.401 [Default:Iridium:A.SetSpeed] Running Loop=1
2012-11-12T18:34:09.405Z,1352745249.405 [Default:GPS] Running Loop=1
2012-11-12T18:34:09.405Z,1352745249.405 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2012-11-12T18:34:09.405Z,1352745249.405 [Default:GPS:A.SetSpeed] Running Loop=1
2012-11-12T18:34:09.406Z,1352745249.406 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2012-11-12T18:34:09.406Z,1352745249.406 [Default:GPS:B.GoToSurface] Running Loop=1
2012-11-12T18:34:09.406Z,1352745249.406 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-11-12T18:34:09.412Z,1352745249.411 [Default:GPS:B.GoToSurface] Stopped
2012-11-12T18:34:09.412Z,1352745249.411 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-11-12T18:34:09.412Z,1352745249.412 [Default:GPS:Read_GPS] Running Loop=1
2012-11-12T18:34:09.412Z,1352745249.412 [Default:GPS:A.SetSpeed] Running Loop=1
2012-11-12T18:34:09.779Z,1352745249.779 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2012-11-12T18:34:09.781Z,1352745249.781 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2012-11-12T18:34:20.565Z,1352745260.565 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:34:20.566Z,1352745260.566 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:34:37.645Z,1352745277.645 [NAL9602](IMPORTANT): GPS fix at: 1352745277.00
2012-11-12T18:34:37.661Z,1352745277.661 [Default:GPS:Read_GPS] Stopped
2012-11-12T18:34:37.661Z,1352745277.661 [Default:GPS:D] Running Loop=1
2012-11-12T18:34:38.085Z,1352745278.085 [Default:GPS:D] Stopped
2012-11-12T18:34:38.086Z,1352745278.086 [Default:GPS](INFO): Completed Default:GPS
2012-11-12T18:34:38.086Z,1352745278.086 [Default:GPS] Stopped
2012-11-12T18:34:38.086Z,1352745278.086 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2012-11-12T18:34:38.086Z,1352745278.086 [Default:GPS:A.SetSpeed] Stopped
2012-11-12T18:34:38.086Z,1352745278.086 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2012-11-12T18:34:52.331Z,1352745292.331 [CommandLine](IMPORTANT): got command failComponent
2012-11-12T18:34:52.331Z,1352745292.331 [CommandLine](IMPORTANT): Failed components:
2012-11-12T18:34:52.331Z,1352745292.331 [CommandLine](IMPORTANT): No failed Components.
2012-11-12T18:35:26.321Z,1352745326.321 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:35:26.321Z,1352745326.321 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:36:26.237Z,1352745386.237 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=0, MTMSN=0
2012-11-12T18:36:26.237Z,1352745386.237 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:36:49.948Z,1352745409.948 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:36:49.948Z,1352745409.948 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:37:15.705Z,1352745435.705 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:37:15.705Z,1352745435.705 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:38:20.101Z,1352745500.101 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:38:20.101Z,1352745500.101 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:39:16.744Z,1352745556.744 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:39:16.744Z,1352745556.744 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:39:37.377Z,1352745577.377 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:39:37.377Z,1352745577.377 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:40:03.653Z,1352745603.653 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:40:03.653Z,1352745603.653 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:40:19.562Z,1352745619.562 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:40:19.562Z,1352745619.562 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:40:43.413Z,1352745643.413 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:40:43.414Z,1352745643.414 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:41:11.125Z,1352745671.125 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:41:11.125Z,1352745671.125 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:41:35.044Z,1352745695.044 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:41:35.044Z,1352745695.044 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:41:51.798Z,1352745711.798 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:41:51.798Z,1352745711.798 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:42:18.425Z,1352745738.425 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:42:18.425Z,1352745738.425 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:42:35.819Z,1352745755.819 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:42:35.819Z,1352745755.819 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:43:28.044Z,1352745808.044 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:43:28.044Z,1352745808.044 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:43:50.713Z,1352745830.713 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:43:50.714Z,1352745830.714 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:45:46.161Z,1352745946.161 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:45:46.161Z,1352745946.161 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:46:09.858Z,1352745969.858 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:46:09.858Z,1352745969.858 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:46:36.485Z,1352745996.485 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:46:36.485Z,1352745996.485 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:47:02.246Z,1352746022.246 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:47:02.246Z,1352746022.246 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:47:27.925Z,1352746047.925 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:47:27.925Z,1352746047.925 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:47:48.665Z,1352746068.665 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:47:48.665Z,1352746068.665 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:48:10.485Z,1352746090.485 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:48:10.485Z,1352746090.485 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:48:30.662Z,1352746110.662 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:48:30.662Z,1352746110.662 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:48:46.048Z,1352746126.048 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:48:46.048Z,1352746126.048 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:49:02.353Z,1352746142.353 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:49:02.353Z,1352746142.353 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:49:20.277Z,1352746160.277 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:49:20.278Z,1352746160.277 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:49:37.244Z,1352746177.244 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:49:37.244Z,1352746177.244 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:49:45.953Z,1352746185.953 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:49:45.953Z,1352746185.953 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:49:54.561Z,1352746194.561 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:49:54.561Z,1352746194.561 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:50:03.129Z,1352746203.129 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:50:03.129Z,1352746203.129 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:50:20.277Z,1352746220.277 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:50:20.277Z,1352746220.277 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:50:28.849Z,1352746228.849 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:50:28.849Z,1352746228.849 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:50:37.851Z,1352746237.851 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:50:37.851Z,1352746237.851 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:50:46.364Z,1352746246.364 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:50:46.364Z,1352746246.364 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:50:54.925Z,1352746254.925 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:50:54.925Z,1352746254.925 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:51:03.574Z,1352746263.574 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:51:03.574Z,1352746263.574 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:51:12.049Z,1352746272.049 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:51:12.049Z,1352746272.049 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:51:20.649Z,1352746280.649 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:51:20.649Z,1352746280.649 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:51:29.674Z,1352746289.674 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:51:29.674Z,1352746289.674 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:51:37.961Z,1352746297.961 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:51:37.961Z,1352746297.961 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:51:46.537Z,1352746306.537 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:51:46.537Z,1352746306.537 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:51:55.493Z,1352746315.493 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:51:55.493Z,1352746315.493 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:52:04.073Z,1352746324.073 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:52:04.073Z,1352746324.073 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:52:18.644Z,1352746338.644 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:52:18.644Z,1352746338.644 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:52:35.786Z,1352746355.786 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:52:35.786Z,1352746355.786 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:53:02.261Z,1352746382.261 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:53:02.261Z,1352746382.261 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:54:30.926Z,1352746470.926 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:54:30.926Z,1352746470.926 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:54:47.901Z,1352746487.901 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:54:47.901Z,1352746487.901 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:55:13.344Z,1352746513.344 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:55:13.344Z,1352746513.344 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:55:31.549Z,1352746531.549 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:55:31.549Z,1352746531.549 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:55:56.389Z,1352746556.389 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:55:56.389Z,1352746556.389 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:56:13.789Z,1352746573.789 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:56:13.789Z,1352746573.789 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:56:31.198Z,1352746591.198 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:56:31.198Z,1352746591.198 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:56:39.692Z,1352746599.692 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:56:39.692Z,1352746599.692 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:56:56.253Z,1352746616.253 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:56:56.254Z,1352746616.253 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:57:04.849Z,1352746624.849 [NAL9602](INFO): SBD MO Status=2, MOMSN=4274, MT Status=2, MTMSN=0
2012-11-12T18:57:04.849Z,1352746624.849 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:57:17.451Z,1352746637.451 [NAL9602](INFO): SBD MO Status=1, MOMSN=4274, MT Status=0, MTMSN=0
2012-11-12T18:57:17.499Z,1352746637.499 [NAL9602](INFO): Sent 332 bytes from file Logs/20121112T180055/shore0000.lzma
2012-11-12T18:57:17.499Z,1352746637.499 [NAL9602](INFO): Packets left to send: 1
2012-11-12T18:57:17.501Z,1352746637.501 [NAL9602](INFO): Stored copy of sent data in Logs/20121112T180055/shore0000.lzma.parts/0001.sbd
2012-11-12T18:57:22.133Z,1352746642.133 [NAL9602](INFO): SBD MO Status=2, MOMSN=4275, MT Status=2, MTMSN=0
2012-11-12T18:57:22.133Z,1352746642.133 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:57:30.725Z,1352746650.725 [NAL9602](INFO): SBD MO Status=2, MOMSN=4275, MT Status=2, MTMSN=0
2012-11-12T18:57:30.725Z,1352746650.725 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:57:39.713Z,1352746659.713 [NAL9602](INFO): SBD MO Status=2, MOMSN=4275, MT Status=2, MTMSN=0
2012-11-12T18:57:39.713Z,1352746659.713 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:57:48.347Z,1352746668.347 [NAL9602](INFO): SBD MO Status=2, MOMSN=4275, MT Status=2, MTMSN=0
2012-11-12T18:57:48.347Z,1352746668.347 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:58:06.189Z,1352746686.189 [NAL9602](INFO): SBD MO Status=2, MOMSN=4275, MT Status=2, MTMSN=0
2012-11-12T18:58:06.189Z,1352746686.189 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:58:14.794Z,1352746694.793 [NAL9602](INFO): SBD MO Status=2, MOMSN=4275, MT Status=2, MTMSN=0
2012-11-12T18:58:14.794Z,1352746694.794 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:58:23.344Z,1352746703.344 [NAL9602](INFO): SBD MO Status=2, MOMSN=4275, MT Status=2, MTMSN=0
2012-11-12T18:58:23.344Z,1352746703.344 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:58:31.973Z,1352746711.973 [NAL9602](INFO): SBD MO Status=2, MOMSN=4275, MT Status=2, MTMSN=0
2012-11-12T18:58:31.973Z,1352746711.973 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:58:58.117Z,1352746738.117 [NAL9602](INFO): SBD MO Status=2, MOMSN=4275, MT Status=2, MTMSN=0
2012-11-12T18:58:58.117Z,1352746738.117 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:59:17.161Z,1352746757.161 [NAL9602](INFO): SBD MO Status=1, MOMSN=4275, MT Status=0, MTMSN=0
2012-11-12T18:59:17.211Z,1352746757.211 [NAL9602](INFO): Sent 162 bytes from file Logs/20121112T180055/shore0000.lzma
2012-11-12T18:59:17.211Z,1352746757.211 [NAL9602](INFO): Packets left to send: 0
2012-11-12T18:59:17.212Z,1352746757.212 [NAL9602](INFO): Stored copy of sent data in Logs/20121112T180055/shore0000.lzma.parts/0000.sbd
2012-11-12T18:59:22.619Z,1352746762.619 [NAL9602](INFO): SBD MO Status=2, MOMSN=4276, MT Status=2, MTMSN=0
2012-11-12T18:59:22.619Z,1352746762.619 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:59:31.229Z,1352746771.229 [NAL9602](INFO): SBD MO Status=2, MOMSN=4276, MT Status=2, MTMSN=0
2012-11-12T18:59:31.229Z,1352746771.229 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:59:40.250Z,1352746780.250 [NAL9602](INFO): SBD MO Status=2, MOMSN=4276, MT Status=2, MTMSN=0
2012-11-12T18:59:40.250Z,1352746780.250 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T18:59:48.861Z,1352746788.861 [NAL9602](INFO): SBD MO Status=2, MOMSN=4276, MT Status=2, MTMSN=0
2012-11-12T18:59:48.861Z,1352746788.861 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T19:00:01.545Z,1352746801.545 [NAL9602](INFO): SBD MO Status=1, MOMSN=4276, MT Status=0, MTMSN=0
2012-11-12T19:00:01.595Z,1352746801.595 [NAL9602](INFO): Sent 332 bytes from file Logs/20121112T180055/shore0001.lzma
2012-11-12T19:00:01.595Z,1352746801.595 [NAL9602](INFO): Packets left to send: 1
2012-11-12T19:00:01.596Z,1352746801.596 [NAL9602](INFO): Stored copy of sent data in Logs/20121112T180055/shore0001.lzma.parts/0001.sbd
2012-11-12T19:00:09.385Z,1352746809.385 [NAL9602](INFO): SBD MO Status=1, MOMSN=4277, MT Status=0, MTMSN=0
2012-11-12T19:00:09.435Z,1352746809.435 [NAL9602](INFO): Sent 35 bytes from file Logs/20121112T180055/shore0001.lzma
2012-11-12T19:00:09.435Z,1352746809.435 [NAL9602](INFO): Packets left to send: 0
2012-11-12T19:00:09.437Z,1352746809.437 [NAL9602](INFO): Stored copy of sent data in Logs/20121112T180055/shore0001.lzma.parts/0000.sbd
2012-11-12T19:00:18.461Z,1352746818.461 [NAL9602](INFO): SBD MO Status=1, MOMSN=4278, MT Status=0, MTMSN=0
2012-11-12T19:00:18.511Z,1352746818.511 [NAL9602](INFO): Sent 332 bytes from file Logs/20121112T183047/shore0000.lzma
2012-11-12T19:00:18.511Z,1352746818.511 [NAL9602](INFO): Packets left to send: 1
2012-11-12T19:00:18.513Z,1352746818.513 [NAL9602](INFO): Stored copy of sent data in Logs/20121112T183047/shore0000.lzma.parts/0001.sbd
2012-11-12T19:00:29.918Z,1352746829.918 [NAL9602](INFO): SBD MO Status=1, MOMSN=4279, MT Status=0, MTMSN=0
2012-11-12T19:00:29.963Z,1352746829.963 [NAL9602](INFO): Sent 216 bytes from file Logs/20121112T183047/shore0000.lzma
2012-11-12T19:00:29.963Z,1352746829.963 [NAL9602](INFO): Packets left to send: 0
2012-11-12T19:00:29.964Z,1352746829.964 [NAL9602](INFO): Stored copy of sent data in Logs/20121112T183047/shore0000.lzma.parts/0000.sbd
2012-11-12T19:00:41.089Z,1352746841.089 [NAL9602](INFO): SBD MO Status=0, MOMSN=4280, MT Status=0, MTMSN=0
2012-11-12T19:00:41.181Z,1352746841.181 [Default:Iridium:Read_Iridium] Stopped
2012-11-12T19:00:41.181Z,1352746841.181 [Default:Iridium](INFO): Completed Default:Iridium
2012-11-12T19:00:41.181Z,1352746841.181 [Default:Iridium] Stopped
2012-11-12T19:00:41.182Z,1352746841.181 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2012-11-12T19:00:41.182Z,1352746841.182 [Default:Iridium:A.SetSpeed] Stopped
2012-11-12T19:00:41.182Z,1352746841.182 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2012-11-12T19:00:41.182Z,1352746841.182 [Default:F.Wait] Running Loop=1
2012-11-12T19:00:41.182Z,1352746841.182 [Default:F.Wait](DEBUG): Initialize Wait Component.
2012-11-12T19:00:41.512Z,1352746841.511 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2012-11-12T19:00:41.512Z,1352746841.512 [Default:CallIridium:B] Stopped
2012-11-12T19:00:41.512Z,1352746841.512 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2012-11-12T19:00:41.512Z,1352746841.512 [Default:CallIridium](INFO): Completed Default:CallIridium
2012-11-12T19:00:41.512Z,1352746841.512 [Default:CallIridium] Stopped
2012-11-12T19:00:41.512Z,1352746841.512 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2012-11-12T19:00:51.624Z,1352746851.624 [NAL9602](INFO): Powering down
2012-11-12T19:01:56.240Z,1352746916.240 [CommandLine](IMPORTANT): got command ibit
2012-11-12T19:01:56.714Z,1352746916.714 [IBIT](IMPORTANT): Beginning Initiated BIT
2012-11-12T19:01:56.715Z,1352746916.715 [IBIT](IMPORTANT): Beginning control surface checks.
2012-11-12T19:01:56.716Z,1352746916.717 [CBIT](IMPORTANT): Beginning GF scan
2012-11-12T19:02:01.653Z,1352746921.653 [NAL9602](INFO): Powering up
2012-11-12T19:02:01.905Z,1352746921.905 [Radio_Freewave](INFO): Powering down
2012-11-12T19:02:02.301Z,1352746922.301 [Radio_Freewave](INFO): Powering up
2012-11-12T19:02:12.375Z,1352746932.375 [NAL9602](INFO): NAL9602 initialized
2012-11-12T19:02:23.191Z,1352746943.191 [CBIT](IMPORTANT): No ground fault detected
2012-11-12T19:02:31.891Z,1352746951.891 [NAL9602](IMPORTANT): GPS fix at: 1352746954.00
2012-11-12T19:02:34.811Z,1352746954.811 [NAL9602](IMPORTANT): GPS fix at: 1352746957.00
2012-11-12T19:02:37.551Z,1352746957.551 [NAL9602](IMPORTANT): GPS fix at: 1352746959.00
2012-11-12T19:02:40.746Z,1352746960.746 [NAL9602](IMPORTANT): GPS fix at: 1352746963.00
2012-11-12T19:02:43.545Z,1352746963.545 [NAL9602](IMPORTANT): GPS fix at: 1352746965.00
2012-11-12T19:02:46.738Z,1352746966.738 [NAL9602](IMPORTANT): GPS fix at: 1352746969.00
2012-11-12T19:02:49.545Z,1352746969.545 [NAL9602](IMPORTANT): GPS fix at: 1352746971.00
2012-11-12T19:02:52.745Z,1352746972.745 [NAL9602](IMPORTANT): GPS fix at: 1352746975.00
2012-11-12T19:02:55.583Z,1352746975.583 [NAL9602](IMPORTANT): GPS fix at: 1352746978.00
2012-11-12T19:02:58.783Z,1352746978.783 [NAL9602](IMPORTANT): GPS fix at: 1352746981.00
2012-11-12T19:03:01.546Z,1352746981.546 [NAL9602](IMPORTANT): GPS fix at: 1352746983.00
2012-11-12T19:03:04.746Z,1352746984.746 [NAL9602](IMPORTANT): GPS fix at: 1352746987.00
2012-11-12T19:03:07.545Z,1352746987.545 [NAL9602](IMPORTANT): GPS fix at: 1352746989.00
2012-11-12T19:03:10.746Z,1352746990.746 [NAL9602](IMPORTANT): GPS fix at: 1352746993.00
2012-11-12T19:03:13.545Z,1352746993.545 [NAL9602](IMPORTANT): GPS fix at: 1352746996.00
2012-11-12T19:03:16.746Z,1352746996.746 [NAL9602](IMPORTANT): GPS fix at: 1352746999.00
2012-11-12T19:03:19.545Z,1352746999.545 [NAL9602](IMPORTANT): GPS fix at: 1352747002.00
2012-11-12T19:03:22.738Z,1352747002.738 [NAL9602](IMPORTANT): GPS fix at: 1352747005.00
2012-11-12T19:03:25.591Z,1352747005.591 [NAL9602](IMPORTANT): GPS fix at: 1352747008.00
2012-11-12T19:03:28.745Z,1352747008.745 [NAL9602](IMPORTANT): GPS fix at: 1352747011.00
2012-11-12T19:03:31.576Z,1352747011.576 [NAL9602](IMPORTANT): GPS fix at: 1352747014.00
2012-11-12T19:03:34.779Z,1352747014.779 [NAL9602](IMPORTANT): GPS fix at: 1352747017.00
2012-11-12T19:03:37.545Z,1352747017.545 [NAL9602](IMPORTANT): GPS fix at: 1352747021.00
2012-11-12T19:03:40.746Z,1352747020.746 [NAL9602](IMPORTANT): GPS fix at: 1352747024.00
2012-11-12T19:03:43.545Z,1352747023.545 [NAL9602](IMPORTANT): GPS fix at: 1352747027.00
2012-11-12T19:03:46.746Z,1352747026.746 [NAL9602](IMPORTANT): GPS fix at: 1352747030.00
2012-11-12T19:03:47.625Z,1352747027.625 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired.
2012-11-12T19:03:48.037Z,1352747028.037 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 145.809998
Voltage: 15.701437
2012-11-12T19:03:48.038Z,1352747028.038 [IBIT](IMPORTANT): batteryCapacityThreshold: 5.000000 Ah
2012-11-12T19:03:48.038Z,1352747028.038 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.500000 V
2012-11-12T19:03:48.481Z,1352747028.481 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2012-11-12T19:03:48.481Z,1352747028.481 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2012-11-12T19:03:48.482Z,1352747028.482 [IBIT](IMPORTANT): Pressure:17.637238 PSI
2012-11-12T19:03:48.482Z,1352747028.482 [IBIT](IMPORTANT): Humidity:25.185555 %
2012-11-12T19:03:48.825Z,1352747028.825 [IBIT](IMPORTANT): surfaceThreshold: 0.500000 m
2012-11-12T19:03:48.825Z,1352747028.825 [IBIT](IMPORTANT): buoyancyNeutral: 498.000000 cc
2012-11-12T19:03:48.826Z,1352747028.826 [IBIT](IMPORTANT): massDefault: 1.090000 cm
2012-11-12T19:03:48.826Z,1352747028.826 [IBIT](IMPORTANT): stopDepth: 125.000000 m
2012-11-12T19:03:48.826Z,1352747028.826 [IBIT](IMPORTANT): abortDepth: 150.000000 m
2012-11-12T19:03:48.826Z,1352747028.826 [IBIT](IMPORTANT): IBIT FAILED
2012-11-12T19:03:54.361Z,1352747034.361 [NAL9602](IMPORTANT): GPS fix at: 1352747033.00
2012-11-12T19:04:19.296Z,1352747059.296 [NAL9602](INFO): Powering down
2012-11-12T19:05:44.356Z,1352747144.356 [Default:CallIridium] Running Loop=1
2012-11-12T19:05:44.356Z,1352747144.356 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2012-11-12T19:05:44.356Z,1352747144.356 [Default:CallIridium:A] Running Loop=1
2012-11-12T19:05:44.357Z,1352747144.357 [Default:CallIridium:A] Stopped
2012-11-12T19:05:44.357Z,1352747144.357 [Default:CallIridium:B] Running Loop=1
2012-11-12T19:05:44.357Z,1352747144.357 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2012-11-12T19:05:49.312Z,1352747149.312 [Default:Iridium] Running Loop=1
2012-11-12T19:05:49.312Z,1352747149.312 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2012-11-12T19:05:49.312Z,1352747149.312 [Default:Iridium:A.SetSpeed] Running Loop=1
2012-11-12T19:05:49.312Z,1352747149.312 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2012-11-12T19:05:49.312Z,1352747149.312 [Default:Iridium:B.GoToSurface] Running Loop=1
2012-11-12T19:05:49.312Z,1352747149.312 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-11-12T19:05:49.313Z,1352747149.313 [Default:Iridium:B.GoToSurface] Stopped
2012-11-12T19:05:49.313Z,1352747149.313 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-11-12T19:05:49.313Z,1352747149.313 [Default:Iridium:Read_Iridium] Running Loop=1
2012-11-12T19:05:49.314Z,1352747149.314 [Default:GPS] Running Loop=1
2012-11-12T19:05:49.314Z,1352747149.314 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2012-11-12T19:05:49.314Z,1352747149.314 [Default:GPS:A.SetSpeed] Running Loop=1
2012-11-12T19:05:49.314Z,1352747149.314 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2012-11-12T19:05:49.314Z,1352747149.314 [Default:GPS:B.GoToSurface] Running Loop=1
2012-11-12T19:05:49.314Z,1352747149.314 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-11-12T19:05:49.315Z,1352747149.315 [Default:GPS:B.GoToSurface] Stopped
2012-11-12T19:05:49.315Z,1352747149.315 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-11-12T19:05:49.315Z,1352747149.315 [Default:GPS:Read_GPS] Running Loop=1
2012-11-12T19:05:50.012Z,1352747150.012 [NAL9602](INFO): Powering up
2012-11-12T19:06:00.423Z,1352747160.423 [NAL9602](INFO): NAL9602 initialized
2012-11-12T19:06:20.789Z,1352747180.789 [NAL9602](INFO): SBD MO Status=1, MOMSN=4281, MT Status=0, MTMSN=0
2012-11-12T19:06:20.845Z,1352747180.845 [NAL9602](INFO): Sent 332 bytes from file Logs/20121112T183047/shore0001.lzma
2012-11-12T19:06:20.845Z,1352747180.845 [NAL9602](INFO): Packets left to send: 3
2012-11-12T19:06:20.847Z,1352747180.847 [NAL9602](INFO): Stored copy of sent data in Logs/20121112T183047/shore0001.lzma.parts/0003.sbd
2012-11-12T19:06:27.485Z,1352747187.485 [NAL9602](INFO): SBD MO Status=2, MOMSN=4282, MT Status=2, MTMSN=0
2012-11-12T19:06:27.486Z,1352747187.486 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T19:06:28.687Z,1352747188.687 [NAL9602](IMPORTANT): GPS fix at: 1352747191.99
2012-11-12T19:06:28.707Z,1352747188.707 [Default:GPS:Read_GPS] Stopped
2012-11-12T19:06:28.707Z,1352747188.707 [Default:GPS:D] Running Loop=1
2012-11-12T19:06:29.112Z,1352747189.112 [Default:GPS:D] Stopped
2012-11-12T19:06:29.113Z,1352747189.113 [Default:GPS](INFO): Completed Default:GPS
2012-11-12T19:06:29.113Z,1352747189.113 [Default:GPS] Stopped
2012-11-12T19:06:29.113Z,1352747189.113 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2012-11-12T19:06:29.113Z,1352747189.113 [Default:GPS:A.SetSpeed] Stopped
2012-11-12T19:06:29.113Z,1352747189.113 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2012-11-12T19:07:01.493Z,1352747221.493 [NAL9602](INFO): SBD MO Status=2, MOMSN=4282, MT Status=2, MTMSN=0
2012-11-12T19:07:01.493Z,1352747221.493 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T19:07:27.385Z,1352747247.385 [NAL9602](INFO): SBD MO Status=1, MOMSN=4282, MT Status=0, MTMSN=0
2012-11-12T19:07:27.435Z,1352747247.435 [NAL9602](INFO): Sent 332 bytes from file Logs/20121112T183047/shore0001.lzma
2012-11-12T19:07:27.435Z,1352747247.435 [NAL9602](INFO): Packets left to send: 2
2012-11-12T19:07:27.436Z,1352747247.436 [NAL9602](INFO): Stored copy of sent data in Logs/20121112T183047/shore0001.lzma.parts/0002.sbd
2012-11-12T19:07:45.414Z,1352747265.414 [NAL9602](INFO): SBD MO Status=1, MOMSN=4283, MT Status=0, MTMSN=0
2012-11-12T19:07:45.463Z,1352747265.463 [NAL9602](INFO): Sent 332 bytes from file Logs/20121112T183047/shore0001.lzma
2012-11-12T19:07:45.463Z,1352747265.463 [NAL9602](INFO): Packets left to send: 1
2012-11-12T19:07:45.464Z,1352747265.464 [NAL9602](INFO): Stored copy of sent data in Logs/20121112T183047/shore0001.lzma.parts/0001.sbd
2012-11-12T19:07:56.185Z,1352747276.185 [NAL9602](INFO): SBD MO Status=1, MOMSN=4284, MT Status=0, MTMSN=0
2012-11-12T19:07:56.235Z,1352747276.235 [NAL9602](INFO): Sent 241 bytes from file Logs/20121112T183047/shore0001.lzma
2012-11-12T19:07:56.235Z,1352747276.235 [NAL9602](INFO): Packets left to send: 0
2012-11-12T19:07:56.236Z,1352747276.236 [NAL9602](INFO): Stored copy of sent data in Logs/20121112T183047/shore0001.lzma.parts/0000.sbd
2012-11-12T19:08:05.426Z,1352747285.426 [NAL9602](INFO): SBD MO Status=0, MOMSN=4285, MT Status=0, MTMSN=0
2012-11-12T19:08:05.521Z,1352747285.521 [Default:Iridium:Read_Iridium] Stopped
2012-11-12T19:08:05.521Z,1352747285.521 [Default:Iridium](INFO): Completed Default:Iridium
2012-11-12T19:08:05.521Z,1352747285.521 [Default:Iridium] Stopped
2012-11-12T19:08:05.521Z,1352747285.521 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2012-11-12T19:08:05.521Z,1352747285.522 [Default:Iridium:A.SetSpeed] Stopped
2012-11-12T19:08:05.521Z,1352747285.522 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2012-11-12T19:08:05.804Z,1352747285.804 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2012-11-12T19:08:05.804Z,1352747285.805 [Default:CallIridium:B] Stopped
2012-11-12T19:08:05.805Z,1352747285.805 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2012-11-12T19:08:05.805Z,1352747285.805 [Default:CallIridium](INFO): Completed Default:CallIridium
2012-11-12T19:08:05.805Z,1352747285.805 [Default:CallIridium] Stopped
2012-11-12T19:08:05.805Z,1352747285.805 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2012-11-12T19:08:15.948Z,1352747295.948 [NAL9602](INFO): Powering down
2012-11-12T19:13:05.988Z,1352747585.988 [Default:CallIridium] Running Loop=1
2012-11-12T19:13:05.988Z,1352747585.989 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2012-11-12T19:13:05.989Z,1352747585.989 [Default:CallIridium:A] Running Loop=1
2012-11-12T19:13:05.989Z,1352747585.989 [Default:CallIridium:A] Stopped
2012-11-12T19:13:05.989Z,1352747585.989 [Default:CallIridium:B] Running Loop=1
2012-11-12T19:13:05.989Z,1352747585.989 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2012-11-12T19:13:10.968Z,1352747590.968 [Default:Iridium] Running Loop=1
2012-11-12T19:13:10.968Z,1352747590.968 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2012-11-12T19:13:10.968Z,1352747590.968 [Default:Iridium:A.SetSpeed] Running Loop=1
2012-11-12T19:13:10.968Z,1352747590.968 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2012-11-12T19:13:10.969Z,1352747590.969 [Default:Iridium:B.GoToSurface] Running Loop=1
2012-11-12T19:13:10.969Z,1352747590.969 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-11-12T19:13:10.969Z,1352747590.969 [Default:Iridium:B.GoToSurface] Stopped
2012-11-12T19:13:10.970Z,1352747590.970 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-11-12T19:13:10.970Z,1352747590.970 [Default:Iridium:Read_Iridium] Running Loop=1
2012-11-12T19:13:10.970Z,1352747590.970 [Default:GPS] Running Loop=1
2012-11-12T19:13:10.970Z,1352747590.970 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2012-11-12T19:13:10.970Z,1352747590.970 [Default:GPS:A.SetSpeed] Running Loop=1
2012-11-12T19:13:10.970Z,1352747590.970 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2012-11-12T19:13:10.970Z,1352747590.970 [Default:GPS:B.GoToSurface] Running Loop=1
2012-11-12T19:13:10.970Z,1352747590.970 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-11-12T19:13:10.971Z,1352747590.971 [Default:GPS:B.GoToSurface] Stopped
2012-11-12T19:13:10.971Z,1352747590.971 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-11-12T19:13:10.971Z,1352747590.971 [Default:GPS:Read_GPS] Running Loop=1
2012-11-12T19:13:11.688Z,1352747591.688 [NAL9602](INFO): Powering up
2012-11-12T19:13:22.523Z,1352747602.523 [NAL9602](INFO): NAL9602 initialized
2012-11-12T19:13:54.589Z,1352747634.589 [NAL9602](INFO): SBD MO Status=2, MOMSN=4286, MT Status=2, MTMSN=0
2012-11-12T19:13:54.590Z,1352747634.589 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T19:13:55.743Z,1352747635.743 [NAL9602](IMPORTANT): GPS fix at: 1352747639.00
2012-11-12T19:13:55.760Z,1352747635.760 [Default:GPS:Read_GPS] Stopped
2012-11-12T19:13:55.761Z,1352747635.760 [Default:GPS:D] Running Loop=1
2012-11-12T19:13:56.169Z,1352747636.169 [Default:GPS:D] Stopped
2012-11-12T19:13:56.169Z,1352747636.169 [Default:GPS](INFO): Completed Default:GPS
2012-11-12T19:13:56.169Z,1352747636.169 [Default:GPS] Stopped
2012-11-12T19:13:56.169Z,1352747636.170 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2012-11-12T19:13:56.170Z,1352747636.170 [Default:GPS:A.SetSpeed] Stopped
2012-11-12T19:13:56.170Z,1352747636.170 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2012-11-12T19:14:20.786Z,1352747660.786 [NAL9602](INFO): SBD MO Status=2, MOMSN=4286, MT Status=2, MTMSN=0
2012-11-12T19:14:20.786Z,1352747660.786 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T19:14:49.844Z,1352747689.844 [NAL9602](INFO): SBD MO Status=1, MOMSN=4286, MT Status=0, MTMSN=0
2012-11-12T19:14:49.891Z,1352747689.891 [NAL9602](INFO): Sent 139 bytes from file Logs/20121112T183047/shore0002.lzma
2012-11-12T19:14:49.891Z,1352747689.891 [NAL9602](INFO): Packets left to send: 0
2012-11-12T19:14:49.892Z,1352747689.892 [NAL9602](INFO): Stored copy of sent data in Logs/20121112T183047/shore0002.lzma.parts/0000.sbd
2012-11-12T19:14:58.563Z,1352747698.563 [CommandLine](IMPORTANT): got command ibit
2012-11-12T19:14:58.701Z,1352747698.701 [IBIT](IMPORTANT): Beginning Initiated BIT
2012-11-12T19:14:58.701Z,1352747698.701 [IBIT](IMPORTANT): Beginning control surface checks.
2012-11-12T19:14:58.703Z,1352747698.703 [CBIT](IMPORTANT): Beginning GF scan
2012-11-12T19:14:59.811Z,1352747699.811 [NAL9602](INFO): SBD MO Status=0, MOMSN=4287, MT Status=0, MTMSN=0
2012-11-12T19:15:01.023Z,1352747701.023 [NAL9602](IMPORTANT): GPS fix at: 1352747704.00
2012-11-12T19:15:22.432Z,1352747722.432 [NAL9602](INFO): SBD MO Status=1, MOMSN=4288, MT Status=0, MTMSN=0
2012-11-12T19:15:22.483Z,1352747722.483 [NAL9602](INFO): Sent 263 bytes from file Logs/20121112T183047/shore0003.lzma
2012-11-12T19:15:22.483Z,1352747722.483 [NAL9602](INFO): Packets left to send: 0
2012-11-12T19:15:22.484Z,1352747722.484 [NAL9602](INFO): Stored copy of sent data in Logs/20121112T183047/shore0003.lzma.parts/0000.sbd
2012-11-12T19:15:25.335Z,1352747725.335 [CBIT](IMPORTANT): No ground fault detected
2012-11-12T19:15:40.436Z,1352747740.436 [NAL9602](INFO): SBD MO Status=2, MOMSN=4289, MT Status=2, MTMSN=0
2012-11-12T19:15:40.436Z,1352747740.436 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T19:15:41.645Z,1352747741.645 [NAL9602](IMPORTANT): GPS fix at: 1352747745.00
2012-11-12T19:15:44.526Z,1352747744.526 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 5
Latitude: 36.802898 Longitude: -121.788078
2012-11-12T19:15:45.452Z,1352747745.452 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 145.630005
Voltage: 15.691938
2012-11-12T19:15:45.453Z,1352747745.453 [IBIT](IMPORTANT): batteryCapacityThreshold: 5.000000 Ah
2012-11-12T19:15:45.453Z,1352747745.453 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.500000 V
2012-11-12T19:15:45.733Z,1352747745.733 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2012-11-12T19:15:45.734Z,1352747745.734 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2012-11-12T19:15:45.734Z,1352747745.734 [IBIT](IMPORTANT): Pressure:17.637238 PSI
2012-11-12T19:15:45.734Z,1352747745.734 [IBIT](IMPORTANT): Humidity:24.503868 %
2012-11-12T19:15:46.129Z,1352747746.129 [IBIT](IMPORTANT): surfaceThreshold: 0.500000 m
2012-11-12T19:15:46.129Z,1352747746.129 [IBIT](IMPORTANT): buoyancyNeutral: 498.000000 cc
2012-11-12T19:15:46.130Z,1352747746.130 [IBIT](IMPORTANT): massDefault: 1.090000 cm
2012-11-12T19:15:46.130Z,1352747746.130 [IBIT](IMPORTANT): stopDepth: 125.000000 m
2012-11-12T19:15:46.130Z,1352747746.130 [IBIT](IMPORTANT): abortDepth: 150.000000 m
2012-11-12T19:15:46.131Z,1352747746.131 [IBIT](IMPORTANT): IBIT PASSED
2012-11-12T19:15:46.488Z,1352747746.488 [Default:Iridium:Read_Iridium] Stopped
2012-11-12T19:15:46.488Z,1352747746.489 [Default:Iridium](INFO): Completed Default:Iridium
2012-11-12T19:15:46.488Z,1352747746.489 [Default:Iridium] Stopped
2012-11-12T19:15:46.489Z,1352747746.489 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2012-11-12T19:15:46.489Z,1352747746.489 [Default:Iridium:A.SetSpeed] Stopped
2012-11-12T19:15:46.489Z,1352747746.489 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2012-11-12T19:15:46.859Z,1352747746.859 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2012-11-12T19:15:46.859Z,1352747746.859 [Default:CallIridium:B] Stopped
2012-11-12T19:15:46.859Z,1352747746.859 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2012-11-12T19:15:46.859Z,1352747746.859 [Default:CallIridium](INFO): Completed Default:CallIridium
2012-11-12T19:15:46.860Z,1352747746.860 [Default:CallIridium] Stopped
2012-11-12T19:15:46.860Z,1352747746.860 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2012-11-12T19:15:52.017Z,1352747752.017 [NAL9602](INFO): SBD MO Status=0, MOMSN=4289, MT Status=0, MTMSN=0
2012-11-12T19:16:07.031Z,1352747767.031 [NAL9602](INFO): Powering down
2012-11-12T19:20:57.061Z,1352748057.061 [Default:CallIridium] Running Loop=1
2012-11-12T19:20:57.061Z,1352748057.061 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2012-11-12T19:20:57.062Z,1352748057.062 [Default:CallIridium:A] Running Loop=1
2012-11-12T19:20:57.062Z,1352748057.062 [Default:CallIridium:A] Stopped
2012-11-12T19:20:57.062Z,1352748057.062 [Default:CallIridium:B] Running Loop=1
2012-11-12T19:20:57.062Z,1352748057.062 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2012-11-12T19:21:02.016Z,1352748062.016 [Default:Iridium] Running Loop=1
2012-11-12T19:21:02.017Z,1352748062.017 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2012-11-12T19:21:02.017Z,1352748062.017 [Default:Iridium:A.SetSpeed] Running Loop=1
2012-11-12T19:21:02.017Z,1352748062.017 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2012-11-12T19:21:02.017Z,1352748062.017 [Default:Iridium:B.GoToSurface] Running Loop=1
2012-11-12T19:21:02.017Z,1352748062.017 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-11-12T19:21:02.018Z,1352748062.018 [Default:Iridium:B.GoToSurface] Stopped
2012-11-12T19:21:02.018Z,1352748062.018 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-11-12T19:21:02.018Z,1352748062.018 [Default:Iridium:Read_Iridium] Running Loop=1
2012-11-12T19:21:02.018Z,1352748062.018 [Default:GPS] Running Loop=1
2012-11-12T19:21:02.019Z,1352748062.019 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2012-11-12T19:21:02.019Z,1352748062.019 [Default:GPS:A.SetSpeed] Running Loop=1
2012-11-12T19:21:02.019Z,1352748062.019 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2012-11-12T19:21:02.019Z,1352748062.019 [Default:GPS:B.GoToSurface] Running Loop=1
2012-11-12T19:21:02.019Z,1352748062.019 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-11-12T19:21:02.020Z,1352748062.020 [Default:GPS:B.GoToSurface] Stopped
2012-11-12T19:21:02.020Z,1352748062.020 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-11-12T19:21:02.020Z,1352748062.020 [Default:GPS:Read_GPS] Running Loop=1
2012-11-12T19:21:02.720Z,1352748062.720 [NAL9602](INFO): Powering up
2012-11-12T19:21:13.143Z,1352748073.143 [NAL9602](INFO): NAL9602 initialized
2012-11-12T19:21:31.145Z,1352748091.145 [NAL9602](IMPORTANT): GPS fix at: 1352748095.00
2012-11-12T19:21:31.162Z,1352748091.162 [Default:GPS:Read_GPS] Stopped
2012-11-12T19:21:31.162Z,1352748091.162 [Default:GPS:D] Running Loop=1
2012-11-12T19:21:31.576Z,1352748091.576 [Default:GPS:D] Stopped
2012-11-12T19:21:31.577Z,1352748091.577 [Default:GPS](INFO): Completed Default:GPS
2012-11-12T19:21:31.577Z,1352748091.577 [Default:GPS] Stopped
2012-11-12T19:21:31.577Z,1352748091.577 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2012-11-12T19:21:31.577Z,1352748091.577 [Default:GPS:A.SetSpeed] Stopped
2012-11-12T19:21:31.577Z,1352748091.577 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2012-11-12T19:22:13.649Z,1352748133.649 [NAL9602](INFO): SBD MO Status=2, MOMSN=4290, MT Status=2, MTMSN=0
2012-11-12T19:22:13.649Z,1352748133.649 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T19:22:40.453Z,1352748160.453 [NAL9602](INFO): SBD MO Status=2, MOMSN=4290, MT Status=2, MTMSN=0
2012-11-12T19:22:40.453Z,1352748160.453 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T19:23:08.034Z,1352748188.034 [NAL9602](INFO): SBD MO Status=2, MOMSN=4290, MT Status=2, MTMSN=0
2012-11-12T19:23:08.034Z,1352748188.034 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2012-11-12T19:23:51.053Z,1352748231.053 [NAL9602](INFO): SBD MO Status=1, MOMSN=4290, MT Status=0, MTMSN=0
2012-11-12T19:23:51.103Z,1352748231.103 [NAL9602](INFO): Sent 332 bytes from file Logs/20121112T183047/shore0004.lzma
2012-11-12T19:23:51.103Z,1352748231.103 [NAL9602](INFO): Packets left to send: 1
2012-11-12T19:23:51.105Z,1352748231.105 [NAL9602](INFO): Stored copy of sent data in Logs/20121112T183047/shore0004.lzma.parts/0001.sbd
2012-11-12T19:24:10.149Z,1352748250.149 [NAL9602](INFO): SBD MO Status=1, MOMSN=4291, MT Status=0, MTMSN=0
2012-11-12T19:24:10.199Z,1352748250.199 [NAL9602](INFO): Sent 180 bytes from file Logs/20121112T183047/shore0004.lzma
2012-11-12T19:24:10.199Z,1352748250.199 [NAL9602](INFO): Packets left to send: 0
2012-11-12T19:24:10.200Z,1352748250.200 [NAL9602](INFO): Stored copy of sent data in Logs/20121112T183047/shore0004.lzma.parts/0000.sbd
2012-11-12T19:24:19.749Z,1352748259.749 [NAL9602](INFO): SBD MO Status=0, MOMSN=4292, MT Status=0, MTMSN=0
2012-11-12T19:24:19.856Z,1352748259.856 [Default:Iridium:Read_Iridium] Stopped
2012-11-12T19:24:19.857Z,1352748259.857 [Default:Iridium](INFO): Completed Default:Iridium
2012-11-12T19:24:19.857Z,1352748259.857 [Default:Iridium] Stopped
2012-11-12T19:24:19.857Z,1352748259.857 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2012-11-12T19:24:19.857Z,1352748259.857 [Default:Iridium:A.SetSpeed] Stopped
2012-11-12T19:24:19.857Z,1352748259.857 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2012-11-12T19:24:20.197Z,1352748260.197 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2012-11-12T19:24:20.197Z,1352748260.197 [Default:CallIridium:B] Stopped
2012-11-12T19:24:20.197Z,1352748260.197 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2012-11-12T19:24:20.197Z,1352748260.197 [Default:CallIridium](INFO): Completed Default:CallIridium
2012-11-12T19:24:20.197Z,1352748260.197 [Default:CallIridium] Stopped
2012-11-12T19:24:20.197Z,1352748260.197 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2012-11-12T19:24:30.333Z,1352748270.332 [NAL9602](INFO): Powering down
2012-11-12T19:29:20.364Z,1352748560.364 [Default:CallIridium] Running Loop=1
2012-11-12T19:29:20.364Z,1352748560.364 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2012-11-12T19:29:20.364Z,1352748560.364 [Default:CallIridium:A] Running Loop=1
2012-11-12T19:29:20.365Z,1352748560.365 [Default:CallIridium:A] Stopped
2012-11-12T19:29:20.365Z,1352748560.365 [Default:CallIridium:B] Running Loop=1
2012-11-12T19:29:20.365Z,1352748560.365 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2012-11-12T19:29:25.328Z,1352748565.328 [Default:Iridium] Running Loop=1
2012-11-12T19:29:25.328Z,1352748565.328 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2012-11-12T19:29:25.328Z,1352748565.328 [Default:Iridium:A.SetSpeed] Running Loop=1
2012-11-12T19:29:25.328Z,1352748565.328 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2012-11-12T19:29:25.328Z,1352748565.328 [Default:Iridium:B.GoToSurface] Running Loop=1
2012-11-12T19:29:25.328Z,1352748565.328 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-11-12T19:29:25.329Z,1352748565.329 [Default:Iridium:B.GoToSurface] Stopped
2012-11-12T19:29:25.329Z,1352748565.329 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-11-12T19:29:25.329Z,1352748565.329 [Default:Iridium:Read_Iridium] Running Loop=1
2012-11-12T19:29:25.330Z,1352748565.330 [Default:GPS] Running Loop=1
2012-11-12T19:29:25.330Z,1352748565.330 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2012-11-12T19:29:25.330Z,1352748565.330 [Default:GPS:A.SetSpeed] Running Loop=1
2012-11-12T19:29:25.330Z,1352748565.330 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2012-11-12T19:29:25.330Z,1352748565.330 [Default:GPS:B.GoToSurface] Running Loop=1
2012-11-12T19:29:25.330Z,1352748565.330 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-11-12T19:29:25.331Z,1352748565.331 [Default:GPS:B.GoToSurface] Stopped
2012-11-12T19:29:25.331Z,1352748565.331 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-11-12T19:29:25.331Z,1352748565.331 [Default:GPS:Read_GPS] Running Loop=1
2012-11-12T19:29:25.976Z,1352748565.976 [NAL9602](INFO): Powering up
2012-11-12T19:29:37.027Z,1352748577.027 [NAL9602](INFO): NAL9602 initialized
2012-11-12T19:29:55.917Z,1352748595.917 [NAL9602](INFO): SBD MO Status=1, MOMSN=4293, MT Status=0, MTMSN=0
2012-11-12T19:29:55.971Z,1352748595.971 [NAL9602](INFO): Sent 138 bytes from file Logs/20121112T183047/shore0005.lzma
2012-11-12T19:29:55.971Z,1352748595.971 [NAL9602](INFO): Packets left to send: 0
2012-11-12T19:29:55.973Z,1352748595.973 [NAL9602](INFO): Stored copy of sent data in Logs/20121112T183047/shore0005.lzma.parts/0000.sbd
2012-11-12T19:30:03.525Z,1352748603.525 [NAL9602](INFO): SBD MO Status=0, MOMSN=4294, MT Status=0, MTMSN=0
2012-11-12T19:30:03.611Z,1352748603.611 [Default:Iridium:Read_Iridium] Stopped
2012-11-12T19:30:03.612Z,1352748603.612 [Default:Iridium](INFO): Completed Default:Iridium
2012-11-12T19:30:03.612Z,1352748603.612 [Default:Iridium] Stopped
2012-11-12T19:30:03.612Z,1352748603.612 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2012-11-12T19:30:03.612Z,1352748603.612 [Default:Iridium:A.SetSpeed] Stopped
2012-11-12T19:30:03.612Z,1352748603.612 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2012-11-12T19:30:03.932Z,1352748603.931 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2012-11-12T19:30:03.932Z,1352748603.932 [Default:CallIridium:B] Stopped
2012-11-12T19:30:03.932Z,1352748603.932 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2012-11-12T19:30:03.932Z,1352748603.932 [Default:CallIridium](INFO): Completed Default:CallIridium
2012-11-12T19:30:03.932Z,1352748603.932 [Default:CallIridium] Stopped
2012-11-12T19:30:03.932Z,1352748603.932 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2012-11-12T19:30:04.723Z,1352748604.723 [NAL9602](IMPORTANT): GPS fix at: 1352748609.00
2012-11-12T19:30:04.755Z,1352748604.755 [Default:GPS:Read_GPS] Stopped
2012-11-12T19:30:04.755Z,1352748604.755 [Default:GPS:D] Running Loop=1
2012-11-12T19:30:05.164Z,1352748605.164 [Default:GPS:D] Stopped
2012-11-12T19:30:05.164Z,1352748605.164 [Default:GPS](INFO): Completed Default:GPS
2012-11-12T19:30:05.164Z,1352748605.164 [Default:GPS] Stopped
2012-11-12T19:30:05.165Z,1352748605.165 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2012-11-12T19:30:05.165Z,1352748605.165 [Default:GPS:A.SetSpeed] Stopped
2012-11-12T19:30:05.165Z,1352748605.165 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2012-11-12T19:30:25.713Z,1352748625.713 [NAL9602](INFO): Powering down
2012-11-12T19:35:05.716Z,1352748905.716 [Default:CallIridium] Running Loop=1
2012-11-12T19:35:05.716Z,1352748905.716 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2012-11-12T19:35:05.716Z,1352748905.716 [Default:CallIridium:A] Running Loop=1
2012-11-12T19:35:05.717Z,1352748905.717 [Default:CallIridium:A] Stopped
2012-11-12T19:35:05.717Z,1352748905.717 [Default:CallIridium:B] Running Loop=1
2012-11-12T19:35:05.717Z,1352748905.717 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2012-11-12T19:35:10.695Z,1352748910.694 [Default:Iridium] Running Loop=1
2012-11-12T19:35:10.695Z,1352748910.695 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2012-11-12T19:35:10.695Z,1352748910.695 [Default:Iridium:A.SetSpeed] Running Loop=1
2012-11-12T19:35:10.695Z,1352748910.695 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2012-11-12T19:35:10.695Z,1352748910.695 [Default:Iridium:B.GoToSurface] Running Loop=1
2012-11-12T19:35:10.695Z,1352748910.695 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-11-12T19:35:10.696Z,1352748910.696 [Default:Iridium:B.GoToSurface] Stopped
2012-11-12T19:35:10.696Z,1352748910.696 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-11-12T19:35:10.696Z,1352748910.696 [Default:Iridium:Read_Iridium] Running Loop=1
2012-11-12T19:35:10.696Z,1352748910.696 [Default:GPS] Running Loop=1
2012-11-12T19:35:10.697Z,1352748910.697 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2012-11-12T19:35:10.697Z,1352748910.697 [Default:GPS:A.SetSpeed] Running Loop=1
2012-11-12T19:35:10.697Z,1352748910.697 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2012-11-12T19:35:10.697Z,1352748910.697 [Default:GPS:B.GoToSurface] Running Loop=1
2012-11-12T19:35:10.697Z,1352748910.697 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-11-12T19:35:10.698Z,1352748910.698 [Default:GPS:B.GoToSurface] Stopped
2012-11-12T19:35:10.698Z,1352748910.698 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-11-12T19:35:10.698Z,1352748910.698 [Default:GPS:Read_GPS] Running Loop=1
2012-11-12T19:35:11.312Z,1352748911.312 [NAL9602](INFO): Powering up
2012-11-12T19:35:22.199Z,1352748922.199 [NAL9602](INFO): NAL9602 initialized
2012-11-12T19:35:44.045Z,1352748944.045 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=4295, MT Status=1, MTMSN=352
2012-11-12T19:35:44.095Z,1352748944.095 [NAL9602](INFO): Sent 165 bytes from file Logs/20121112T183047/shore0006.lzma
2012-11-12T19:35:44.095Z,1352748944.095 [NAL9602](INFO): Packets left to send: 0
2012-11-12T19:35:44.102Z,1352748944.102 [NAL9602](INFO): Stored copy of sent data in Logs/20121112T183047/shore0006.lzma.parts/0000.sbd
2012-11-12T19:35:44.687Z,1352748944.687 [NAL9602](INFO): Received command:Restart app
2012-11-12T19:35:44.779Z,1352748944.779 [CommandLine](IMPORTANT): got command restart application
2012-11-12T19:35:45.898Z,1352748945.898 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2012-11-12T19:35:45.899Z,1352748945.898 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2012-11-12T19:35:46.226Z,1352748946.226 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2012-11-12T19:35:46.556Z,1352748946.556 [WetLabsBB2FL](INFO): Powering down
2012-11-12T19:35:46.558Z,1352748946.559 [ComponentRegistry](INFO): Shutting down Turbulence_NPS ThreadHandler
2012-11-12T19:35:46.711Z,1352748946.711 [Turbulence_NPS](INFO): Uninitialize Powering down
2012-11-12T19:35:46.718Z,1352748946.718 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2012-11-12T19:35:46.883Z,1352748946.883 [CTD_NeilBrown](INFO): Powering down
2012-11-12T19:35:46.886Z,1352748946.886 [ComponentRegistry](INFO): Shutting down DVL_micro ThreadHandler
2012-11-12T19:35:47.040Z,1352748947.040 [DVL_micro](INFO): uninitialize:Powering down
2012-11-12T19:35:47.047Z,1352748947.047 [ComponentRegistry](INFO): Shutting down AsyncPiEstimator ThreadHandler
2012-11-12T19:35:47.359Z,1352748947.359 [AsyncPiEstimator](DEBUG): Uninitialize AsyncPiEstimator.
2012-11-12T19:35:47.367Z,1352748947.367 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2012-11-12T19:35:47.447Z,1352748947.447 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2012-11-12T19:35:47.449Z,1352748947.448 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2012-11-12T19:35:47.523Z,1352748947.523 [controlThread](DEBUG): Uninitializing ControlThread
2012-11-12T19:35:47.523Z,1352748947.523 [AHRS_sp3003D](INFO): Powering down
2012-11-12T19:35:47.612Z,1352748947.612 [NAL9602](INFO): Powering down
2012-11-12T19:35:47.613Z,1352748947.613 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2012-11-12T19:35:47.614Z,1352748947.614 [NavChart](DEBUG): Uninitialize NavChart Derivation.
2012-11-12T19:35:47.615Z,1352748947.615 [Default] Stopped
2012-11-12T19:35:47.615Z,1352748947.615 [Default](INFO): Aggregate::uninitialize Default
2012-11-12T19:35:47.615Z,1352748947.615 [Default:GPS] Stopped
2012-11-12T19:35:47.615Z,1352748947.615 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2012-11-12T19:35:47.615Z,1352748947.615 [Default:GPS:A.SetSpeed] Stopped
2012-11-12T19:35:47.616Z,1352748947.616 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2012-11-12T19:35:47.616Z,1352748947.616 [Default:GPS:Read_GPS] Stopped
2012-11-12T19:35:47.616Z,1352748947.616 [Default:Iridium] Stopped
2012-11-12T19:35:47.616Z,1352748947.616 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2012-11-12T19:35:47.616Z,1352748947.616 [Default:Iridium:A.SetSpeed] Stopped
2012-11-12T19:35:47.616Z,1352748947.616 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2012-11-12T19:35:47.616Z,1352748947.616 [Default:Iridium:Read_Iridium] Stopped
2012-11-12T19:35:47.616Z,1352748947.616 [Default:CallIridium] Stopped
2012-11-12T19:35:47.616Z,1352748947.616 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2012-11-12T19:35:47.616Z,1352748947.616 [Default:CallIridium:B] Stopped
2012-11-12T19:35:47.616Z,1352748947.616 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2012-11-12T19:35:47.617Z,1352748947.616 [Default:D.SetSpeed] Stopped
2012-11-12T19:35:47.617Z,1352748947.616 [Default:D.SetSpeed](DEBUG): Uninitialize.
2012-11-12T19:35:47.617Z,1352748947.617 [Default:E.GoToSurface] Stopped
2012-11-12T19:35:47.617Z,1352748947.617 [Default:E.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-11-12T19:35:47.617Z,1352748947.617 [Default:F.Wait] Stopped
2012-11-12T19:35:47.617Z,1352748947.617 [Default:F.Wait](DEBUG): Uninitialize Wait Component.
2012-11-12T19:35:47.621Z,1352748947.621 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2012-11-12T19:35:47.622Z,1352748947.622 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2012-11-12T19:35:47.622Z,1352748947.622 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2012-11-12T19:35:47.622Z,1352748947.622 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2012-11-12T19:35:47.623Z,1352748947.622 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2012-11-12T19:35:47.623Z,1352748947.623 [BuoyancyServo](INFO): Powering down
2012-11-12T19:35:47.635Z,1352748947.635 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2012-11-12T19:35:47.635Z,1352748947.635 [ElevatorServo](INFO): Powering down
2012-11-12T19:35:47.636Z,1352748947.635 [MassServo](DEBUG): Uninitialize Mass Servo.
2012-11-12T19:35:47.636Z,1352748947.636 [MassServo](INFO): Powering down
2012-11-12T19:35:47.636Z,1352748947.636 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2012-11-12T19:35:47.637Z,1352748947.636 [RudderServo](INFO): Powering down
2012-11-12T19:35:47.637Z,1352748947.637 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2012-11-12T19:35:47.637Z,1352748947.637 [ThrusterServo](INFO): Powering down
2012-11-12T19:35:47.638Z,1352748947.638 [SBIT](DEBUG): Uninitialize SBIT Component.
2012-11-12T19:35:47.639Z,1352748947.639 [IBIT](DEBUG): Uninitialize IBIT Component.
2012-11-12T19:35:47.639Z,1352748947.639 [CBIT](DEBUG): Uninitialize CBIT Component.