2012-05-22T17:33:38.142Z,1337708018.142 [Supervisor](DEBUG): Initializing supervisor.
2012-05-22T17:33:38.144Z,1337708018.144 [SyncHandler](DEBUG): Created PCaller Thread at 1077138656
2012-05-22T17:33:38.145Z,1337708018.145 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2012-05-22T17:33:38.146Z,1337708018.146 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 1077335264
2012-05-22T17:33:38.147Z,1337708018.147 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2012-05-22T17:33:38.157Z,1337708018.157 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2012-05-22T17:33:38.158Z,1337708018.158 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 1077531872
2012-05-22T17:33:38.159Z,1337708018.158 [ComponentRegistry](DEBUG): SyncComponent "logger" handled in the control thread.
2012-05-22T17:33:38.159Z,1337708018.159 [Supervisor](INFO): Looking for Config files in directory: Config/
2012-05-22T17:33:38.160Z,1337708018.160 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2012-05-22T17:33:38.424Z,1337708018.424 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2012-05-22T17:33:38.425Z,1337708018.425 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2012-05-22T17:33:38.603Z,1337708018.602 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2012-05-22T17:33:38.603Z,1337708018.603 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2012-05-22T17:33:38.687Z,1337708018.687 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2012-05-22T17:33:38.688Z,1337708018.688 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2012-05-22T17:33:38.870Z,1337708018.870 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2012-05-22T17:33:38.871Z,1337708018.871 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2012-05-22T17:33:38.994Z,1337708018.994 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2012-05-22T17:33:38.994Z,1337708018.994 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2012-05-22T17:33:39.205Z,1337708019.205 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2012-05-22T17:33:39.205Z,1337708019.205 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2012-05-22T17:33:39.349Z,1337708019.349 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2012-05-22T17:33:39.350Z,1337708019.350 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2012-05-22T17:33:39.640Z,1337708019.640 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2012-05-22T17:33:39.640Z,1337708019.640 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2012-05-22T17:33:39.738Z,1337708019.738 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2012-05-22T17:33:39.739Z,1337708019.739 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2012-05-22T17:33:40.108Z,1337708020.109 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2012-05-22T17:33:40.109Z,1337708020.109 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2012-05-22T17:33:40.216Z,1337708020.216 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2012-05-22T17:33:40.217Z,1337708020.217 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2012-05-22T17:33:40.304Z,1337708020.304 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2012-05-22T17:33:40.305Z,1337708020.305 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2012-05-22T17:33:40.405Z,1337708020.405 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2012-05-22T17:33:40.542Z,1337708020.542 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2012-05-22T17:33:40.641Z,1337708020.641 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2012-05-22T17:33:40.737Z,1337708020.737 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2012-05-22T17:33:40.844Z,1337708020.844 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2012-05-22T17:33:40.932Z,1337708020.932 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2012-05-22T17:33:41.021Z,1337708021.021 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2012-05-22T17:33:41.132Z,1337708021.132 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2012-05-22T17:33:41.254Z,1337708021.254 [InternalSim] Loaded
2012-05-22T17:33:41.254Z,1337708021.254 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2012-05-22T17:33:41.255Z,1337708021.255 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2012-05-22T17:33:41.255Z,1337708021.255 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2012-05-22T17:33:41.296Z,1337708021.296 [SBIT](DEBUG): Construct Startup Built In Test.
2012-05-22T17:33:41.307Z,1337708021.307 [SBIT] Loaded
2012-05-22T17:33:41.307Z,1337708021.307 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2012-05-22T17:33:41.308Z,1337708021.308 [IBIT](DEBUG): Construct Initiated Built In Test.
2012-05-22T17:33:41.331Z,1337708021.331 [IBIT] Loaded
2012-05-22T17:33:41.331Z,1337708021.331 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2012-05-22T17:33:41.338Z,1337708021.338 [CBIT](DEBUG): Construct CBIT Built In Test.
2012-05-22T17:33:41.439Z,1337708021.439 [CBIT] Loaded
2012-05-22T17:33:41.440Z,1337708021.440 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2012-05-22T17:33:41.440Z,1337708021.440 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2012-05-22T17:33:41.440Z,1337708021.440 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2012-05-22T17:33:41.569Z,1337708021.569 [BuoyancyServo] Loaded
2012-05-22T17:33:41.569Z,1337708021.569 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2012-05-22T17:33:41.576Z,1337708021.576 [ElevatorServo] Loaded
2012-05-22T17:33:41.576Z,1337708021.576 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2012-05-22T17:33:41.582Z,1337708021.582 [MassServo] Loaded
2012-05-22T17:33:41.582Z,1337708021.582 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2012-05-22T17:33:41.589Z,1337708021.589 [RudderServo] Loaded
2012-05-22T17:33:41.589Z,1337708021.589 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2012-05-22T17:33:41.595Z,1337708021.595 [ThrusterServo] Loaded
2012-05-22T17:33:41.595Z,1337708021.595 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2012-05-22T17:33:41.596Z,1337708021.596 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2012-05-22T17:33:41.596Z,1337708021.596 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2012-05-22T17:33:41.611Z,1337708021.611 [DepthRateCalculator] Loaded
2012-05-22T17:33:41.611Z,1337708021.611 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2012-05-22T17:33:41.626Z,1337708021.626 [NavChart] Loaded
2012-05-22T17:33:41.627Z,1337708021.627 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2012-05-22T17:33:41.632Z,1337708021.632 [PitchRateCalculator] Loaded
2012-05-22T17:33:41.632Z,1337708021.632 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2012-05-22T17:33:41.638Z,1337708021.638 [SpeedCalculator] Loaded
2012-05-22T17:33:41.638Z,1337708021.638 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2012-05-22T17:33:41.652Z,1337708021.652 [TempGradientCalculator] Loaded
2012-05-22T17:33:41.652Z,1337708021.652 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2012-05-22T17:33:41.657Z,1337708021.657 [YawRateCalculator] Loaded
2012-05-22T17:33:41.658Z,1337708021.658 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2012-05-22T17:33:41.686Z,1337708021.686 [Navigation] Loaded
2012-05-22T17:33:41.686Z,1337708021.686 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread.
2012-05-22T17:33:41.687Z,1337708021.687 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2012-05-22T17:33:41.687Z,1337708021.687 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2012-05-22T17:33:41.888Z,1337708021.888 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2012-05-22T17:33:41.889Z,1337708021.889 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2012-05-22T17:33:41.909Z,1337708021.909 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2012-05-22T17:33:41.910Z,1337708021.910 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2012-05-22T17:33:41.946Z,1337708021.946 [VerticalControl](DEBUG): Construct VerticalControl.
2012-05-22T17:33:41.989Z,1337708021.989 [VerticalControl] Loaded
2012-05-22T17:33:41.989Z,1337708021.989 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2012-05-22T17:33:41.990Z,1337708021.990 [HorizontalControl](DEBUG): Construct HorizontalControl.
2012-05-22T17:33:42.009Z,1337708022.009 [HorizontalControl] Loaded
2012-05-22T17:33:42.009Z,1337708022.009 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2012-05-22T17:33:42.010Z,1337708022.010 [SpeedControl](DEBUG): Construct SpeedControl.
2012-05-22T17:33:42.012Z,1337708022.012 [SpeedControl] Loaded
2012-05-22T17:33:42.012Z,1337708022.012 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2012-05-22T17:33:42.013Z,1337708022.013 [LoopControl](DEBUG): Construct LoopControl.
2012-05-22T17:33:42.014Z,1337708022.013 [LoopControl] Loaded
2012-05-22T17:33:42.014Z,1337708022.014 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2012-05-22T17:33:42.014Z,1337708022.014 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2012-05-22T17:33:42.015Z,1337708022.015 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2012-05-22T17:33:42.020Z,1337708022.020 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator.
2012-05-22T17:33:42.024Z,1337708022.024 [AsyncPiEstimator] Loaded
2012-05-22T17:33:42.025Z,1337708022.025 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread.
2012-05-22T17:33:42.026Z,1337708022.026 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 1078994144
2012-05-22T17:33:42.026Z,1337708022.026 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2012-05-22T17:33:42.027Z,1337708022.027 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2012-05-22T17:33:42.115Z,1337708022.115 [AHRS_sp3003D] Loaded
2012-05-22T17:33:42.115Z,1337708022.115 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2012-05-22T17:33:42.351Z,1337708022.351 [Batt_Ocean_Server] Loaded
2012-05-22T17:33:42.351Z,1337708022.351 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2012-05-22T17:33:42.363Z,1337708022.362 [Depth_Keller] Loaded
2012-05-22T17:33:42.363Z,1337708022.363 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2012-05-22T17:33:42.368Z,1337708022.368 [DropWeight] Loaded
2012-05-22T17:33:42.368Z,1337708022.368 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2012-05-22T17:33:42.457Z,1337708022.457 [DVL_micro] Loaded
2012-05-22T17:33:42.457Z,1337708022.457 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2012-05-22T17:33:42.536Z,1337708022.536 [NAL9601] Loaded
2012-05-22T17:33:42.536Z,1337708022.536 [ComponentRegistry](DEBUG): SyncComponent "NAL9601" handled in the control thread.
2012-05-22T17:33:42.582Z,1337708022.582 [Onboard] Loaded
2012-05-22T17:33:42.582Z,1337708022.582 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2012-05-22T17:33:42.588Z,1337708022.588 [Radio_Freewave] Loaded
2012-05-22T17:33:42.588Z,1337708022.588 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread.
2012-05-22T17:33:42.589Z,1337708022.589 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2012-05-22T17:33:42.590Z,1337708022.590 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2012-05-22T17:33:42.632Z,1337708022.632 [CTD_NeilBrown] Loaded
2012-05-22T17:33:42.633Z,1337708022.633 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2012-05-22T17:33:42.634Z,1337708022.634 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 1079645408
2012-05-22T17:33:42.662Z,1337708022.662 [WetLabsBB2FL] Loaded
2012-05-22T17:33:42.663Z,1337708022.662 [ComponentRegistry](DEBUG): SyncComponent "WetLabsBB2FL" handled in the control thread.
2012-05-22T17:33:42.663Z,1337708022.663 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2012-05-22T17:33:42.665Z,1337708022.665 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2012-05-22T17:33:42.666Z,1337708022.666 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2012-05-22T17:33:42.671Z,1337708022.671 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2012-05-22T17:33:42.672Z,1337708022.672 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 1079842016
2012-05-22T17:33:42.672Z,1337708022.672 [Supervisor](DEBUG): Running supervisor.
2012-05-22T17:33:42.676Z,1337708022.676 [controlThread](DEBUG): Initializing ControlThread
2012-05-22T17:33:42.677Z,1337708022.677 [InternalSim](DEBUG):  InternalSim initializing...
2012-05-22T17:33:42.711Z,1337708022.711 [SBIT](INFO): Initialize SBIT Component.
2012-05-22T17:33:42.712Z,1337708022.712 [SBIT](IMPORTANT): Tethys CM Info:
$Rev: 9636 $
2012-05-22T17:33:42.712Z,1337708022.712 [IBIT](INFO): Initialize IBIT Component.
2012-05-22T17:33:42.716Z,1337708022.716 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator.
2012-05-22T17:33:42.725Z,1337708022.725 [CBIT](DEBUG): Initialize CBIT Component.
2012-05-22T17:33:42.726Z,1337708022.726 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2012-05-22T17:33:42.727Z,1337708022.727 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2012-05-22T17:33:42.756Z,1337708022.756 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2012-05-22T17:33:42.756Z,1337708022.756 [NavChart](DEBUG): Initialize NavChart Derivation.
2012-05-22T17:33:42.757Z,1337708022.757 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2012-05-22T17:33:42.757Z,1337708022.757 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2012-05-22T17:33:42.757Z,1337708022.757 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2012-05-22T17:33:42.759Z,1337708022.759 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2012-05-22T17:33:42.759Z,1337708022.759 [Navigation](DEBUG): Initializing Navigation.
2012-05-22T17:33:42.760Z,1337708022.760 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2012-05-22T17:33:42.762Z,1337708022.762 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2012-05-22T17:33:42.762Z,1337708022.762 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2012-05-22T17:33:42.763Z,1337708022.763 [LoopControl](DEBUG): Initialize LoopControlComponent.
2012-05-22T17:33:42.837Z,1337708022.837 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2012-05-22T17:33:42.843Z,1337708022.843 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2012-05-22T17:33:42.847Z,1337708022.847 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2012-05-22T17:33:42.851Z,1337708022.851 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2012-05-22T17:33:42.855Z,1337708022.855 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2012-05-22T17:33:42.855Z,1337708022.855 [NavChartDb](INFO): Creating index for Soundings
2012-05-22T17:33:42.859Z,1337708022.859 [NavChartDb](INFO): Creating index for Contour 0p0
2012-05-22T17:33:42.861Z,1337708022.861 [NavChartDb](INFO): Creating index for Contour 1p8
2012-05-22T17:33:42.863Z,1337708022.863 [NavChartDb](INFO): Creating index for Contour 3p6
2012-05-22T17:33:42.864Z,1337708022.864 [NavChartDb](INFO): Creating index for Contour 5p4
2012-05-22T17:33:42.867Z,1337708022.866 [NavChartDb](INFO): Creating index for Contour 9p1
2012-05-22T17:33:42.868Z,1337708022.868 [NavChartDb](INFO): Creating index for Contour 10p9
2012-05-22T17:33:42.870Z,1337708022.870 [NavChartDb](INFO): Creating index for Contour 18p2
2012-05-22T17:33:42.872Z,1337708022.872 [NavChartDb](INFO): Creating index for Contour 36p5
2012-05-22T17:33:42.874Z,1337708022.874 [NavChartDb](INFO): Creating index for Contour 54p8
2012-05-22T17:33:42.876Z,1337708022.876 [NavChartDb](INFO): Creating index for Contour 73p1
2012-05-22T17:33:42.878Z,1337708022.878 [NavChartDb](INFO): Creating index for Contour 91p4
2012-05-22T17:33:42.880Z,1337708022.880 [NavChartDb](INFO): Creating index for Contour 182p8
2012-05-22T17:33:42.882Z,1337708022.882 [NavChartDb](INFO): Creating index for Contour 365p7
2012-05-22T17:33:42.884Z,1337708022.884 [NavChartDb](INFO): Creating index for Contour 548p6
2012-05-22T17:33:42.886Z,1337708022.886 [NavChartDb](INFO): Creating index for Contour 731p5
2012-05-22T17:33:42.888Z,1337708022.888 [NavChartDb](INFO): Creating index for Contour 914p4
2012-05-22T17:33:42.890Z,1337708022.890 [NavChartDb](INFO): Creating index for Contour 1097p2
2012-05-22T17:33:42.892Z,1337708022.892 [NavChartDb](INFO): Creating index for Contour 1280p1
2012-05-22T17:33:42.894Z,1337708022.894 [NavChartDb](INFO): Creating index for Contour 1463p0
2012-05-22T17:33:42.896Z,1337708022.896 [NavChartDb](INFO): Creating index for Contour 1645p9
2012-05-22T17:33:42.898Z,1337708022.898 [NavChartDb](INFO): Creating index for Contour 1828p8
2012-05-22T17:33:42.900Z,1337708022.900 [NavChartDb](INFO): Creating index for Contour 2011p6
2012-05-22T17:33:42.901Z,1337708022.901 [NavChartDb](INFO): Creating index for Contour 2194p5
2012-05-22T17:33:42.904Z,1337708022.904 [NavChartDb](INFO): Creating index for Contour 2377p4
2012-05-22T17:33:42.905Z,1337708022.905 [NavChartDb](INFO): Creating index for Contour 2560p3
2012-05-22T17:33:42.907Z,1337708022.907 [NavChartDb](INFO): Creating index for Contour 2743p2
2012-05-22T17:33:42.909Z,1337708022.909 [NavChartDb](INFO): Creating index for Contour 2926p0
2012-05-22T17:33:42.911Z,1337708022.911 [NavChartDb](INFO): Creating index for Contour 3108p9
2012-05-22T17:33:42.913Z,1337708022.913 [NavChartDb](INFO): Creating index for Contour 3291p8
2012-05-22T17:33:42.915Z,1337708022.915 [NavChartDb](INFO): Creating index for Contour 3474p7
2012-05-22T17:33:42.917Z,1337708022.917 [NavChartDb](INFO): Creating index for Contour 3657p6
2012-05-22T17:33:44.663Z,1337708024.663 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2012-05-22T17:33:44.668Z,1337708024.668 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2012-05-22T17:33:44.678Z,1337708024.678 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2012-05-22T17:33:44.687Z,1337708024.687 [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-22T17:33:44.688Z,1337708024.688 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2012-05-22T17:33:44.714Z,1337708024.714 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2012-05-22T17:33:44.716Z,1337708024.716 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2012-05-22T17:33:44.721Z,1337708024.721 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2012-05-22T17:33:44.729Z,1337708024.729 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2012-05-22T17:33:44.732Z,1337708024.732 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2012-05-22T17:33:44.738Z,1337708024.738 [Default:Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2012-05-22T17:33:44.746Z,1337708024.746 [Default:D.SetSpeed](DEBUG): Construct.
2012-05-22T17:33:44.749Z,1337708024.749 [Default:E.GoToSurface](DEBUG): Construct GoToSurface.
2012-05-22T17:33:44.754Z,1337708024.754 [Default:F.Wait](DEBUG): Construct Wait.
2012-05-22T17:33:44.757Z,1337708024.757 [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-22T17:33:44.763Z,1337708024.763 [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-22T17:33:44.783Z,1337708024.783 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2012-05-22T17:33:44.893Z,1337708024.893 [DVL_micro](DEBUG): Initializing DVL_micro.
2012-05-22T17:33:44.917Z,1337708024.917 [WetLabsBB2FL](INFO): Powering down
2012-05-22T17:33:44.984Z,1337708024.984 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2012-05-22T17:33:44.985Z,1337708024.985 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2012-05-22T17:33:44.994Z,1337708024.994 [ElevatorServo](DEBUG): Initializing EZServoServo.
2012-05-22T17:33:44.995Z,1337708024.995 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2012-05-22T17:33:45.005Z,1337708025.005 [MassServo](DEBUG): Initializing EZServoServo.
2012-05-22T17:33:45.006Z,1337708025.006 [MassServo](DEBUG): Initializing MassServo.
2012-05-22T17:33:45.014Z,1337708025.014 [RudderServo](DEBUG): Initializing EZServoServo.
2012-05-22T17:33:45.015Z,1337708025.015 [RudderServo](DEBUG): Initializing RudderServo.
2012-05-22T17:33:45.022Z,1337708025.022 [ThrusterServo](DEBUG): Initializing EZServoServo.
2012-05-22T17:33:45.023Z,1337708025.023 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2012-05-22T17:33:47.588Z,1337708027.588 [NAL9601](INFO): Powering up NAL9601
2012-05-22T17:33:50.016Z,1337708030.016 [Radio_Freewave](INFO): Powering up
2012-05-22T17:33:58.142Z,1337708038.142 [SBIT](IMPORTANT): Beginning Startup BIT
2012-05-22T17:33:58.144Z,1337708038.144 [CBIT](IMPORTANT): Beginning GF scan
2012-05-22T17:34:24.243Z,1337708064.243 [CBIT](IMPORTANT): No ground fault detected
2012-05-22T17:34:39.405Z,1337708079.405 [SBIT](FAULT): Rudder: EXPECTED:0.000000 ACTUAL:-0.299121
2012-05-22T17:34:39.405Z,1337708079.405 [SBIT](FAULT): Control surface position failure.
2012-05-22T17:34:39.804Z,1337708079.804 [SBIT](CRITICAL): SBIT FAILED
2012-05-22T17:34:40.152Z,1337708080.151 [MissionManager](IMPORTANT): Started mission Startup
2012-05-22T17:34:40.152Z,1337708080.152 [Startup] Running Loop=1
2012-05-22T17:34:40.152Z,1337708080.152 [Startup](INFO): Aggregate::initialize Startup
2012-05-22T17:34:40.152Z,1337708080.152 [Startup:A.GoToSurface] Running Loop=1
2012-05-22T17:34:40.152Z,1337708080.152 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-05-22T17:34:40.158Z,1337708080.158 [Startup:StartupSatComms] Running Loop=1
2012-05-22T17:34:40.158Z,1337708080.158 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2012-05-22T17:34:40.158Z,1337708080.158 [Startup:StartupSatComms:A] Running Loop=1
2012-05-22T17:34:40.567Z,1337708080.567 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2012-05-22T17:34:53.427Z,1337708093.427 [NAL9601](INFO): NAL9601 initialized
2012-05-22T17:35:40.166Z,1337708140.166 [Startup:StartupSatComms:A](INFO): Timed out from 2012-05-22T17:34:40.2Z
2012-05-22T17:35:40.166Z,1337708140.166 [Startup:StartupSatComms:A_Timeout] Running Loop=1
2012-05-22T17:35:40.166Z,1337708140.166 [Startup:StartupSatComms:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:A_Timeout
2012-05-22T17:35:40.167Z,1337708140.167 [Startup:StartupSatComms:A_Timeout](INFO): Completed Startup:StartupSatComms:A_Timeout
2012-05-22T17:35:40.167Z,1337708140.167 [Startup:StartupSatComms:A] Stopped
2012-05-22T17:35:40.167Z,1337708140.167 [Startup:StartupSatComms:B] Running Loop=1
2012-05-22T17:35:40.544Z,1337708140.544 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2012-05-22T17:36:40.510Z,1337708200.510 [Startup:StartupSatComms:B](INFO): Timed out from 2012-05-22T17:35:40.2Z
2012-05-22T17:36:40.510Z,1337708200.510 [Startup:StartupSatComms:A_Timeout] Running Loop=1
2012-05-22T17:36:40.510Z,1337708200.510 [Startup:StartupSatComms:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:A_Timeout
2012-05-22T17:36:40.510Z,1337708200.510 [Startup:StartupSatComms:A_Timeout](INFO): Completed Startup:StartupSatComms:A_Timeout
2012-05-22T17:36:40.510Z,1337708200.510 [Startup:StartupSatComms:B] Stopped
2012-05-22T17:36:40.511Z,1337708200.510 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2012-05-22T17:36:40.511Z,1337708200.511 [Startup:StartupSatComms] Stopped
2012-05-22T17:36:40.511Z,1337708200.511 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2012-05-22T17:36:40.512Z,1337708200.512 [Startup](INFO): Completed Startup
2012-05-22T17:36:40.512Z,1337708200.512 [Startup] Stopped
2012-05-22T17:36:40.512Z,1337708200.512 [Startup](INFO): Aggregate::uninitialize Startup
2012-05-22T17:36:40.512Z,1337708200.512 [Startup:A.GoToSurface] Stopped
2012-05-22T17:36:40.512Z,1337708200.512 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-05-22T17:36:40.652Z,1337708200.652 [MissionManager](IMPORTANT): Started mission Default
2012-05-22T17:36:40.652Z,1337708200.652 [Default] Running Loop=1
2012-05-22T17:36:40.652Z,1337708200.652 [Default](INFO): Aggregate::initialize Default
2012-05-22T17:36:40.652Z,1337708200.652 [Default:D.SetSpeed] Running Loop=1
2012-05-22T17:36:40.652Z,1337708200.652 [Default:D.SetSpeed](DEBUG): Initialize.
2012-05-22T17:36:40.652Z,1337708200.652 [Default:E.GoToSurface] Running Loop=1
2012-05-22T17:36:40.652Z,1337708200.652 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-05-22T17:36:40.653Z,1337708200.653 [Default:Iridium] Running Loop=1
2012-05-22T17:36:40.653Z,1337708200.653 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2012-05-22T17:36:40.653Z,1337708200.653 [Default:Iridium:A.SetSpeed] Running Loop=1
2012-05-22T17:36:40.653Z,1337708200.653 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2012-05-22T17:36:40.653Z,1337708200.653 [Default:Iridium:B.GoToSurface] Running Loop=1
2012-05-22T17:36:40.653Z,1337708200.653 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-05-22T17:36:40.654Z,1337708200.654 [Default:E.GoToSurface] Running Loop=1
2012-05-22T17:36:40.660Z,1337708200.660 [Default:D.SetSpeed] Running Loop=1
2012-05-22T17:36:40.664Z,1337708200.664 [Default:CallIridium] Running Loop=1
2012-05-22T17:36:40.665Z,1337708200.665 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2012-05-22T17:36:40.665Z,1337708200.665 [Default:CallIridium:A] Running Loop=1
2012-05-22T17:36:40.667Z,1337708200.667 [Default:CallIridium:A] Stopped
2012-05-22T17:36:40.667Z,1337708200.667 [Default:CallIridium:B] Running Loop=1
2012-05-22T17:36:40.667Z,1337708200.667 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2012-05-22T17:36:40.672Z,1337708200.672 [Default:Iridium:B.GoToSurface] Stopped
2012-05-22T17:36:40.672Z,1337708200.672 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-05-22T17:36:40.672Z,1337708200.672 [Default:Iridium:Read_Iridium] Running Loop=1
2012-05-22T17:36:40.672Z,1337708200.672 [Default:Iridium:A.SetSpeed] Running Loop=1
2012-05-22T17:36:40.677Z,1337708200.677 [Default:GPS] Running Loop=1
2012-05-22T17:36:40.677Z,1337708200.677 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2012-05-22T17:36:40.677Z,1337708200.677 [Default:GPS:A.SetSpeed] Running Loop=1
2012-05-22T17:36:40.677Z,1337708200.677 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2012-05-22T17:36:40.677Z,1337708200.677 [Default:GPS:B.GoToSurface] Running Loop=1
2012-05-22T17:36:40.678Z,1337708200.678 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-05-22T17:36:40.683Z,1337708200.683 [Default:GPS:B.GoToSurface] Stopped
2012-05-22T17:36:40.683Z,1337708200.683 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-05-22T17:36:40.683Z,1337708200.683 [Default:GPS:Read_GPS] Running Loop=1
2012-05-22T17:36:40.683Z,1337708200.683 [Default:GPS:A.SetSpeed] Running Loop=1
2012-05-22T17:36:41.060Z,1337708201.060 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2012-05-22T17:36:41.063Z,1337708201.063 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2012-05-22T17:39:25.621Z,1337708365.621 [NAL9601](INFO): SBD MO Status=2, MOMSN=6681, MT Status=2, MTMSN=0
2012-05-22T17:39:25.621Z,1337708365.621 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T17:40:20.585Z,1337708420.585 [NAL9601](INFO): SBD MO Status=2, MOMSN=6681, MT Status=2, MTMSN=0
2012-05-22T17:40:20.586Z,1337708420.586 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T17:40:44.946Z,1337708444.946 [NAL9601](INFO): SBD MO Status=2, MOMSN=6681, MT Status=2, MTMSN=0
2012-05-22T17:40:44.946Z,1337708444.946 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T17:41:08.365Z,1337708468.365 [NAL9601](INFO): SBD MO Status=2, MOMSN=6681, MT Status=2, MTMSN=0
2012-05-22T17:41:08.366Z,1337708468.365 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T17:42:23.526Z,1337708543.526 [NAL9601](INFO): SBD MO Status=2, MOMSN=6681, MT Status=2, MTMSN=0
2012-05-22T17:42:23.526Z,1337708543.526 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T17:43:03.165Z,1337708583.165 [NAL9601](INFO): SBD MO Status=2, MOMSN=6681, MT Status=2, MTMSN=0
2012-05-22T17:43:03.166Z,1337708583.165 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T17:44:55.475Z,1337708695.475 [NAL9601](FAULT): GPS failed to acquire within timeout.
2012-05-22T17:44:55.475Z,1337708695.476 [NAL9601] Data Fault, FailCount= 1
2012-05-22T17:44:55.475Z,1337708695.476 [NAL9601](ERROR): Data Fault
2012-05-22T17:44:55.541Z,1337708695.541 [CBIT](ERROR): Data Fault in component: NAL9601
2012-05-22T17:44:55.881Z,1337708695.881 [NAL9601](INFO): Powering down
2012-05-22T17:44:55.949Z,1337708695.949 [CBIT](INFO): Clearing failed state for component NAL9601
2012-05-22T17:44:55.949Z,1337708695.949 [NAL9601] No Fault, FailCount= 1
2012-05-22T17:45:01.086Z,1337708701.086 [NAL9601](INFO): Powering up NAL9601
2012-05-22T17:46:06.723Z,1337708766.723 [NAL9601](INFO): NAL9601 initialized
2012-05-22T17:48:35.158Z,1337708915.158 [NAL9601](INFO): SBD MO Status=2, MOMSN=6681, MT Status=2, MTMSN=0
2012-05-22T17:48:35.158Z,1337708915.158 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T17:49:05.422Z,1337708945.422 [NAL9601](INFO): SBD MO Status=1, MOMSN=6681, MT Status=0, MTMSN=0
2012-05-22T17:49:05.635Z,1337708945.635 [NAL9601](INFO): Sent 147 bytes from file Logs/20120511T211252/shore0001.lzma
2012-05-22T17:49:05.635Z,1337708945.635 [NAL9601](INFO): Packets left to send: 0
2012-05-22T17:49:05.636Z,1337708945.636 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000000
2012-05-22T17:49:47.118Z,1337708987.118 [NAL9601](INFO): SBD MO Status=2, MOMSN=6682, MT Status=2, MTMSN=0
2012-05-22T17:49:47.118Z,1337708987.118 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T17:50:20.102Z,1337709020.102 [NAL9601](INFO): SBD MO Status=2, MOMSN=6682, MT Status=2, MTMSN=0
2012-05-22T17:50:20.102Z,1337709020.102 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T17:50:35.254Z,1337709035.254 [NAL9601](INFO): SBD MO Status=2, MOMSN=6682, MT Status=2, MTMSN=0
2012-05-22T17:50:35.254Z,1337709035.254 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T17:51:42.014Z,1337709102.014 [NAL9601](INFO): SBD MO Status=2, MOMSN=6682, MT Status=2, MTMSN=0
2012-05-22T17:51:42.014Z,1337709102.014 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T17:55:07.484Z,1337709307.484 [NAL9601](IMPORTANT): GPS fix at: 1337711042.00
2012-05-22T17:55:07.498Z,1337709307.499 [Default:GPS:Read_GPS] Stopped
2012-05-22T17:55:07.499Z,1337709307.499 [Default:GPS:D] Running Loop=1
2012-05-22T17:55:07.922Z,1337709307.921 [Default:GPS:D] Stopped
2012-05-22T17:55:07.922Z,1337709307.922 [Default:GPS](INFO): Completed Default:GPS
2012-05-22T17:55:07.922Z,1337709307.922 [Default:GPS] Stopped
2012-05-22T17:55:07.922Z,1337709307.922 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2012-05-22T17:55:07.922Z,1337709307.922 [Default:GPS:A.SetSpeed] Stopped
2012-05-22T17:55:07.922Z,1337709307.922 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2012-05-22T17:57:23.027Z,1337709443.027 [NAL9601](INFO): SBD MO Status=1, MOMSN=6682, MT Status=0, MTMSN=0
2012-05-22T17:57:23.163Z,1337709443.163 [NAL9601](INFO): Sent 332 bytes from file Logs/20120514T221616/shore0000.lzma
2012-05-22T17:57:23.163Z,1337709443.163 [NAL9601](INFO): Packets left to send: 1
2012-05-22T17:57:23.164Z,1337709443.164 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000001
2012-05-22T17:57:38.753Z,1337709458.753 [NAL9601](INFO): SBD MO Status=1, MOMSN=6683, MT Status=0, MTMSN=0
2012-05-22T17:57:38.943Z,1337709458.943 [NAL9601](INFO): Sent 280 bytes from file Logs/20120514T221616/shore0000.lzma
2012-05-22T17:57:38.943Z,1337709458.943 [NAL9601](INFO): Packets left to send: 0
2012-05-22T17:57:38.944Z,1337709458.944 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000002
2012-05-22T17:57:57.569Z,1337709477.569 [NAL9601](INFO): SBD MO Status=2, MOMSN=6684, MT Status=2, MTMSN=0
2012-05-22T17:57:57.569Z,1337709477.569 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T17:58:08.173Z,1337709488.173 [Radio_Freewave](INFO): Powering down
2012-05-22T17:58:09.310Z,1337709489.310 [ThrusterServo](FAULT): getVelocity uart error serial timeout
2012-05-22T17:58:09.311Z,1337709489.311 [ThrusterServo](FAULT): Thruster uart error: serial timeout
2012-05-22T17:58:09.311Z,1337709489.311 [ThrusterServo] Communications Fault, FailCount= 1
2012-05-22T17:58:09.311Z,1337709489.311 [ThrusterServo](ERROR): Communications Fault
2012-05-22T17:58:09.313Z,1337709489.313 [CBIT](ERROR): Communications Fault in component: ThrusterServo
2012-05-22T17:58:10.083Z,1337709490.083 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2012-05-22T17:58:10.083Z,1337709490.083 [ThrusterServo](INFO): Powering down
2012-05-22T17:58:10.085Z,1337709490.085 [CBIT](INFO): Clearing failed state for component ThrusterServo
2012-05-22T17:58:10.085Z,1337709490.085 [ThrusterServo] No Fault, FailCount= 1
2012-05-22T17:58:10.728Z,1337709490.728 [ThrusterServo](DEBUG): Initializing EZServoServo.
2012-05-22T17:58:10.847Z,1337709490.847 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2012-05-22T17:58:12.857Z,1337709492.857 [Radio_Freewave](INFO): Powering up
2012-05-22T18:00:06.924Z,1337709606.924 [NAL9601](INFO): SBD MO Status=2, MOMSN=6684, MT Status=2, MTMSN=0
2012-05-22T18:00:06.925Z,1337709606.925 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:00:23.654Z,1337709623.654 [NAL9601](INFO): SBD MO Status=2, MOMSN=6684, MT Status=2, MTMSN=0
2012-05-22T18:00:23.654Z,1337709623.654 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:01:08.628Z,1337709668.628 [NAL9601](INFO): SBD MO Status=2, MOMSN=6684, MT Status=2, MTMSN=0
2012-05-22T18:01:08.629Z,1337709668.629 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:01:40.130Z,1337709700.129 [NAL9601](INFO): SBD MO Status=2, MOMSN=6684, MT Status=2, MTMSN=0
2012-05-22T18:01:40.130Z,1337709700.130 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:02:04.989Z,1337709724.990 [NAL9601](INFO): SBD MO Status=2, MOMSN=6684, MT Status=2, MTMSN=0
2012-05-22T18:02:04.990Z,1337709724.990 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:02:30.893Z,1337709750.893 [NAL9601](INFO): SBD MO Status=2, MOMSN=6684, MT Status=2, MTMSN=0
2012-05-22T18:02:30.893Z,1337709750.893 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:05:05.000Z,1337709905.000 [NAL9601](INFO): SBD MO Status=1, MOMSN=6684, MT Status=0, MTMSN=0
2012-05-22T18:05:05.147Z,1337709905.147 [NAL9601](INFO): Sent 158 bytes from file Logs/20120514T221616/shore0001.lzma
2012-05-22T18:05:05.147Z,1337709905.147 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:05:05.148Z,1337709905.148 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000003
2012-05-22T18:05:26.298Z,1337709926.297 [NAL9601](INFO): SBD MO Status=1, MOMSN=6685, MT Status=0, MTMSN=0
2012-05-22T18:05:26.515Z,1337709926.515 [NAL9601](INFO): Sent 271 bytes from file Logs/20120514T221616/shore0002.lzma
2012-05-22T18:05:26.515Z,1337709926.515 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:05:26.516Z,1337709926.516 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000004
2012-05-22T18:05:36.409Z,1337709936.409 [NAL9601](INFO): SBD MO Status=1, MOMSN=6686, MT Status=0, MTMSN=0
2012-05-22T18:05:36.595Z,1337709936.595 [NAL9601](INFO): Sent 332 bytes from file Logs/20120514T222303/shore0000.lzma
2012-05-22T18:05:36.595Z,1337709936.595 [NAL9601](INFO): Packets left to send: 1
2012-05-22T18:05:36.596Z,1337709936.596 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000005
2012-05-22T18:05:45.300Z,1337709945.300 [NAL9601](INFO): SBD MO Status=1, MOMSN=6687, MT Status=0, MTMSN=0
2012-05-22T18:05:45.483Z,1337709945.483 [NAL9601](INFO): Sent 116 bytes from file Logs/20120514T222303/shore0000.lzma
2012-05-22T18:05:45.483Z,1337709945.483 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:05:45.484Z,1337709945.484 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000006
2012-05-22T18:06:07.037Z,1337709967.037 [NAL9601](INFO): SBD MO Status=1, MOMSN=6688, MT Status=0, MTMSN=0
2012-05-22T18:06:07.263Z,1337709967.263 [NAL9601](INFO): Sent 96 bytes from file Logs/20120514T222303/shore0001.lzma
2012-05-22T18:06:07.263Z,1337709967.263 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:06:07.264Z,1337709967.264 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000007
2012-05-22T18:06:18.724Z,1337709978.724 [NAL9601](INFO): SBD MO Status=1, MOMSN=6689, MT Status=0, MTMSN=0
2012-05-22T18:06:18.934Z,1337709978.934 [NAL9601](INFO): Sent 332 bytes from file Logs/20120514T222303/shore0002.lzma
2012-05-22T18:06:18.935Z,1337709978.935 [NAL9601](INFO): Packets left to send: 1
2012-05-22T18:06:18.936Z,1337709978.936 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000008
2012-05-22T18:06:32.085Z,1337709992.085 [NAL9601](INFO): SBD MO Status=1, MOMSN=6690, MT Status=0, MTMSN=0
2012-05-22T18:06:32.211Z,1337709992.211 [NAL9601](INFO): Sent 65 bytes from file Logs/20120514T222303/shore0002.lzma
2012-05-22T18:06:32.211Z,1337709992.211 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:06:32.212Z,1337709992.212 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000009
2012-05-22T18:06:45.413Z,1337710005.413 [NAL9601](INFO): SBD MO Status=1, MOMSN=6691, MT Status=0, MTMSN=0
2012-05-22T18:06:45.591Z,1337710005.591 [NAL9601](INFO): Sent 332 bytes from file Logs/20120514T222543/shore0000.lzma
2012-05-22T18:06:45.591Z,1337710005.591 [NAL9601](INFO): Packets left to send: 1
2012-05-22T18:06:45.592Z,1337710005.592 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000010
2012-05-22T18:06:52.323Z,1337710012.323 [NAL9601](INFO): SBD MO Status=1, MOMSN=6692, MT Status=0, MTMSN=0
2012-05-22T18:06:52.479Z,1337710012.479 [NAL9601](INFO): Sent 179 bytes from file Logs/20120514T222543/shore0000.lzma
2012-05-22T18:06:52.479Z,1337710012.479 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:06:52.480Z,1337710012.480 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000011
2012-05-22T18:07:02.549Z,1337710022.549 [NAL9601](INFO): SBD MO Status=1, MOMSN=6693, MT Status=0, MTMSN=0
2012-05-22T18:07:02.763Z,1337710022.763 [NAL9601](INFO): Sent 332 bytes from file Logs/20120514T222543/shore0001.lzma
2012-05-22T18:07:02.763Z,1337710022.763 [NAL9601](INFO): Packets left to send: 1
2012-05-22T18:07:02.764Z,1337710022.764 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000012
2012-05-22T18:07:08.689Z,1337710028.690 [NAL9601](INFO): SBD MO Status=1, MOMSN=6694, MT Status=0, MTMSN=0
2012-05-22T18:07:08.855Z,1337710028.855 [NAL9601](INFO): Sent 2 bytes from file Logs/20120514T222543/shore0001.lzma
2012-05-22T18:07:08.855Z,1337710028.855 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:07:08.856Z,1337710028.856 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000013
2012-05-22T18:07:20.382Z,1337710040.382 [NAL9601](INFO): SBD MO Status=1, MOMSN=6695, MT Status=0, MTMSN=0
2012-05-22T18:07:20.535Z,1337710040.535 [NAL9601](INFO): Sent 294 bytes from file Logs/20120514T222543/shore0002.lzma
2012-05-22T18:07:20.535Z,1337710040.535 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:07:20.536Z,1337710040.536 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000014
2012-05-22T18:07:34.765Z,1337710054.765 [NAL9601](INFO): SBD MO Status=1, MOMSN=6696, MT Status=0, MTMSN=0
2012-05-22T18:07:34.919Z,1337710054.919 [NAL9601](INFO): Sent 332 bytes from file Logs/20120514T223147/shore0000.lzma
2012-05-22T18:07:34.919Z,1337710054.919 [NAL9601](INFO): Packets left to send: 1
2012-05-22T18:07:34.920Z,1337710054.920 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000015
2012-05-22T18:07:46.062Z,1337710066.062 [NAL9601](INFO): SBD MO Status=1, MOMSN=6697, MT Status=0, MTMSN=0
2012-05-22T18:07:46.195Z,1337710066.195 [NAL9601](INFO): Sent 273 bytes from file Logs/20120514T223147/shore0000.lzma
2012-05-22T18:07:46.195Z,1337710066.195 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:07:46.196Z,1337710066.196 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000016
2012-05-22T18:07:54.971Z,1337710074.971 [NAL9601](INFO): SBD MO Status=1, MOMSN=6698, MT Status=0, MTMSN=0
2012-05-22T18:07:55.183Z,1337710075.183 [NAL9601](INFO): Sent 159 bytes from file Logs/20120514T223147/shore0001.lzma
2012-05-22T18:07:55.183Z,1337710075.183 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:07:55.184Z,1337710075.184 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000017
2012-05-22T18:08:08.268Z,1337710088.268 [NAL9601](INFO): SBD MO Status=1, MOMSN=6699, MT Status=0, MTMSN=0
2012-05-22T18:08:08.471Z,1337710088.471 [NAL9601](INFO): Sent 249 bytes from file Logs/20120514T223147/shore0002.lzma
2012-05-22T18:08:08.471Z,1337710088.471 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:08:08.472Z,1337710088.472 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000018
2012-05-22T18:08:23.237Z,1337710103.237 [NAL9601](INFO): SBD MO Status=1, MOMSN=6700, MT Status=0, MTMSN=0
2012-05-22T18:08:23.439Z,1337710103.439 [NAL9601](INFO): Sent 224 bytes from file Logs/20120514T223147/shore0003.lzma
2012-05-22T18:08:23.439Z,1337710103.439 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:08:23.440Z,1337710103.440 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000019
2012-05-22T18:08:36.913Z,1337710116.913 [NAL9601](INFO): SBD MO Status=1, MOMSN=6701, MT Status=0, MTMSN=0
2012-05-22T18:08:37.115Z,1337710117.115 [NAL9601](INFO): Sent 146 bytes from file Logs/20120514T223147/shore0004.lzma
2012-05-22T18:08:37.115Z,1337710117.115 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:08:37.116Z,1337710117.116 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000020
2012-05-22T18:08:56.629Z,1337710136.629 [NAL9601](INFO): SBD MO Status=1, MOMSN=6702, MT Status=0, MTMSN=0
2012-05-22T18:08:56.787Z,1337710136.787 [NAL9601](INFO): Sent 148 bytes from file Logs/20120514T223147/shore0005.lzma
2012-05-22T18:08:56.787Z,1337710136.787 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:08:56.847Z,1337710136.847 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000021
2012-05-22T18:09:18.377Z,1337710158.377 [NAL9601](INFO): SBD MO Status=2, MOMSN=6703, MT Status=2, MTMSN=0
2012-05-22T18:09:18.378Z,1337710158.378 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:09:51.849Z,1337710191.849 [NAL9601](INFO): SBD MO Status=2, MOMSN=6703, MT Status=2, MTMSN=0
2012-05-22T18:09:51.850Z,1337710191.850 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:10:13.636Z,1337710213.636 [NAL9601](INFO): SBD MO Status=1, MOMSN=6703, MT Status=0, MTMSN=0
2012-05-22T18:10:13.767Z,1337710213.767 [NAL9601](INFO): Sent 145 bytes from file Logs/20120514T223147/shore0006.lzma
2012-05-22T18:10:13.767Z,1337710213.767 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:10:13.768Z,1337710213.768 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000022
2012-05-22T18:10:51.313Z,1337710251.313 [NAL9601](INFO): SBD MO Status=1, MOMSN=6704, MT Status=0, MTMSN=0
2012-05-22T18:10:51.507Z,1337710251.507 [NAL9601](INFO): Sent 145 bytes from file Logs/20120514T223147/shore0007.lzma
2012-05-22T18:10:51.507Z,1337710251.507 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:10:51.550Z,1337710251.550 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000023
2012-05-22T18:11:08.254Z,1337710268.253 [NAL9601](INFO): SBD MO Status=2, MOMSN=6705, MT Status=2, MTMSN=0
2012-05-22T18:11:08.254Z,1337710268.254 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:12:00.226Z,1337710320.226 [NAL9601](INFO): SBD MO Status=2, MOMSN=6705, MT Status=2, MTMSN=0
2012-05-22T18:12:00.226Z,1337710320.226 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:14:49.622Z,1337710489.622 [NAL9601](INFO): SBD MO Status=2, MOMSN=6705, MT Status=2, MTMSN=0
2012-05-22T18:14:49.622Z,1337710489.622 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:15:15.913Z,1337710515.913 [NAL9601](INFO): SBD MO Status=1, MOMSN=6705, MT Status=0, MTMSN=0
2012-05-22T18:15:16.095Z,1337710516.095 [NAL9601](INFO): Sent 181 bytes from file Logs/20120514T223147/shore0008.lzma
2012-05-22T18:15:16.095Z,1337710516.095 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:15:16.096Z,1337710516.096 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000024
2012-05-22T18:15:28.492Z,1337710528.492 [NAL9601](INFO): SBD MO Status=1, MOMSN=6706, MT Status=0, MTMSN=0
2012-05-22T18:15:28.679Z,1337710528.679 [NAL9601](INFO): Sent 332 bytes from file Logs/20120514T231332/shore0000.lzma
2012-05-22T18:15:28.679Z,1337710528.679 [NAL9601](INFO): Packets left to send: 1
2012-05-22T18:15:28.680Z,1337710528.680 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000025
2012-05-22T18:15:39.429Z,1337710539.429 [NAL9601](INFO): SBD MO Status=1, MOMSN=6707, MT Status=0, MTMSN=0
2012-05-22T18:15:39.563Z,1337710539.563 [NAL9601](INFO): Sent 112 bytes from file Logs/20120514T231332/shore0000.lzma
2012-05-22T18:15:39.563Z,1337710539.563 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:15:39.564Z,1337710539.564 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000026
2012-05-22T18:15:47.571Z,1337710547.571 [NAL9601](INFO): SBD MO Status=1, MOMSN=6708, MT Status=0, MTMSN=0
2012-05-22T18:15:47.747Z,1337710547.747 [NAL9601](INFO): Sent 96 bytes from file Logs/20120514T231332/shore0001.lzma
2012-05-22T18:15:47.747Z,1337710547.747 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:15:47.748Z,1337710547.748 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000027
2012-05-22T18:16:02.852Z,1337710562.852 [NAL9601](INFO): SBD MO Status=1, MOMSN=6709, MT Status=0, MTMSN=0
2012-05-22T18:16:03.023Z,1337710563.023 [NAL9601](INFO): Sent 332 bytes from file Logs/20120514T231332/shore0002.lzma
2012-05-22T18:16:03.023Z,1337710563.023 [NAL9601](INFO): Packets left to send: 1
2012-05-22T18:16:03.024Z,1337710563.024 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000028
2012-05-22T18:16:10.113Z,1337710570.114 [NAL9601](INFO): SBD MO Status=1, MOMSN=6710, MT Status=0, MTMSN=0
2012-05-22T18:16:10.315Z,1337710570.315 [NAL9601](INFO): Sent 98 bytes from file Logs/20120514T231332/shore0002.lzma
2012-05-22T18:16:10.315Z,1337710570.315 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:16:10.317Z,1337710570.317 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000029
2012-05-22T18:16:19.451Z,1337710579.451 [NAL9601](INFO): SBD MO Status=1, MOMSN=6711, MT Status=0, MTMSN=0
2012-05-22T18:16:19.599Z,1337710579.599 [NAL9601](INFO): Sent 262 bytes from file Logs/20120514T231332/shore0003.lzma
2012-05-22T18:16:19.599Z,1337710579.599 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:16:19.600Z,1337710579.600 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000030
2012-05-22T18:16:31.529Z,1337710591.529 [NAL9601](INFO): SBD MO Status=1, MOMSN=6712, MT Status=0, MTMSN=0
2012-05-22T18:16:31.695Z,1337710591.695 [NAL9601](INFO): Sent 112 bytes from file Logs/20120514T231332/shore0004.lzma
2012-05-22T18:16:31.695Z,1337710591.695 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:16:31.696Z,1337710591.696 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000031
2012-05-22T18:16:47.646Z,1337710607.645 [NAL9601](INFO): SBD MO Status=2, MOMSN=6713, MT Status=2, MTMSN=0
2012-05-22T18:16:47.646Z,1337710607.646 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:17:14.930Z,1337710634.930 [NAL9601](INFO): SBD MO Status=1, MOMSN=6713, MT Status=0, MTMSN=0
2012-05-22T18:17:15.115Z,1337710635.115 [NAL9601](INFO): Sent 184 bytes from file Logs/20120514T231332/shore0005.lzma
2012-05-22T18:17:15.115Z,1337710635.115 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:17:15.116Z,1337710635.116 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000032
2012-05-22T18:17:26.626Z,1337710646.625 [NAL9601](INFO): SBD MO Status=1, MOMSN=6714, MT Status=0, MTMSN=0
2012-05-22T18:17:26.795Z,1337710646.795 [NAL9601](INFO): Sent 225 bytes from file Logs/20120515T211608/shore0000.lzma
2012-05-22T18:17:26.795Z,1337710646.795 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:17:26.796Z,1337710646.796 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000033
2012-05-22T18:17:33.922Z,1337710653.921 [NAL9601](INFO): SBD MO Status=1, MOMSN=6715, MT Status=0, MTMSN=0
2012-05-22T18:17:34.111Z,1337710654.111 [NAL9601](INFO): Sent 265 bytes from file Logs/20120515T212218/shore0000.lzma
2012-05-22T18:17:34.111Z,1337710654.111 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:17:34.112Z,1337710654.112 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000034
2012-05-22T18:17:44.936Z,1337710664.936 [NAL9601](INFO): SBD MO Status=1, MOMSN=6716, MT Status=0, MTMSN=0
2012-05-22T18:17:45.067Z,1337710665.067 [NAL9601](INFO): Sent 265 bytes from file Logs/20120515T212445/shore0000.lzma
2012-05-22T18:17:45.067Z,1337710665.067 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:17:45.068Z,1337710665.068 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000035
2012-05-22T18:18:00.997Z,1337710680.997 [NAL9601](INFO): SBD MO Status=2, MOMSN=6717, MT Status=2, MTMSN=0
2012-05-22T18:18:00.998Z,1337710680.998 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:18:22.896Z,1337710702.896 [NAL9601](INFO): SBD MO Status=2, MOMSN=6717, MT Status=2, MTMSN=0
2012-05-22T18:18:22.896Z,1337710702.896 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:19:04.618Z,1337710744.618 [NAL9601](INFO): SBD MO Status=1, MOMSN=6717, MT Status=0, MTMSN=0
2012-05-22T18:19:04.743Z,1337710744.743 [NAL9601](INFO): Sent 265 bytes from file Logs/20120515T214513/shore0000.lzma
2012-05-22T18:19:04.743Z,1337710744.743 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:19:04.744Z,1337710744.744 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000036
2012-05-22T18:19:16.002Z,1337710756.003 [NAL9601](INFO): SBD MO Status=2, MOMSN=6718, MT Status=2, MTMSN=0
2012-05-22T18:19:16.003Z,1337710756.003 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:19:37.131Z,1337710777.131 [NAL9601](INFO): SBD MO Status=1, MOMSN=6718, MT Status=0, MTMSN=0
2012-05-22T18:19:37.291Z,1337710777.291 [NAL9601](INFO): Sent 264 bytes from file Logs/20120515T214938/shore0000.lzma
2012-05-22T18:19:37.291Z,1337710777.291 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:19:37.292Z,1337710777.292 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000037
2012-05-22T18:19:51.186Z,1337710791.186 [NAL9601](INFO): SBD MO Status=1, MOMSN=6719, MT Status=0, MTMSN=0
2012-05-22T18:19:51.375Z,1337710791.375 [NAL9601](INFO): Sent 265 bytes from file Logs/20120515T215022/shore0000.lzma
2012-05-22T18:19:51.375Z,1337710791.375 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:19:51.376Z,1337710791.376 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000038
2012-05-22T18:20:01.763Z,1337710801.763 [NAL9601](INFO): SBD MO Status=2, MOMSN=6720, MT Status=2, MTMSN=0
2012-05-22T18:20:01.763Z,1337710801.763 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:20:31.613Z,1337710831.613 [NAL9601](INFO): SBD MO Status=2, MOMSN=6720, MT Status=2, MTMSN=0
2012-05-22T18:20:31.614Z,1337710831.614 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:21:15.512Z,1337710875.513 [NAL9601](INFO): SBD MO Status=2, MOMSN=6720, MT Status=2, MTMSN=0
2012-05-22T18:21:15.513Z,1337710875.513 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:21:46.448Z,1337710906.448 [NAL9601](INFO): SBD MO Status=2, MOMSN=6720, MT Status=2, MTMSN=0
2012-05-22T18:21:46.449Z,1337710906.449 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:22:11.186Z,1337710931.186 [NAL9601](INFO): SBD MO Status=2, MOMSN=6720, MT Status=2, MTMSN=0
2012-05-22T18:22:11.186Z,1337710931.186 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:22:28.665Z,1337710948.665 [NAL9601](INFO): SBD MO Status=2, MOMSN=6720, MT Status=2, MTMSN=0
2012-05-22T18:22:28.665Z,1337710948.665 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:22:45.433Z,1337710965.432 [NAL9601](INFO): SBD MO Status=2, MOMSN=6720, MT Status=2, MTMSN=0
2012-05-22T18:22:45.433Z,1337710965.433 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-22T18:23:52.302Z,1337711032.302 [NAL9601](INFO): SBD MO Status=1, MOMSN=6720, MT Status=0, MTMSN=0
2012-05-22T18:23:52.495Z,1337711032.495 [NAL9601](INFO): Sent 304 bytes from file Logs/20120515T215533/shore0000.lzma
2012-05-22T18:23:52.495Z,1337711032.495 [NAL9601](INFO): Packets left to send: 0
2012-05-22T18:23:52.496Z,1337711032.496 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000039
2012-05-22T18:24:00.483Z,1337711040.483 [CommandLine](IMPORTANT): got command restart application
2012-05-22T18:24:00.530Z,1337711040.530 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2012-05-22T18:24:00.531Z,1337711040.531 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2012-05-22T18:24:00.552Z,1337711040.552 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2012-05-22T18:24:00.559Z,1337711040.559 [CTD_NeilBrown](INFO): Powering down
2012-05-22T18:24:00.559Z,1337711040.559 [ComponentRegistry](INFO): Shutting down AsyncPiEstimator ThreadHandler
2012-05-22T18:24:00.717Z,1337711040.717 [AsyncPiEstimator](DEBUG): Uninitialize AsyncPiEstimator.
2012-05-22T18:24:00.717Z,1337711040.717 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2012-05-22T18:24:00.717Z,1337711040.717 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2012-05-22T18:24:00.903Z,1337711040.903 [controlThread](DEBUG): Uninitializing ControlThread
2012-05-22T18:24:00.904Z,1337711040.904 [AHRS_sp3003D](INFO): Powering down
2012-05-22T18:24:00.992Z,1337711040.992 [DVL_micro](INFO): Powering down
2012-05-22T18:24:00.992Z,1337711040.992 [NAL9601](INFO): Powering down
2012-05-22T18:24:00.993Z,1337711040.993 [WetLabsBB2FL](INFO): Powering down
2012-05-22T18:24:00.993Z,1337711040.993 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2012-05-22T18:24:00.994Z,1337711040.994 [NavChart](DEBUG): Uninitialize NavChart Derivation.
2012-05-22T18:24:00.995Z,1337711040.995 [Default] Stopped
2012-05-22T18:24:00.995Z,1337711040.995 [Default](INFO): Aggregate::uninitialize Default
2012-05-22T18:24:00.995Z,1337711040.995 [Default:Iridium] Stopped
2012-05-22T18:24:00.995Z,1337711040.995 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2012-05-22T18:24:00.995Z,1337711040.995 [Default:Iridium:A.SetSpeed] Stopped
2012-05-22T18:24:00.996Z,1337711040.996 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2012-05-22T18:24:00.996Z,1337711040.996 [Default:Iridium:Read_Iridium] Stopped
2012-05-22T18:24:00.996Z,1337711040.996 [Default:CallIridium] Stopped
2012-05-22T18:24:00.996Z,1337711040.996 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2012-05-22T18:24:00.996Z,1337711040.996 [Default:CallIridium:B] Stopped
2012-05-22T18:24:00.996Z,1337711040.996 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2012-05-22T18:24:00.996Z,1337711040.996 [Default:D.SetSpeed] Stopped
2012-05-22T18:24:00.996Z,1337711040.996 [Default:D.SetSpeed](DEBUG): Uninitialize.
2012-05-22T18:24:00.996Z,1337711040.996 [Default:E.GoToSurface] Stopped
2012-05-22T18:24:00.996Z,1337711040.996 [Default:E.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-05-22T18:24:01.000Z,1337711041.000 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2012-05-22T18:24:01.001Z,1337711041.001 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2012-05-22T18:24:01.001Z,1337711041.001 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2012-05-22T18:24:01.001Z,1337711041.001 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2012-05-22T18:24:01.002Z,1337711041.002 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2012-05-22T18:24:01.002Z,1337711041.002 [BuoyancyServo](INFO): Powering down
2012-05-22T18:24:01.002Z,1337711041.002 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2012-05-22T18:24:01.002Z,1337711041.002 [ElevatorServo](INFO): Powering down
2012-05-22T18:24:01.003Z,1337711041.003 [MassServo](DEBUG): Uninitialize Mass Servo.
2012-05-22T18:24:01.003Z,1337711041.003 [MassServo](INFO): Powering down
2012-05-22T18:24:01.003Z,1337711041.003 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2012-05-22T18:24:01.003Z,1337711041.003 [RudderServo](INFO): Powering down
2012-05-22T18:24:01.004Z,1337711041.004 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2012-05-22T18:24:01.004Z,1337711041.004 [ThrusterServo](INFO): Powering down
2012-05-22T18:24:01.004Z,1337711041.004 [SBIT](DEBUG): Uninitialize SBIT Component.
2012-05-22T18:24:01.004Z,1337711041.004 [IBIT](DEBUG): Uninitialize IBIT Component.
2012-05-22T18:24:01.005Z,1337711041.005 [CBIT](DEBUG): Uninitialize CBIT Component.