2012-05-22T18:24:01.863Z,1337711041.862 [Supervisor](DEBUG): Initializing supervisor.
2012-05-22T18:24:01.865Z,1337711041.865 [SyncHandler](DEBUG): Created PCaller Thread at 1077138656
2012-05-22T18:24:01.865Z,1337711041.865 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2012-05-22T18:24:01.867Z,1337711041.866 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 1077335264
2012-05-22T18:24:01.867Z,1337711041.867 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2012-05-22T18:24:01.877Z,1337711041.877 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2012-05-22T18:24:01.878Z,1337711041.878 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 1077531872
2012-05-22T18:24:01.879Z,1337711041.879 [ComponentRegistry](DEBUG): SyncComponent "logger" handled in the control thread.
2012-05-22T18:24:01.880Z,1337711041.880 [Supervisor](INFO): Looking for Config files in directory: Config/
2012-05-22T18:24:01.881Z,1337711041.881 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2012-05-22T18:24:02.147Z,1337711042.147 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2012-05-22T18:24:02.147Z,1337711042.147 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2012-05-22T18:24:02.329Z,1337711042.329 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2012-05-22T18:24:02.329Z,1337711042.329 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2012-05-22T18:24:02.412Z,1337711042.412 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2012-05-22T18:24:02.413Z,1337711042.413 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2012-05-22T18:24:02.593Z,1337711042.593 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2012-05-22T18:24:02.594Z,1337711042.594 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2012-05-22T18:24:02.716Z,1337711042.717 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2012-05-22T18:24:02.717Z,1337711042.717 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2012-05-22T18:24:02.967Z,1337711042.967 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2012-05-22T18:24:02.967Z,1337711042.967 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2012-05-22T18:24:03.111Z,1337711043.111 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2012-05-22T18:24:03.111Z,1337711043.111 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2012-05-22T18:24:03.361Z,1337711043.361 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2012-05-22T18:24:03.362Z,1337711043.362 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2012-05-22T18:24:03.457Z,1337711043.457 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2012-05-22T18:24:03.458Z,1337711043.458 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2012-05-22T18:24:03.823Z,1337711043.823 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2012-05-22T18:24:03.823Z,1337711043.823 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2012-05-22T18:24:03.930Z,1337711043.930 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2012-05-22T18:24:03.931Z,1337711043.931 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2012-05-22T18:24:04.015Z,1337711044.015 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2012-05-22T18:24:04.016Z,1337711044.016 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2012-05-22T18:24:04.116Z,1337711044.116 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2012-05-22T18:24:04.246Z,1337711044.246 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2012-05-22T18:24:04.344Z,1337711044.344 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2012-05-22T18:24:04.438Z,1337711044.438 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2012-05-22T18:24:04.545Z,1337711044.545 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2012-05-22T18:24:04.632Z,1337711044.632 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2012-05-22T18:24:04.718Z,1337711044.718 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2012-05-22T18:24:04.828Z,1337711044.828 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2012-05-22T18:24:04.948Z,1337711044.948 [InternalSim] Loaded
2012-05-22T18:24:04.949Z,1337711044.949 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2012-05-22T18:24:04.950Z,1337711044.950 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2012-05-22T18:24:04.950Z,1337711044.950 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2012-05-22T18:24:04.991Z,1337711044.991 [SBIT](DEBUG): Construct Startup Built In Test.
2012-05-22T18:24:05.002Z,1337711045.003 [SBIT] Loaded
2012-05-22T18:24:05.003Z,1337711045.003 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2012-05-22T18:24:05.004Z,1337711045.003 [IBIT](DEBUG): Construct Initiated Built In Test.
2012-05-22T18:24:05.026Z,1337711045.026 [IBIT] Loaded
2012-05-22T18:24:05.026Z,1337711045.026 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2012-05-22T18:24:05.033Z,1337711045.033 [CBIT](DEBUG): Construct CBIT Built In Test.
2012-05-22T18:24:05.135Z,1337711045.135 [CBIT] Loaded
2012-05-22T18:24:05.135Z,1337711045.135 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2012-05-22T18:24:05.135Z,1337711045.135 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2012-05-22T18:24:05.136Z,1337711045.136 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2012-05-22T18:24:05.261Z,1337711045.261 [BuoyancyServo] Loaded
2012-05-22T18:24:05.261Z,1337711045.261 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2012-05-22T18:24:05.267Z,1337711045.267 [ElevatorServo] Loaded
2012-05-22T18:24:05.268Z,1337711045.268 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2012-05-22T18:24:05.274Z,1337711045.274 [MassServo] Loaded
2012-05-22T18:24:05.274Z,1337711045.274 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2012-05-22T18:24:05.280Z,1337711045.280 [RudderServo] Loaded
2012-05-22T18:24:05.281Z,1337711045.281 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2012-05-22T18:24:05.287Z,1337711045.287 [ThrusterServo] Loaded
2012-05-22T18:24:05.287Z,1337711045.287 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2012-05-22T18:24:05.288Z,1337711045.288 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2012-05-22T18:24:05.288Z,1337711045.288 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2012-05-22T18:24:05.303Z,1337711045.303 [DepthRateCalculator] Loaded
2012-05-22T18:24:05.303Z,1337711045.303 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2012-05-22T18:24:05.318Z,1337711045.318 [NavChart] Loaded
2012-05-22T18:24:05.318Z,1337711045.318 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2012-05-22T18:24:05.324Z,1337711045.324 [PitchRateCalculator] Loaded
2012-05-22T18:24:05.324Z,1337711045.324 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2012-05-22T18:24:05.330Z,1337711045.330 [SpeedCalculator] Loaded
2012-05-22T18:24:05.330Z,1337711045.330 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2012-05-22T18:24:05.344Z,1337711045.344 [TempGradientCalculator] Loaded
2012-05-22T18:24:05.344Z,1337711045.344 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2012-05-22T18:24:05.349Z,1337711045.349 [YawRateCalculator] Loaded
2012-05-22T18:24:05.350Z,1337711045.349 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2012-05-22T18:24:05.378Z,1337711045.378 [Navigation] Loaded
2012-05-22T18:24:05.378Z,1337711045.378 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread.
2012-05-22T18:24:05.379Z,1337711045.379 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2012-05-22T18:24:05.379Z,1337711045.379 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2012-05-22T18:24:05.578Z,1337711045.578 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2012-05-22T18:24:05.579Z,1337711045.579 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2012-05-22T18:24:05.599Z,1337711045.599 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2012-05-22T18:24:05.600Z,1337711045.600 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2012-05-22T18:24:05.636Z,1337711045.636 [VerticalControl](DEBUG): Construct VerticalControl.
2012-05-22T18:24:05.677Z,1337711045.677 [VerticalControl] Loaded
2012-05-22T18:24:05.678Z,1337711045.678 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2012-05-22T18:24:05.678Z,1337711045.678 [HorizontalControl](DEBUG): Construct HorizontalControl.
2012-05-22T18:24:05.697Z,1337711045.697 [HorizontalControl] Loaded
2012-05-22T18:24:05.697Z,1337711045.697 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2012-05-22T18:24:05.698Z,1337711045.698 [SpeedControl](DEBUG): Construct SpeedControl.
2012-05-22T18:24:05.700Z,1337711045.700 [SpeedControl] Loaded
2012-05-22T18:24:05.700Z,1337711045.700 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2012-05-22T18:24:05.701Z,1337711045.701 [LoopControl](DEBUG): Construct LoopControl.
2012-05-22T18:24:05.702Z,1337711045.702 [LoopControl] Loaded
2012-05-22T18:24:05.702Z,1337711045.702 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2012-05-22T18:24:05.702Z,1337711045.702 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2012-05-22T18:24:05.703Z,1337711045.703 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2012-05-22T18:24:05.708Z,1337711045.708 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator.
2012-05-22T18:24:05.712Z,1337711045.712 [AsyncPiEstimator] Loaded
2012-05-22T18:24:05.713Z,1337711045.713 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread.
2012-05-22T18:24:05.714Z,1337711045.714 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 1078994144
2012-05-22T18:24:05.715Z,1337711045.714 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2012-05-22T18:24:05.715Z,1337711045.715 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2012-05-22T18:24:05.803Z,1337711045.803 [AHRS_sp3003D] Loaded
2012-05-22T18:24:05.804Z,1337711045.804 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2012-05-22T18:24:06.038Z,1337711046.038 [Batt_Ocean_Server] Loaded
2012-05-22T18:24:06.038Z,1337711046.038 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2012-05-22T18:24:06.050Z,1337711046.050 [Depth_Keller] Loaded
2012-05-22T18:24:06.050Z,1337711046.050 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2012-05-22T18:24:06.055Z,1337711046.055 [DropWeight] Loaded
2012-05-22T18:24:06.056Z,1337711046.056 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2012-05-22T18:24:06.144Z,1337711046.144 [DVL_micro] Loaded
2012-05-22T18:24:06.145Z,1337711046.145 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2012-05-22T18:24:06.219Z,1337711046.219 [NAL9601] Loaded
2012-05-22T18:24:06.219Z,1337711046.219 [ComponentRegistry](DEBUG): SyncComponent "NAL9601" handled in the control thread.
2012-05-22T18:24:06.265Z,1337711046.265 [Onboard] Loaded
2012-05-22T18:24:06.265Z,1337711046.265 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2012-05-22T18:24:06.271Z,1337711046.271 [Radio_Freewave] Loaded
2012-05-22T18:24:06.271Z,1337711046.271 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread.
2012-05-22T18:24:06.272Z,1337711046.272 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2012-05-22T18:24:06.272Z,1337711046.272 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2012-05-22T18:24:06.315Z,1337711046.315 [CTD_NeilBrown] Loaded
2012-05-22T18:24:06.315Z,1337711046.315 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2012-05-22T18:24:06.317Z,1337711046.316 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 1079645408
2012-05-22T18:24:06.345Z,1337711046.345 [WetLabsBB2FL] Loaded
2012-05-22T18:24:06.345Z,1337711046.345 [ComponentRegistry](DEBUG): SyncComponent "WetLabsBB2FL" handled in the control thread.
2012-05-22T18:24:06.345Z,1337711046.345 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2012-05-22T18:24:06.348Z,1337711046.348 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2012-05-22T18:24:06.349Z,1337711046.349 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2012-05-22T18:24:06.354Z,1337711046.354 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2012-05-22T18:24:06.355Z,1337711046.355 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 1079842016
2012-05-22T18:24:06.355Z,1337711046.355 [Supervisor](DEBUG): Running supervisor.
2012-05-22T18:24:06.358Z,1337711046.358 [controlThread](DEBUG): Initializing ControlThread
2012-05-22T18:24:06.359Z,1337711046.359 [InternalSim](DEBUG):  InternalSim initializing...
2012-05-22T18:24:06.393Z,1337711046.393 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator.
2012-05-22T18:24:06.401Z,1337711046.401 [SBIT](INFO): Initialize SBIT Component.
2012-05-22T18:24:06.403Z,1337711046.403 [SBIT](IMPORTANT): Tethys CM Info:
$Rev: 9636 $
2012-05-22T18:24:06.403Z,1337711046.403 [IBIT](INFO): Initialize IBIT Component.
2012-05-22T18:24:06.406Z,1337711046.406 [CBIT](DEBUG): Initialize CBIT Component.
2012-05-22T18:24:06.406Z,1337711046.406 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2012-05-22T18:24:06.408Z,1337711046.408 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2012-05-22T18:24:06.436Z,1337711046.436 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2012-05-22T18:24:06.436Z,1337711046.436 [NavChart](DEBUG): Initialize NavChart Derivation.
2012-05-22T18:24:06.437Z,1337711046.437 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2012-05-22T18:24:06.437Z,1337711046.437 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2012-05-22T18:24:06.438Z,1337711046.438 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2012-05-22T18:24:06.439Z,1337711046.439 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2012-05-22T18:24:06.439Z,1337711046.439 [Navigation](DEBUG): Initializing Navigation.
2012-05-22T18:24:06.440Z,1337711046.440 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2012-05-22T18:24:06.442Z,1337711046.442 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2012-05-22T18:24:06.442Z,1337711046.442 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2012-05-22T18:24:06.443Z,1337711046.443 [LoopControl](DEBUG): Initialize LoopControlComponent.
2012-05-22T18:24:06.516Z,1337711046.516 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2012-05-22T18:24:06.521Z,1337711046.521 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2012-05-22T18:24:06.525Z,1337711046.525 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2012-05-22T18:24:06.529Z,1337711046.529 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2012-05-22T18:24:06.533Z,1337711046.533 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2012-05-22T18:24:06.534Z,1337711046.534 [NavChartDb](INFO): Creating index for Soundings
2012-05-22T18:24:06.537Z,1337711046.537 [NavChartDb](INFO): Creating index for Contour 0p0
2012-05-22T18:24:06.539Z,1337711046.539 [NavChartDb](INFO): Creating index for Contour 1p8
2012-05-22T18:24:06.541Z,1337711046.541 [NavChartDb](INFO): Creating index for Contour 3p6
2012-05-22T18:24:06.544Z,1337711046.543 [NavChartDb](INFO): Creating index for Contour 5p4
2012-05-22T18:24:06.545Z,1337711046.545 [NavChartDb](INFO): Creating index for Contour 9p1
2012-05-22T18:24:06.547Z,1337711046.547 [NavChartDb](INFO): Creating index for Contour 10p9
2012-05-22T18:24:06.549Z,1337711046.549 [NavChartDb](INFO): Creating index for Contour 18p2
2012-05-22T18:24:06.551Z,1337711046.551 [NavChartDb](INFO): Creating index for Contour 36p5
2012-05-22T18:24:06.553Z,1337711046.553 [NavChartDb](INFO): Creating index for Contour 54p8
2012-05-22T18:24:06.555Z,1337711046.555 [NavChartDb](INFO): Creating index for Contour 73p1
2012-05-22T18:24:06.557Z,1337711046.557 [NavChartDb](INFO): Creating index for Contour 91p4
2012-05-22T18:24:06.559Z,1337711046.559 [NavChartDb](INFO): Creating index for Contour 182p8
2012-05-22T18:24:06.561Z,1337711046.561 [NavChartDb](INFO): Creating index for Contour 365p7
2012-05-22T18:24:06.563Z,1337711046.563 [NavChartDb](INFO): Creating index for Contour 548p6
2012-05-22T18:24:06.565Z,1337711046.565 [NavChartDb](INFO): Creating index for Contour 731p5
2012-05-22T18:24:06.567Z,1337711046.567 [NavChartDb](INFO): Creating index for Contour 914p4
2012-05-22T18:24:06.569Z,1337711046.569 [NavChartDb](INFO): Creating index for Contour 1097p2
2012-05-22T18:24:06.571Z,1337711046.571 [NavChartDb](INFO): Creating index for Contour 1280p1
2012-05-22T18:24:06.573Z,1337711046.573 [NavChartDb](INFO): Creating index for Contour 1463p0
2012-05-22T18:24:06.575Z,1337711046.575 [NavChartDb](INFO): Creating index for Contour 1645p9
2012-05-22T18:24:06.577Z,1337711046.577 [NavChartDb](INFO): Creating index for Contour 1828p8
2012-05-22T18:24:06.579Z,1337711046.579 [NavChartDb](INFO): Creating index for Contour 2011p6
2012-05-22T18:24:06.581Z,1337711046.581 [NavChartDb](INFO): Creating index for Contour 2194p5
2012-05-22T18:24:06.583Z,1337711046.583 [NavChartDb](INFO): Creating index for Contour 2377p4
2012-05-22T18:24:06.585Z,1337711046.585 [NavChartDb](INFO): Creating index for Contour 2560p3
2012-05-22T18:24:06.586Z,1337711046.586 [NavChartDb](INFO): Creating index for Contour 2743p2
2012-05-22T18:24:06.588Z,1337711046.588 [NavChartDb](INFO): Creating index for Contour 2926p0
2012-05-22T18:24:06.590Z,1337711046.590 [NavChartDb](INFO): Creating index for Contour 3108p9
2012-05-22T18:24:06.592Z,1337711046.592 [NavChartDb](INFO): Creating index for Contour 3291p8
2012-05-22T18:24:06.594Z,1337711046.594 [NavChartDb](INFO): Creating index for Contour 3474p7
2012-05-22T18:24:06.596Z,1337711046.596 [NavChartDb](INFO): Creating index for Contour 3657p6
2012-05-22T18:24:08.087Z,1337711048.087 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2012-05-22T18:24:08.092Z,1337711048.092 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2012-05-22T18:24:08.102Z,1337711048.102 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2012-05-22T18:24:08.111Z,1337711048.111 [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-05-22T18:24:08.112Z,1337711048.112 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2012-05-22T18:24:08.139Z,1337711048.139 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2012-05-22T18:24:08.141Z,1337711048.141 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2012-05-22T18:24:08.144Z,1337711048.144 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2012-05-22T18:24:08.151Z,1337711048.151 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2012-05-22T18:24:08.155Z,1337711048.155 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2012-05-22T18:24:08.161Z,1337711048.161 [Default:Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2012-05-22T18:24:08.170Z,1337711048.170 [Default:D.SetSpeed](DEBUG): Construct.
2012-05-22T18:24:08.173Z,1337711048.173 [Default:E.GoToSurface](DEBUG): Construct GoToSurface.
2012-05-22T18:24:08.177Z,1337711048.177 [Default:F.Wait](DEBUG): Construct Wait.
2012-05-22T18:24:08.181Z,1337711048.181 [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-05-22T18:24:08.185Z,1337711048.185 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,DVL_micro,NAL9601,Onboard,Radio_Freewave,WetLabsBB2FL,Depth_Keller,DepthRateCalculator,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,logger,
2012-05-22T18:24:08.204Z,1337711048.204 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2012-05-22T18:24:08.313Z,1337711048.313 [DVL_micro](DEBUG): Initializing DVL_micro.
2012-05-22T18:24:08.333Z,1337711048.333 [Radio_Freewave](INFO): Powering up
2012-05-22T18:24:08.339Z,1337711048.339 [WetLabsBB2FL](INFO): Powering down
2012-05-22T18:24:08.408Z,1337711048.408 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2012-05-22T18:24:08.409Z,1337711048.409 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2012-05-22T18:24:08.418Z,1337711048.418 [ElevatorServo](DEBUG): Initializing EZServoServo.
2012-05-22T18:24:08.419Z,1337711048.419 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2012-05-22T18:24:08.426Z,1337711048.426 [MassServo](DEBUG): Initializing EZServoServo.
2012-05-22T18:24:08.427Z,1337711048.427 [MassServo](DEBUG): Initializing MassServo.
2012-05-22T18:24:08.436Z,1337711048.436 [RudderServo](DEBUG): Initializing EZServoServo.
2012-05-22T18:24:08.437Z,1337711048.437 [RudderServo](DEBUG): Initializing RudderServo.
2012-05-22T18:24:08.444Z,1337711048.444 [ThrusterServo](DEBUG): Initializing EZServoServo.
2012-05-22T18:24:08.445Z,1337711048.445 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2012-05-22T18:24:11.458Z,1337711051.458 [NAL9601](INFO): Powering up NAL9601
2012-05-22T18:24:21.874Z,1337711061.874 [SBIT](IMPORTANT): Beginning Startup BIT
2012-05-22T18:24:21.876Z,1337711061.876 [CBIT](IMPORTANT): Beginning GF scan
2012-05-22T18:24:32.266Z,1337711072.266 [SBIT](FAULT): Elevator: EXPECTED:15.000000 ACTUAL:14.936239
2012-05-22T18:24:48.116Z,1337711088.116 [CBIT](IMPORTANT): No ground fault detected
2012-05-22T18:25:04.099Z,1337711104.099 [SBIT](CRITICAL): SBIT FAILED
2012-05-22T18:25:04.431Z,1337711104.431 [MissionManager](IMPORTANT): Started mission Startup
2012-05-22T18:25:04.431Z,1337711104.431 [Startup] Running Loop=1
2012-05-22T18:25:04.431Z,1337711104.431 [Startup](INFO): Aggregate::initialize Startup
2012-05-22T18:25:04.431Z,1337711104.431 [Startup:A.GoToSurface] Running Loop=1
2012-05-22T18:25:04.432Z,1337711104.432 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-05-22T18:25:04.438Z,1337711104.438 [Startup:StartupSatComms] Running Loop=1
2012-05-22T18:25:04.438Z,1337711104.438 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2012-05-22T18:25:04.439Z,1337711104.439 [Startup:StartupSatComms:A] Running Loop=1
2012-05-22T18:25:04.828Z,1337711104.828 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2012-05-22T18:25:17.327Z,1337711117.327 [NAL9601](INFO): NAL9601 initialized
2012-05-22T18:26:04.646Z,1337711164.646 [Startup:StartupSatComms:A](INFO): Timed out from 2012-05-22T18:25:04.4Z
2012-05-22T18:26:04.646Z,1337711164.646 [Startup:StartupSatComms:A_Timeout] Running Loop=1
2012-05-22T18:26:04.646Z,1337711164.646 [Startup:StartupSatComms:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:A_Timeout
2012-05-22T18:26:04.646Z,1337711164.646 [Startup:StartupSatComms:A_Timeout](INFO): Completed Startup:StartupSatComms:A_Timeout
2012-05-22T18:26:04.646Z,1337711164.647 [Startup:StartupSatComms:A] Stopped
2012-05-22T18:26:04.647Z,1337711164.647 [Startup:StartupSatComms:B] Running Loop=1
2012-05-22T18:26:05.080Z,1337711165.080 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2012-05-22T18:26:32.516Z,1337711192.516 [NAL9601](INFO): SBD MO Status=1, MOMSN=6721, MT Status=0, MTMSN=0
2012-05-22T18:26:32.695Z,1337711192.695 [NAL9601](INFO): Sent 302 bytes from file Logs/20120515T215853/shore0000.lzma
2012-05-22T18:26:32.695Z,1337711192.695 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:26:32.696Z,1337711192.696 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000000
2012-05-22T18:26:45.840Z,1337711205.840 [NAL9601](INFO): SBD MO Status=2, MOMSN=6722, MT Status=2, MTMSN=0
2012-05-22T18:26:45.840Z,1337711205.840 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:27:04.958Z,1337711224.958 [Startup:StartupSatComms:B](INFO): Timed out from 2012-05-22T18:26:04.6Z
2012-05-22T18:27:04.959Z,1337711224.958 [Startup:StartupSatComms:A_Timeout] Running Loop=1
2012-05-22T18:27:04.959Z,1337711224.959 [Startup:StartupSatComms:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:A_Timeout
2012-05-22T18:27:04.959Z,1337711224.959 [Startup:StartupSatComms:A_Timeout](INFO): Completed Startup:StartupSatComms:A_Timeout
2012-05-22T18:27:04.959Z,1337711224.959 [Startup:StartupSatComms:B] Stopped
2012-05-22T18:27:04.959Z,1337711224.959 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2012-05-22T18:27:04.959Z,1337711224.959 [Startup:StartupSatComms] Stopped
2012-05-22T18:27:04.959Z,1337711224.959 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2012-05-22T18:27:04.960Z,1337711224.960 [Startup](INFO): Completed Startup
2012-05-22T18:27:04.960Z,1337711224.960 [Startup] Stopped
2012-05-22T18:27:04.960Z,1337711224.960 [Startup](INFO): Aggregate::uninitialize Startup
2012-05-22T18:27:04.960Z,1337711224.960 [Startup:A.GoToSurface] Stopped
2012-05-22T18:27:04.961Z,1337711224.961 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-05-22T18:27:05.141Z,1337711225.141 [MissionManager](IMPORTANT): Started mission Default
2012-05-22T18:27:05.141Z,1337711225.141 [Default] Running Loop=1
2012-05-22T18:27:05.141Z,1337711225.141 [Default](INFO): Aggregate::initialize Default
2012-05-22T18:27:05.141Z,1337711225.141 [Default:D.SetSpeed] Running Loop=1
2012-05-22T18:27:05.141Z,1337711225.141 [Default:D.SetSpeed](DEBUG): Initialize.
2012-05-22T18:27:05.141Z,1337711225.141 [Default:E.GoToSurface] Running Loop=1
2012-05-22T18:27:05.141Z,1337711225.141 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-05-22T18:27:05.142Z,1337711225.142 [Default:Iridium] Running Loop=1
2012-05-22T18:27:05.142Z,1337711225.142 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2012-05-22T18:27:05.142Z,1337711225.142 [Default:Iridium:A.SetSpeed] Running Loop=1
2012-05-22T18:27:05.142Z,1337711225.142 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2012-05-22T18:27:05.142Z,1337711225.142 [Default:Iridium:B.GoToSurface] Running Loop=1
2012-05-22T18:27:05.142Z,1337711225.142 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-05-22T18:27:05.143Z,1337711225.143 [Default:E.GoToSurface] Running Loop=1
2012-05-22T18:27:05.148Z,1337711225.148 [Default:D.SetSpeed] Running Loop=1
2012-05-22T18:27:05.153Z,1337711225.153 [Default:CallIridium] Running Loop=1
2012-05-22T18:27:05.153Z,1337711225.153 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2012-05-22T18:27:05.153Z,1337711225.153 [Default:CallIridium:A] Running Loop=1
2012-05-22T18:27:05.155Z,1337711225.155 [Default:CallIridium:A] Stopped
2012-05-22T18:27:05.155Z,1337711225.155 [Default:CallIridium:B] Running Loop=1
2012-05-22T18:27:05.155Z,1337711225.155 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2012-05-22T18:27:05.161Z,1337711225.161 [Default:Iridium:B.GoToSurface] Stopped
2012-05-22T18:27:05.161Z,1337711225.161 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-05-22T18:27:05.161Z,1337711225.161 [Default:Iridium:Read_Iridium] Running Loop=1
2012-05-22T18:27:05.161Z,1337711225.161 [Default:Iridium:A.SetSpeed] Running Loop=1
2012-05-22T18:27:05.165Z,1337711225.165 [Default:GPS] Running Loop=1
2012-05-22T18:27:05.166Z,1337711225.165 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2012-05-22T18:27:05.166Z,1337711225.166 [Default:GPS:A.SetSpeed] Running Loop=1
2012-05-22T18:27:05.166Z,1337711225.166 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2012-05-22T18:27:05.166Z,1337711225.166 [Default:GPS:B.GoToSurface] Running Loop=1
2012-05-22T18:27:05.166Z,1337711225.166 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-05-22T18:27:05.171Z,1337711225.171 [Default:GPS:B.GoToSurface] Stopped
2012-05-22T18:27:05.171Z,1337711225.171 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-05-22T18:27:05.172Z,1337711225.172 [Default:GPS:Read_GPS] Running Loop=1
2012-05-22T18:27:05.172Z,1337711225.172 [Default:GPS:A.SetSpeed] Running Loop=1
2012-05-22T18:27:07.523Z,1337711227.523 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2012-05-22T18:27:07.526Z,1337711227.526 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2012-05-22T18:27:17.602Z,1337711237.602 [NAL9601](INFO): SBD MO Status=1, MOMSN=6722, MT Status=0, MTMSN=0
2012-05-22T18:27:17.731Z,1337711237.731 [NAL9601](INFO): Sent 332 bytes from file Logs/20120521T231942/shore0000.lzma
2012-05-22T18:27:17.731Z,1337711237.731 [NAL9601](INFO): Packets left to send: 1
2012-05-22T18:27:17.732Z,1337711237.732 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000001
2012-05-22T18:27:39.497Z,1337711259.497 [NAL9601](INFO): SBD MO Status=2, MOMSN=6723, MT Status=2, MTMSN=0
2012-05-22T18:27:39.497Z,1337711259.497 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:28:02.185Z,1337711282.185 [NAL9601](INFO): SBD MO Status=2, MOMSN=6723, MT Status=2, MTMSN=0
2012-05-22T18:28:02.186Z,1337711282.186 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:28:40.006Z,1337711320.006 [NAL9601](INFO): SBD MO Status=1, MOMSN=6723, MT Status=0, MTMSN=0
2012-05-22T18:28:40.199Z,1337711320.199 [NAL9601](INFO): Sent 110 bytes from file Logs/20120521T231942/shore0000.lzma
2012-05-22T18:28:40.199Z,1337711320.199 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:28:40.200Z,1337711320.200 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000002
2012-05-22T18:28:54.128Z,1337711334.128 [NAL9601](INFO): SBD MO Status=2, MOMSN=6724, MT Status=2, MTMSN=0
2012-05-22T18:28:54.128Z,1337711334.128 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:29:40.539Z,1337711380.539 [NAL9601](INFO): SBD MO Status=2, MOMSN=6724, MT Status=0, MTMSN=0
2012-05-22T18:29:40.539Z,1337711380.539 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:30:35.746Z,1337711435.746 [NAL9601](INFO): SBD MO Status=2, MOMSN=6724, MT Status=2, MTMSN=0
2012-05-22T18:30:35.746Z,1337711435.746 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:30:53.210Z,1337711453.210 [NAL9601](INFO): SBD MO Status=2, MOMSN=6724, MT Status=2, MTMSN=0
2012-05-22T18:30:53.210Z,1337711453.210 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:30:54.416Z,1337711454.416 [NAL9601](IMPORTANT): GPS fix at: 1337713192.00
2012-05-22T18:30:54.430Z,1337711454.430 [Default:GPS:Read_GPS] Stopped
2012-05-22T18:30:54.430Z,1337711454.430 [Default:GPS:D] Running Loop=1
2012-05-22T18:30:54.865Z,1337711454.865 [Default:GPS:D] Stopped
2012-05-22T18:30:54.865Z,1337711454.865 [Default:GPS](INFO): Completed Default:GPS
2012-05-22T18:30:54.865Z,1337711454.865 [Default:GPS] Stopped
2012-05-22T18:30:54.865Z,1337711454.865 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2012-05-22T18:30:54.865Z,1337711454.865 [Default:GPS:A.SetSpeed] Stopped
2012-05-22T18:30:54.866Z,1337711454.866 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2012-05-22T18:31:13.282Z,1337711473.282 [NAL9601](INFO): SBD MO Status=2, MOMSN=6724, MT Status=2, MTMSN=0
2012-05-22T18:31:13.282Z,1337711473.282 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:31:59.097Z,1337711519.098 [NAL9601](INFO): SBD MO Status=1, MOMSN=6724, MT Status=0, MTMSN=0
2012-05-22T18:31:59.291Z,1337711519.291 [NAL9601](INFO): Sent 138 bytes from file Logs/20120521T231942/shore0001.lzma
2012-05-22T18:31:59.291Z,1337711519.291 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:31:59.505Z,1337711519.505 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000003
2012-05-22T18:32:09.444Z,1337711529.444 [NAL9601](INFO): SBD MO Status=2, MOMSN=6725, MT Status=2, MTMSN=0
2012-05-22T18:32:09.444Z,1337711529.444 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:32:43.817Z,1337711563.817 [NAL9601](INFO): SBD MO Status=2, MOMSN=6725, MT Status=2, MTMSN=0
2012-05-22T18:32:43.818Z,1337711563.818 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:33:17.834Z,1337711597.833 [NAL9601](INFO): SBD MO Status=2, MOMSN=6725, MT Status=2, MTMSN=0
2012-05-22T18:33:17.834Z,1337711597.834 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:33:43.438Z,1337711623.438 [NAL9601](INFO): SBD MO Status=2, MOMSN=6725, MT Status=2, MTMSN=0
2012-05-22T18:33:43.438Z,1337711623.438 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:34:04.924Z,1337711644.924 [NAL9601](INFO): SBD MO Status=2, MOMSN=6725, MT Status=2, MTMSN=0
2012-05-22T18:34:04.925Z,1337711644.925 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:34:27.642Z,1337711667.642 [NAL9601](INFO): SBD MO Status=2, MOMSN=6725, MT Status=2, MTMSN=0
2012-05-22T18:34:27.642Z,1337711667.642 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:35:02.317Z,1337711702.318 [NAL9601](INFO): SBD MO Status=1, MOMSN=6725, MT Status=0, MTMSN=0
2012-05-22T18:35:02.507Z,1337711702.507 [NAL9601](INFO): Sent 332 bytes from file Logs/20120522T135221/shore0000.lzma
2012-05-22T18:35:02.507Z,1337711702.507 [NAL9601](INFO): Packets left to send: 1
2012-05-22T18:35:02.508Z,1337711702.508 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000004
2012-05-22T18:35:13.629Z,1337711713.629 [NAL9601](INFO): SBD MO Status=1, MOMSN=6726, MT Status=0, MTMSN=0
2012-05-22T18:35:13.787Z,1337711713.787 [NAL9601](INFO): Sent 233 bytes from file Logs/20120522T135221/shore0000.lzma
2012-05-22T18:35:13.787Z,1337711713.787 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:35:14.017Z,1337711714.017 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000005
2012-05-22T18:35:21.305Z,1337711721.305 [NAL9601](INFO): SBD MO Status=1, MOMSN=6727, MT Status=0, MTMSN=0
2012-05-22T18:35:21.475Z,1337711721.475 [NAL9601](INFO): Sent 152 bytes from file Logs/20120522T135221/shore0001.lzma
2012-05-22T18:35:21.475Z,1337711721.475 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:35:21.476Z,1337711721.476 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000006
2012-05-22T18:35:33.400Z,1337711733.400 [NAL9601](INFO): SBD MO Status=1, MOMSN=6728, MT Status=0, MTMSN=0
2012-05-22T18:35:33.559Z,1337711733.559 [NAL9601](INFO): Sent 332 bytes from file Logs/20120522T135903/shore0000.lzma
2012-05-22T18:35:33.559Z,1337711733.559 [NAL9601](INFO): Packets left to send: 1
2012-05-22T18:35:33.560Z,1337711733.560 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000007
2012-05-22T18:35:43.949Z,1337711743.949 [NAL9601](INFO): SBD MO Status=1, MOMSN=6729, MT Status=0, MTMSN=0
2012-05-22T18:35:44.143Z,1337711744.143 [NAL9601](INFO): Sent 187 bytes from file Logs/20120522T135903/shore0000.lzma
2012-05-22T18:35:44.143Z,1337711744.143 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:35:44.144Z,1337711744.144 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000008
2012-05-22T18:35:55.333Z,1337711755.333 [NAL9601](INFO): SBD MO Status=2, MOMSN=6730, MT Status=2, MTMSN=0
2012-05-22T18:35:55.333Z,1337711755.333 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:36:24.356Z,1337711784.356 [NAL9601](INFO): SBD MO Status=2, MOMSN=6730, MT Status=2, MTMSN=0
2012-05-22T18:36:24.357Z,1337711784.357 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:36:52.481Z,1337711812.480 [NAL9601](INFO): SBD MO Status=2, MOMSN=6730, MT Status=2, MTMSN=0
2012-05-22T18:36:52.481Z,1337711812.481 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:37:29.706Z,1337711849.706 [NAL9601](INFO): SBD MO Status=2, MOMSN=6730, MT Status=2, MTMSN=0
2012-05-22T18:37:29.706Z,1337711849.706 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:38:23.580Z,1337711903.580 [NAL9601](INFO): SBD MO Status=2, MOMSN=6730, MT Status=0, MTMSN=0
2012-05-22T18:38:23.581Z,1337711903.581 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:39:08.612Z,1337711948.612 [NAL9601](INFO): SBD MO Status=2, MOMSN=6730, MT Status=2, MTMSN=0
2012-05-22T18:39:08.613Z,1337711948.612 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:39:50.117Z,1337711990.117 [NAL9601](INFO): SBD MO Status=1, MOMSN=6730, MT Status=0, MTMSN=0
2012-05-22T18:39:50.259Z,1337711990.259 [NAL9601](INFO): Sent 332 bytes from file Logs/20120522T135903/shore0001.lzma
2012-05-22T18:39:50.259Z,1337711990.259 [NAL9601](INFO): Packets left to send: 4
2012-05-22T18:39:50.260Z,1337711990.260 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000009
2012-05-22T18:40:09.443Z,1337712009.443 [NAL9601](INFO): SBD MO Status=1, MOMSN=6731, MT Status=0, MTMSN=0
2012-05-22T18:40:09.631Z,1337712009.631 [NAL9601](INFO): Sent 332 bytes from file Logs/20120522T135903/shore0001.lzma
2012-05-22T18:40:09.631Z,1337712009.631 [NAL9601](INFO): Packets left to send: 3
2012-05-22T18:40:09.632Z,1337712009.632 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000010
2012-05-22T18:40:27.100Z,1337712027.100 [NAL9601](INFO): SBD MO Status=2, MOMSN=6732, MT Status=2, MTMSN=0
2012-05-22T18:40:27.100Z,1337712027.100 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:40:52.038Z,1337712052.038 [NAL9601](INFO): SBD MO Status=2, MOMSN=6732, MT Status=2, MTMSN=0
2012-05-22T18:40:52.038Z,1337712052.038 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:41:28.157Z,1337712088.158 [NAL9601](INFO): SBD MO Status=2, MOMSN=6732, MT Status=2, MTMSN=0
2012-05-22T18:41:28.158Z,1337712088.158 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:42:02.062Z,1337712122.062 [NAL9601](INFO): SBD MO Status=1, MOMSN=6732, MT Status=0, MTMSN=0
2012-05-22T18:42:02.255Z,1337712122.255 [NAL9601](INFO): Sent 332 bytes from file Logs/20120522T135903/shore0001.lzma
2012-05-22T18:42:02.255Z,1337712122.255 [NAL9601](INFO): Packets left to send: 2
2012-05-22T18:42:02.256Z,1337712122.256 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000011
2012-05-22T18:42:17.410Z,1337712137.409 [NAL9601](INFO): SBD MO Status=2, MOMSN=6733, MT Status=2, MTMSN=0
2012-05-22T18:42:17.410Z,1337712137.410 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:42:55.807Z,1337712175.807 [NAL9601](INFO): SBD MO Status=1, MOMSN=6733, MT Status=0, MTMSN=0
2012-05-22T18:42:55.971Z,1337712175.971 [NAL9601](INFO): Sent 332 bytes from file Logs/20120522T135903/shore0001.lzma
2012-05-22T18:42:55.971Z,1337712175.971 [NAL9601](INFO): Packets left to send: 1
2012-05-22T18:42:55.972Z,1337712175.972 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000012
2012-05-22T18:43:08.313Z,1337712188.313 [NAL9601](INFO): SBD MO Status=2, MOMSN=6734, MT Status=2, MTMSN=0
2012-05-22T18:43:08.313Z,1337712188.313 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:44:09.218Z,1337712249.218 [NAL9601](INFO): SBD MO Status=1, MOMSN=6734, MT Status=0, MTMSN=0
2012-05-22T18:44:09.359Z,1337712249.359 [NAL9601](INFO): Sent 274 bytes from file Logs/20120522T135903/shore0001.lzma
2012-05-22T18:44:09.359Z,1337712249.359 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:44:09.360Z,1337712249.360 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000013
2012-05-22T18:44:25.317Z,1337712265.317 [NAL9601](INFO): SBD MO Status=1, MOMSN=6735, MT Status=0, MTMSN=0
2012-05-22T18:44:25.531Z,1337712265.531 [NAL9601](INFO): Sent 332 bytes from file Logs/20120522T143248/shore0000.lzma
2012-05-22T18:44:25.531Z,1337712265.531 [NAL9601](INFO): Packets left to send: 1
2012-05-22T18:44:25.532Z,1337712265.532 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000014
2012-05-22T18:44:37.009Z,1337712277.009 [NAL9601](INFO): SBD MO Status=1, MOMSN=6736, MT Status=0, MTMSN=0
2012-05-22T18:44:37.215Z,1337712277.215 [NAL9601](INFO): Sent 68 bytes from file Logs/20120522T143248/shore0000.lzma
2012-05-22T18:44:37.215Z,1337712277.215 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:44:37.263Z,1337712277.263 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000015
2012-05-22T18:44:53.137Z,1337712293.137 [NAL9601](INFO): SBD MO Status=2, MOMSN=6737, MT Status=2, MTMSN=0
2012-05-22T18:44:53.137Z,1337712293.137 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:45:09.446Z,1337712309.446 [NAL9601](INFO): SBD MO Status=2, MOMSN=6737, MT Status=2, MTMSN=0
2012-05-22T18:45:09.446Z,1337712309.446 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:45:40.116Z,1337712340.116 [NAL9601](INFO): SBD MO Status=2, MOMSN=6737, MT Status=2, MTMSN=0
2012-05-22T18:45:40.116Z,1337712340.116 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:46:12.562Z,1337712372.562 [NAL9601](INFO): SBD MO Status=2, MOMSN=6737, MT Status=2, MTMSN=0
2012-05-22T18:46:12.562Z,1337712372.562 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:46:51.722Z,1337712411.722 [NAL9601](INFO): SBD MO Status=2, MOMSN=6737, MT Status=2, MTMSN=0
2012-05-22T18:46:51.722Z,1337712411.722 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:47:54.929Z,1337712474.929 [NAL9601](INFO): SBD MO Status=2, MOMSN=6737, MT Status=2, MTMSN=0
2012-05-22T18:47:54.929Z,1337712474.930 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:49:25.685Z,1337712565.685 [NAL9601](INFO): SBD MO Status=2, MOMSN=6737, MT Status=2, MTMSN=0
2012-05-22T18:49:25.686Z,1337712565.685 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:51:38.598Z,1337712698.598 [NAL9601](INFO): SBD MO Status=2, MOMSN=6737, MT Status=2, MTMSN=0
2012-05-22T18:51:38.598Z,1337712698.598 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:52:13.945Z,1337712733.945 [NAL9601](INFO): SBD MO Status=1, MOMSN=6737, MT Status=0, MTMSN=0
2012-05-22T18:52:14.107Z,1337712734.107 [NAL9601](INFO): Sent 332 bytes from file Logs/20120522T143248/shore0001.lzma
2012-05-22T18:52:14.107Z,1337712734.107 [NAL9601](INFO): Packets left to send: 1
2012-05-22T18:52:14.108Z,1337712734.108 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000016
2012-05-22T18:52:28.828Z,1337712748.828 [NAL9601](INFO): SBD MO Status=2, MOMSN=6738, MT Status=2, MTMSN=0
2012-05-22T18:52:28.828Z,1337712748.828 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:52:50.821Z,1337712770.821 [NAL9601](INFO): SBD MO Status=2, MOMSN=6738, MT Status=2, MTMSN=0
2012-05-22T18:52:50.822Z,1337712770.822 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:53:30.774Z,1337712810.774 [NAL9601](INFO): SBD MO Status=1, MOMSN=6738, MT Status=0, MTMSN=0
2012-05-22T18:53:30.987Z,1337712810.987 [NAL9601](INFO): Sent 290 bytes from file Logs/20120522T143248/shore0001.lzma
2012-05-22T18:53:30.987Z,1337712810.987 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:53:30.988Z,1337712810.988 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000017
2012-05-22T18:53:44.058Z,1337712824.057 [NAL9601](INFO): SBD MO Status=1, MOMSN=6739, MT Status=0, MTMSN=0
2012-05-22T18:53:44.279Z,1337712824.279 [NAL9601](INFO): Sent 332 bytes from file Logs/20120522T153836/shore0000.lzma
2012-05-22T18:53:44.279Z,1337712824.279 [NAL9601](INFO): Packets left to send: 1
2012-05-22T18:53:44.280Z,1337712824.280 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000018
2012-05-22T18:54:13.007Z,1337712853.007 [NAL9601](INFO): SBD MO Status=1, MOMSN=6740, MT Status=0, MTMSN=0
2012-05-22T18:54:13.219Z,1337712853.219 [NAL9601](INFO): Sent 73 bytes from file Logs/20120522T153836/shore0000.lzma
2012-05-22T18:54:13.219Z,1337712853.219 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:54:13.220Z,1337712853.220 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000019
2012-05-22T18:54:25.485Z,1337712865.485 [NAL9601](INFO): SBD MO Status=1, MOMSN=6741, MT Status=0, MTMSN=0
2012-05-22T18:54:25.703Z,1337712865.703 [NAL9601](INFO): Sent 332 bytes from file Logs/20120522T153836/shore0001.lzma
2012-05-22T18:54:25.703Z,1337712865.703 [NAL9601](INFO): Packets left to send: 2
2012-05-22T18:54:25.704Z,1337712865.704 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000020
2012-05-22T18:54:43.633Z,1337712883.633 [NAL9601](INFO): SBD MO Status=1, MOMSN=6742, MT Status=0, MTMSN=0
2012-05-22T18:54:43.779Z,1337712883.779 [NAL9601](INFO): Sent 332 bytes from file Logs/20120522T153836/shore0001.lzma
2012-05-22T18:54:43.779Z,1337712883.779 [NAL9601](INFO): Packets left to send: 1
2012-05-22T18:54:43.780Z,1337712883.780 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000021
2012-05-22T18:55:15.265Z,1337712915.265 [NAL9601](INFO): SBD MO Status=2, MOMSN=6743, MT Status=0, MTMSN=0
2012-05-22T18:55:15.266Z,1337712915.266 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:55:45.333Z,1337712945.332 [NAL9601](INFO): SBD MO Status=2, MOMSN=6743, MT Status=2, MTMSN=0
2012-05-22T18:55:45.333Z,1337712945.333 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:56:10.905Z,1337712970.905 [NAL9601](INFO): SBD MO Status=2, MOMSN=6743, MT Status=2, MTMSN=0
2012-05-22T18:56:10.905Z,1337712970.905 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:56:56.577Z,1337713016.577 [NAL9601](INFO): SBD MO Status=2, MOMSN=6743, MT Status=2, MTMSN=0
2012-05-22T18:56:56.577Z,1337713016.577 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:58:07.192Z,1337713087.192 [NAL9601](INFO): SBD MO Status=2, MOMSN=6743, MT Status=2, MTMSN=0
2012-05-22T18:58:07.192Z,1337713087.192 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:59:00.919Z,1337713140.919 [NAL9601](INFO): SBD MO Status=2, MOMSN=6743, MT Status=0, MTMSN=0
2012-05-22T18:59:00.919Z,1337713140.919 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:59:20.141Z,1337713160.141 [NAL9601](INFO): SBD MO Status=2, MOMSN=6743, MT Status=2, MTMSN=0
2012-05-22T18:59:20.141Z,1337713160.141 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:59:47.622Z,1337713187.622 [NAL9601](INFO): SBD MO Status=2, MOMSN=6743, MT Status=2, MTMSN=0
2012-05-22T18:59:47.622Z,1337713187.622 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T19:00:11.938Z,1337713211.938 [NAL9601](INFO): SBD MO Status=1, MOMSN=6743, MT Status=0, MTMSN=0
2012-05-22T19:00:12.063Z,1337713212.063 [NAL9601](INFO): Sent 236 bytes from file Logs/20120522T153836/shore0001.lzma
2012-05-22T19:00:12.063Z,1337713212.063 [NAL9601](INFO): Packets left to send: 0
2012-05-22T19:00:12.064Z,1337713212.064 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000022
2012-05-22T19:00:30.873Z,1337713230.873 [NAL9601](INFO): SBD MO Status=1, MOMSN=6744, MT Status=0, MTMSN=0
2012-05-22T19:00:31.035Z,1337713231.035 [NAL9601](INFO): Sent 332 bytes from file Logs/20120522T173338/shore0000.lzma
2012-05-22T19:00:31.035Z,1337713231.035 [NAL9601](INFO): Packets left to send: 1
2012-05-22T19:00:31.036Z,1337713231.036 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000023
2012-05-22T19:00:40.577Z,1337713240.577 [NAL9601](INFO): SBD MO Status=2, MOMSN=6745, MT Status=2, MTMSN=0
2012-05-22T19:00:40.577Z,1337713240.578 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T19:01:03.657Z,1337713263.657 [NAL9601](INFO): SBD MO Status=2, MOMSN=6745, MT Status=2, MTMSN=0
2012-05-22T19:01:03.658Z,1337713263.658 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T19:01:29.724Z,1337713289.724 [NAL9601](INFO): SBD MO Status=2, MOMSN=6745, MT Status=2, MTMSN=0
2012-05-22T19:01:29.725Z,1337713289.725 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T19:01:55.014Z,1337713315.013 [NAL9601](INFO): SBD MO Status=2, MOMSN=6745, MT Status=2, MTMSN=0
2012-05-22T19:01:55.014Z,1337713315.014 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T19:02:17.153Z,1337713337.153 [NAL9601](INFO): SBD MO Status=2, MOMSN=6745, MT Status=2, MTMSN=0
2012-05-22T19:02:17.154Z,1337713337.154 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T19:02:43.121Z,1337713363.121 [NAL9601](INFO): SBD MO Status=2, MOMSN=6745, MT Status=2, MTMSN=0
2012-05-22T19:02:43.122Z,1337713363.122 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T19:04:05.017Z,1337713445.017 [NAL9601](INFO): SBD MO Status=2, MOMSN=6745, MT Status=2, MTMSN=0
2012-05-22T19:04:05.018Z,1337713445.017 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T19:04:21.706Z,1337713461.706 [NAL9601](INFO): SBD MO Status=2, MOMSN=6745, MT Status=2, MTMSN=0
2012-05-22T19:04:21.706Z,1337713461.706 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T19:04:42.828Z,1337713482.828 [NAL9601](INFO): SBD MO Status=2, MOMSN=6745, MT Status=2, MTMSN=0
2012-05-22T19:04:42.828Z,1337713482.828 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T19:06:50.837Z,1337713610.837 [NAL9601](INFO): SBD MO Status=2, MOMSN=6745, MT Status=2, MTMSN=0
2012-05-22T19:06:50.838Z,1337713610.838 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T19:07:16.869Z,1337713636.869 [NAL9601](INFO): SBD MO Status=2, MOMSN=6745, MT Status=2, MTMSN=0
2012-05-22T19:07:16.870Z,1337713636.870 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T19:08:00.826Z,1337713680.826 [NAL9601](INFO): SBD MO Status=1, MOMSN=6745, MT Status=0, MTMSN=0
2012-05-22T19:08:01.035Z,1337713681.035 [NAL9601](INFO): Sent 184 bytes from file Logs/20120522T173338/shore0000.lzma
2012-05-22T19:08:01.035Z,1337713681.035 [NAL9601](INFO): Packets left to send: 0
2012-05-22T19:08:01.036Z,1337713681.036 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000024
2012-05-22T19:08:18.520Z,1337713698.520 [NAL9601](INFO): SBD MO Status=2, MOMSN=6746, MT Status=2, MTMSN=0
2012-05-22T19:08:18.521Z,1337713698.520 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T19:08:35.364Z,1337713715.364 [NAL9601](INFO): SBD MO Status=2, MOMSN=6746, MT Status=2, MTMSN=0
2012-05-22T19:08:35.364Z,1337713715.364 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T19:09:28.304Z,1337713768.304 [NAL9601](INFO): SBD MO Status=2, MOMSN=6746, MT Status=2, MTMSN=0
2012-05-22T19:09:28.304Z,1337713768.304 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T19:10:36.180Z,1337713836.180 [NAL9601](INFO): SBD MO Status=2, MOMSN=6746, MT Status=0, MTMSN=0
2012-05-22T19:10:36.180Z,1337713836.180 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T19:11:17.149Z,1337713877.149 [NAL9601](INFO): SBD MO Status=2, MOMSN=6746, MT Status=2, MTMSN=0
2012-05-22T19:11:17.149Z,1337713877.149 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T19:11:54.545Z,1337713914.545 [NAL9601](INFO): SBD MO Status=2, MOMSN=6746, MT Status=2, MTMSN=0
2012-05-22T19:11:54.546Z,1337713914.546 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T19:12:37.261Z,1337713957.261 [NAL9601](INFO): SBD MO Status=2, MOMSN=6746, MT Status=2, MTMSN=0
2012-05-22T19:12:37.262Z,1337713957.262 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T19:13:27.111Z,1337714007.111 [CommandLine](IMPORTANT): got command restart application
2012-05-22T19:13:27.175Z,1337714007.174 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2012-05-22T19:13:27.175Z,1337714007.175 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2012-05-22T19:13:27.458Z,1337714007.458 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2012-05-22T19:13:27.535Z,1337714007.535 [CTD_NeilBrown](INFO): Powering down
2012-05-22T19:13:27.535Z,1337714007.535 [ComponentRegistry](INFO): Shutting down AsyncPiEstimator ThreadHandler
2012-05-22T19:13:27.729Z,1337714007.729 [AsyncPiEstimator](DEBUG): Uninitialize AsyncPiEstimator.
2012-05-22T19:13:27.729Z,1337714007.729 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2012-05-22T19:13:27.729Z,1337714007.730 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2012-05-22T19:13:27.782Z,1337714007.782 [controlThread](DEBUG): Uninitializing ControlThread
2012-05-22T19:13:27.783Z,1337714007.783 [AHRS_sp3003D](INFO): Powering down
2012-05-22T19:13:27.872Z,1337714007.872 [DVL_micro](INFO): Powering down
2012-05-22T19:13:27.872Z,1337714007.872 [NAL9601](INFO): Powering down
2012-05-22T19:13:27.873Z,1337714007.873 [WetLabsBB2FL](INFO): Powering down
2012-05-22T19:13:27.873Z,1337714007.874 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2012-05-22T19:13:27.874Z,1337714007.874 [NavChart](DEBUG): Uninitialize NavChart Derivation.
2012-05-22T19:13:27.875Z,1337714007.875 [Default] Stopped
2012-05-22T19:13:27.875Z,1337714007.875 [Default](INFO): Aggregate::uninitialize Default
2012-05-22T19:13:27.875Z,1337714007.875 [Default:Iridium] Stopped
2012-05-22T19:13:27.875Z,1337714007.875 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2012-05-22T19:13:27.875Z,1337714007.875 [Default:Iridium:A.SetSpeed] Stopped
2012-05-22T19:13:27.876Z,1337714007.875 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2012-05-22T19:13:27.876Z,1337714007.875 [Default:Iridium:Read_Iridium] Stopped
2012-05-22T19:13:27.876Z,1337714007.876 [Default:CallIridium] Stopped
2012-05-22T19:13:27.876Z,1337714007.876 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2012-05-22T19:13:27.876Z,1337714007.876 [Default:CallIridium:B] Stopped
2012-05-22T19:13:27.876Z,1337714007.876 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2012-05-22T19:13:27.876Z,1337714007.876 [Default:D.SetSpeed] Stopped
2012-05-22T19:13:27.876Z,1337714007.876 [Default:D.SetSpeed](DEBUG): Uninitialize.
2012-05-22T19:13:27.876Z,1337714007.876 [Default:E.GoToSurface] Stopped
2012-05-22T19:13:27.876Z,1337714007.876 [Default:E.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-05-22T19:13:27.881Z,1337714007.881 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2012-05-22T19:13:27.881Z,1337714007.881 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2012-05-22T19:13:27.881Z,1337714007.881 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2012-05-22T19:13:27.881Z,1337714007.881 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2012-05-22T19:13:27.882Z,1337714007.882 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2012-05-22T19:13:27.882Z,1337714007.882 [BuoyancyServo](INFO): Powering down
2012-05-22T19:13:27.883Z,1337714007.883 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2012-05-22T19:13:27.883Z,1337714007.883 [ElevatorServo](INFO): Powering down
2012-05-22T19:13:27.883Z,1337714007.883 [MassServo](DEBUG): Uninitialize Mass Servo.
2012-05-22T19:13:27.883Z,1337714007.883 [MassServo](INFO): Powering down
2012-05-22T19:13:27.883Z,1337714007.884 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2012-05-22T19:13:27.884Z,1337714007.884 [RudderServo](INFO): Powering down
2012-05-22T19:13:27.884Z,1337714007.884 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2012-05-22T19:13:27.884Z,1337714007.884 [ThrusterServo](INFO): Powering down
2012-05-22T19:13:27.884Z,1337714007.884 [SBIT](DEBUG): Uninitialize SBIT Component.
2012-05-22T19:13:27.885Z,1337714007.885 [IBIT](DEBUG): Uninitialize IBIT Component.
2012-05-22T19:13:27.885Z,1337714007.885 [CBIT](DEBUG): Uninitialize CBIT Component.