2013-10-31T19:40:17.549Z,1383248417.549 [Supervisor](DEBUG): Initializing supervisor. 2013-10-31T19:40:17.551Z,1383248417.551 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0 2013-10-31T19:40:17.552Z,1383248417.552 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2013-10-31T19:40:17.553Z,1383248417.553 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0 2013-10-31T19:40:17.556Z,1383248417.556 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2013-10-31T19:40:17.567Z,1383248417.567 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2013-10-31T19:40:17.568Z,1383248417.568 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0 2013-10-31T19:40:17.569Z,1383248417.569 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2013-10-31T19:40:17.570Z,1383248417.570 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0 2013-10-31T19:40:17.571Z,1383248417.571 [Supervisor](INFO): Looking for Config files in directory: Config/ 2013-10-31T19:40:17.575Z,1383248417.575 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2013-10-31T19:40:18.030Z,1383248418.030 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2013-10-31T19:40:18.031Z,1383248418.031 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2013-10-31T19:40:18.226Z,1383248418.226 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2013-10-31T19:40:18.227Z,1383248418.227 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2013-10-31T19:40:18.315Z,1383248418.315 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2013-10-31T19:40:18.316Z,1383248418.316 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2013-10-31T19:40:18.432Z,1383248418.432 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2013-10-31T19:40:18.433Z,1383248418.433 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2013-10-31T19:40:18.576Z,1383248418.576 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2013-10-31T19:40:18.577Z,1383248418.577 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2013-10-31T19:40:18.826Z,1383248418.826 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2013-10-31T19:40:18.827Z,1383248418.827 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2013-10-31T19:40:19.001Z,1383248419.001 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2013-10-31T19:40:19.002Z,1383248419.002 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2013-10-31T19:40:19.322Z,1383248419.322 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2013-10-31T19:40:19.323Z,1383248419.323 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2013-10-31T19:40:19.427Z,1383248419.427 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2013-10-31T19:40:19.428Z,1383248419.428 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2013-10-31T19:40:19.856Z,1383248419.856 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2013-10-31T19:40:19.857Z,1383248419.857 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2013-10-31T19:40:19.971Z,1383248419.971 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2013-10-31T19:40:19.972Z,1383248419.972 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2013-10-31T19:40:20.060Z,1383248420.060 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2013-10-31T19:40:20.061Z,1383248420.061 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2013-10-31T19:40:20.162Z,1383248420.162 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2013-10-31T19:40:20.291Z,1383248420.291 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2013-10-31T19:40:20.389Z,1383248420.389 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2013-10-31T19:40:20.497Z,1383248420.497 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2013-10-31T19:40:20.595Z,1383248420.595 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2013-10-31T19:40:20.714Z,1383248420.714 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2013-10-31T19:40:20.812Z,1383248420.812 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2013-10-31T19:40:20.901Z,1383248420.901 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/LOGIN/ 2013-10-31T19:40:20.902Z,1383248420.902 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2013-10-31T19:40:20.903Z,1383248420.903 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2013-10-31T19:40:21.070Z,1383248421.070 [InternalSim] Loaded 2013-10-31T19:40:21.070Z,1383248421.070 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread. 2013-10-31T19:40:21.071Z,1383248421.071 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2013-10-31T19:40:21.071Z,1383248421.071 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2013-10-31T19:40:21.159Z,1383248421.159 [SBIT](DEBUG): Construct Startup Built In Test. 2013-10-31T19:40:21.188Z,1383248421.188 [SBIT] Loaded 2013-10-31T19:40:21.189Z,1383248421.189 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2013-10-31T19:40:21.189Z,1383248421.189 [IBIT](DEBUG): Construct Initiated Built In Test. 2013-10-31T19:40:21.219Z,1383248421.219 [IBIT] Loaded 2013-10-31T19:40:21.220Z,1383248421.220 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2013-10-31T19:40:21.222Z,1383248421.222 [CBIT](DEBUG): Construct CBIT Built In Test. 2013-10-31T19:40:21.340Z,1383248421.340 [CBIT] Loaded 2013-10-31T19:40:21.340Z,1383248421.340 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2013-10-31T19:40:21.341Z,1383248421.341 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2013-10-31T19:40:21.341Z,1383248421.341 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2013-10-31T19:40:21.511Z,1383248421.511 [BuoyancyServo] Loaded 2013-10-31T19:40:21.511Z,1383248421.511 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2013-10-31T19:40:21.523Z,1383248421.523 [ElevatorServo] Loaded 2013-10-31T19:40:21.524Z,1383248421.524 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2013-10-31T19:40:21.535Z,1383248421.535 [MassServo] Loaded 2013-10-31T19:40:21.536Z,1383248421.536 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2013-10-31T19:40:21.547Z,1383248421.547 [RudderServo] Loaded 2013-10-31T19:40:21.548Z,1383248421.548 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2013-10-31T19:40:21.559Z,1383248421.559 [ThrusterServo] Loaded 2013-10-31T19:40:21.559Z,1383248421.559 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2013-10-31T19:40:21.559Z,1383248421.559 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2013-10-31T19:40:21.560Z,1383248421.560 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2013-10-31T19:40:21.595Z,1383248421.595 [DepthRateCalculator] Loaded 2013-10-31T19:40:21.595Z,1383248421.595 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2013-10-31T19:40:24.157Z,1383248424.157 [HFRadarModelCalc] Loaded 2013-10-31T19:40:24.157Z,1383248424.157 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread. 2013-10-31T19:40:24.173Z,1383248424.173 [NavChart] Loaded 2013-10-31T19:40:24.174Z,1383248424.174 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2013-10-31T19:40:24.179Z,1383248424.179 [PitchRateCalculator] Loaded 2013-10-31T19:40:24.180Z,1383248424.180 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2013-10-31T19:40:24.191Z,1383248424.191 [SpeedCalculator] Loaded 2013-10-31T19:40:24.191Z,1383248424.191 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2013-10-31T19:40:24.208Z,1383248424.208 [TempGradientCalculator] Loaded 2013-10-31T19:40:24.208Z,1383248424.208 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2013-10-31T19:40:24.214Z,1383248424.214 [YawRateCalculator] Loaded 2013-10-31T19:40:24.214Z,1383248424.214 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2013-10-31T19:40:24.262Z,1383248424.262 [Navigation] Loaded 2013-10-31T19:40:24.262Z,1383248424.262 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread. 2013-10-31T19:40:24.263Z,1383248424.263 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2013-10-31T19:40:24.263Z,1383248424.263 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2013-10-31T19:40:24.514Z,1383248424.514 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2013-10-31T19:40:24.514Z,1383248424.514 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2013-10-31T19:40:24.542Z,1383248424.542 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2013-10-31T19:40:24.542Z,1383248424.542 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2013-10-31T19:40:24.590Z,1383248424.590 [VerticalControl](DEBUG): Construct VerticalControl. 2013-10-31T19:40:24.687Z,1383248424.687 [VerticalControl] Loaded 2013-10-31T19:40:24.687Z,1383248424.687 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2013-10-31T19:40:24.688Z,1383248424.688 [HorizontalControl](DEBUG): Construct HorizontalControl. 2013-10-31T19:40:24.746Z,1383248424.746 [HorizontalControl] Loaded 2013-10-31T19:40:24.747Z,1383248424.747 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2013-10-31T19:40:24.747Z,1383248424.747 [SpeedControl](DEBUG): Construct SpeedControl. 2013-10-31T19:40:24.749Z,1383248424.749 [SpeedControl] Loaded 2013-10-31T19:40:24.749Z,1383248424.749 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2013-10-31T19:40:24.750Z,1383248424.750 [LoopControl](DEBUG): Construct LoopControl. 2013-10-31T19:40:24.751Z,1383248424.751 [LoopControl] Loaded 2013-10-31T19:40:24.751Z,1383248424.751 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2013-10-31T19:40:24.751Z,1383248424.751 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2013-10-31T19:40:24.752Z,1383248424.752 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2013-10-31T19:40:24.758Z,1383248424.758 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator. 2013-10-31T19:40:24.763Z,1383248424.763 [AsyncPiEstimator] Loaded 2013-10-31T19:40:24.763Z,1383248424.763 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread. 2013-10-31T19:40:24.764Z,1383248424.764 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406474E0 2013-10-31T19:40:24.765Z,1383248424.765 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2013-10-31T19:40:24.765Z,1383248424.765 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2013-10-31T19:40:24.971Z,1383248424.971 [AHRS_sp3003D] Loaded 2013-10-31T19:40:24.971Z,1383248424.971 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread. 2013-10-31T19:40:24.985Z,1383248424.985 [Depth_Keller] Loaded 2013-10-31T19:40:24.985Z,1383248424.985 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2013-10-31T19:40:25.175Z,1383248425.175 [DVL_micro] Loaded 2013-10-31T19:40:25.175Z,1383248425.175 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread. 2013-10-31T19:40:25.176Z,1383248425.176 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 406D64E0 2013-10-31T19:40:25.268Z,1383248425.268 [NAL9602] Loaded 2013-10-31T19:40:25.268Z,1383248425.268 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2013-10-31T19:40:25.310Z,1383248425.310 [Onboard] Loaded 2013-10-31T19:40:25.310Z,1383248425.310 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2013-10-31T19:40:25.317Z,1383248425.317 [Radio_Freewave] Loaded 2013-10-31T19:40:25.317Z,1383248425.317 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread. 2013-10-31T19:40:25.466Z,1383248425.466 [DAT] Loaded 2013-10-31T19:40:25.467Z,1383248425.467 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2013-10-31T19:40:25.467Z,1383248425.467 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2013-10-31T19:40:25.468Z,1383248425.468 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2013-10-31T19:40:25.571Z,1383248425.571 [CTD_NeilBrown] Loaded 2013-10-31T19:40:25.571Z,1383248425.571 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2013-10-31T19:40:25.572Z,1383248425.572 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 407334E0 2013-10-31T19:40:25.606Z,1383248425.606 [WetLabsBB2FL] Loaded 2013-10-31T19:40:25.606Z,1383248425.606 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2013-10-31T19:40:25.607Z,1383248425.607 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407634E0 2013-10-31T19:40:25.608Z,1383248425.608 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2013-10-31T19:40:25.610Z,1383248425.610 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2013-10-31T19:40:25.611Z,1383248425.611 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2013-10-31T19:40:25.618Z,1383248425.618 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2013-10-31T19:40:25.619Z,1383248425.619 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 407934E0 2013-10-31T19:40:25.624Z,1383248425.624 [Supervisor](DEBUG): Running supervisor. 2013-10-31T19:40:25.625Z,1383248425.625 [CommandLine](INFO): Thread ID is 6806 2013-10-31T19:40:25.627Z,1383248425.627 [controlThread](INFO): Thread ID is 6805 2013-10-31T19:40:25.627Z,1383248425.627 [controlThread](DEBUG): Initializing ControlThread 2013-10-31T19:40:25.628Z,1383248425.628 [CycleStarter](INFO): Thread ID is 6804 2013-10-31T19:40:25.628Z,1383248425.628 [InternalSim](DEBUG): InternalSim initializing... 2013-10-31T19:40:25.665Z,1383248425.665 [logger](INFO): Thread ID is 6807 2013-10-31T19:40:25.689Z,1383248425.689 [SBIT](INFO): Initialize SBIT Component. 2013-10-31T19:40:25.689Z,1383248425.689 [SBIT](IMPORTANT): Tethys CM Info: $Rev:10711 2013-10-31T19:40:25.689Z,1383248425.689 [SBIT](IMPORTANT): Kernel Release:2.6.27.8 2013-10-31T19:40:25.690Z,1383248425.690 [SBIT](IMPORTANT): Kernel Version:#634 PREEMPT Wed Feb 13 10:21:48 PST 2013 2013-10-31T19:40:25.690Z,1383248425.690 [IBIT](INFO): Initialize IBIT Component. 2013-10-31T19:40:25.691Z,1383248425.691 [CBIT](DEBUG): Initialize CBIT Component. 2013-10-31T19:40:25.691Z,1383248425.691 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2013-10-31T19:40:25.705Z,1383248425.705 [AsyncPiEstimator](INFO): Thread ID is 6868 2013-10-31T19:40:25.705Z,1383248425.705 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator. 2013-10-31T19:40:25.717Z,1383248425.717 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2013-10-31T19:40:25.718Z,1383248425.718 [NavChart](DEBUG): Initialize NavChart Derivation. 2013-10-31T19:40:25.718Z,1383248425.718 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2013-10-31T19:40:25.718Z,1383248425.718 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2013-10-31T19:40:25.719Z,1383248425.719 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2013-10-31T19:40:25.719Z,1383248425.719 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2013-10-31T19:40:25.720Z,1383248425.720 [Navigation](DEBUG): Initializing Navigation. 2013-10-31T19:40:25.721Z,1383248425.721 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2013-10-31T19:40:25.723Z,1383248425.723 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2013-10-31T19:40:25.723Z,1383248425.723 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2013-10-31T19:40:25.724Z,1383248425.724 [LoopControl](DEBUG): Initialize LoopControlComponent. 2013-10-31T19:40:25.733Z,1383248425.733 [DVL_micro](INFO): Thread ID is 6869 2013-10-31T19:40:25.742Z,1383248425.742 [DVL_micro](INFO): Initializing 2013-10-31T19:40:25.742Z,1383248425.742 [DVL_micro](INFO): start:Powering up 2013-10-31T19:40:25.743Z,1383248425.743 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-10-31T19:40:25.743Z,1383248425.743 [DVL_micro](INFO): Cycling power to configure device. 2013-10-31T19:40:25.748Z,1383248425.748 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2013-10-31T19:40:25.754Z,1383248425.754 [CTD_NeilBrown](INFO): Thread ID is 6870 2013-10-31T19:40:25.754Z,1383248425.754 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown. 2013-10-31T19:40:25.756Z,1383248425.756 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4 2013-10-31T19:40:25.789Z,1383248425.789 [WetLabsBB2FL](INFO): Thread ID is 6871 2013-10-31T19:40:25.789Z,1383248425.789 [WetLabsBB2FL](INFO): Powering down 2013-10-31T19:40:25.814Z,1383248425.814 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2013-10-31T19:40:25.821Z,1383248425.821 [NavChartDb](INFO): Thread ID is 6872 2013-10-31T19:40:25.830Z,1383248425.830 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources 2013-10-31T19:40:25.831Z,1383248425.831 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2013-10-31T19:40:25.831Z,1383248425.831 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2013-10-31T19:40:25.831Z,1383248425.831 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2013-10-31T19:40:25.832Z,1383248425.832 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2013-10-31T19:40:25.832Z,1383248425.832 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2013-10-31T19:40:25.832Z,1383248425.832 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2013-10-31T19:40:25.833Z,1383248425.833 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2013-10-31T19:40:25.833Z,1383248425.833 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2013-10-31T19:40:25.855Z,1383248425.855 [MissionManager](DEBUG): 2013-10-31T19:40:25.855Z,1383248425.855 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2013-10-31T19:40:25.948Z,1383248425.948 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool 2013-10-31T19:40:25.950Z,1383248425.950 [Default:GPS:A.SetSpeed](DEBUG): Construct. 2013-10-31T19:40:25.965Z,1383248425.965 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface. 2013-10-31T19:40:26.002Z,1383248426.002 [Default:Iridium:A.SetSpeed](DEBUG): Construct. 2013-10-31T19:40:26.005Z,1383248426.005 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface. 2013-10-31T19:40:26.039Z,1383248426.039 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2013-10-31T19:40:26.062Z,1383248426.062 [Default:D.SetSpeed](DEBUG): Construct. 2013-10-31T19:40:26.065Z,1383248426.065 [Default:E.GoToSurface](DEBUG): Construct GoToSurface. 2013-10-31T19:40:26.094Z,1383248426.094 [Default:F.Wait](DEBUG): Construct Wait. 2013-10-31T19:40:26.106Z,1383248426.106 [MissionManager](DEBUG): 400 400 Burn 300 Dropped drop weight due to communications timeout 5.0 1.0 5 2013-10-31T19:40:26.110Z,1383248426.110 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Depth_Keller,NAL9602,Onboard,Radio_Freewave,DAT,Depth_Keller,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter, 2013-10-31T19:40:26.151Z,1383248426.151 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2013-10-31T19:40:26.164Z,1383248426.164 [Depth_Keller](ERROR): Pressure reading out of range: 1831.078247 decibar 2013-10-31T19:40:26.234Z,1383248426.234 [Radio_Freewave](INFO): Powering up 2013-10-31T19:40:26.244Z,1383248426.244 [DAT](INFO): Powering up 2013-10-31T19:40:26.244Z,1383248426.244 [DAT](DEBUG): Initializing DAT. 2013-10-31T19:40:26.452Z,1383248426.452 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2013-10-31T19:40:26.457Z,1383248426.457 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2013-10-31T19:40:26.464Z,1383248426.464 [ElevatorServo](DEBUG): Initializing EZServoServo. 2013-10-31T19:40:26.489Z,1383248426.489 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2013-10-31T19:40:26.502Z,1383248426.502 [MassServo](DEBUG): Initializing EZServoServo. 2013-10-31T19:40:26.510Z,1383248426.510 [MassServo](DEBUG): Initializing MassServo. 2013-10-31T19:40:26.515Z,1383248426.515 [RudderServo](DEBUG): Initializing EZServoServo. 2013-10-31T19:40:26.517Z,1383248426.517 [RudderServo](DEBUG): Initializing RudderServo. 2013-10-31T19:40:26.523Z,1383248426.523 [ThrusterServo](DEBUG): Initializing EZServoServo. 2013-10-31T19:40:26.529Z,1383248426.529 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2013-10-31T19:40:27.848Z,1383248427.848 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-10-31T19:40:27.848Z,1383248427.848 [DVL_micro](INFO): Querying output modes 2013-10-31T19:40:27.848Z,1383248427.848 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606 2013-10-31T19:40:27.859Z,1383248427.859 [DVL_micro](DEBUG): cmdResponse: 01 2013-10-31T19:40:27.860Z,1383248427.860 [DVL_micro](INFO): NQ1 output enabled 2013-10-31T19:40:27.860Z,1383248427.860 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525 2013-10-31T19:40:27.872Z,1383248427.872 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 2013-10-31T19:40:27.877Z,1383248427.877 [DVL_micro](INFO): pause:Powering down 2013-10-31T19:40:30.353Z,1383248430.353 [NAL9602](INFO): Powering up NAL9602 2013-10-31T19:40:40.974Z,1383248440.974 [NAL9602](INFO): NAL9602 initialized 2013-10-31T19:40:41.454Z,1383248441.454 [SBIT](IMPORTANT): Beginning Startup BIT 2013-10-31T19:40:41.457Z,1383248441.457 [CBIT](IMPORTANT): Beginning GF scan 2013-10-31T19:40:45.891Z,1383248445.891 [DAT](INFO): Init failed - response: 2013-10-31T19:40:45.891Z,1383248445.891 [DAT](FAULT): DAT failed to initialize 2013-10-31T19:40:45.892Z,1383248445.892 [DAT] Communications Fault, FailCount= 1 2013-10-31T19:40:45.892Z,1383248445.892 [DAT](ERROR): Communications Fault 2013-10-31T19:40:46.091Z,1383248446.091 [CBIT](ERROR): Communications Fault in component: DAT 2013-10-31T19:40:46.451Z,1383248446.451 [DAT](INFO): Powering down 2013-10-31T19:40:47.805Z,1383248447.805 [CBIT](INFO): Clearing failed state for component DAT 2013-10-31T19:40:47.805Z,1383248447.805 [DAT] No Fault, FailCount= 1 2013-10-31T19:40:49.909Z,1383248449.909 [DAT](INFO): Powering up 2013-10-31T19:40:49.911Z,1383248449.911 [DAT](DEBUG): Initializing DAT. 2013-10-31T19:41:08.010Z,1383248468.010 [CBIT](IMPORTANT): No ground fault detected 2013-10-31T19:41:10.204Z,1383248470.204 [DAT](INFO): Powering down 2013-10-31T19:41:28.920Z,1383248488.920 [NAL9602](IMPORTANT): GPS fix at: 1383248510.00 2013-10-31T19:41:35.100Z,1383248495.100 [SBIT](IMPORTANT): SBIT PASSED 2013-10-31T19:41:35.492Z,1383248495.492 [MissionManager](IMPORTANT): Started mission Startup 2013-10-31T19:41:35.492Z,1383248495.492 [Startup] Running Loop=1 2013-10-31T19:41:35.492Z,1383248495.492 [Startup](INFO): Aggregate::initialize Startup 2013-10-31T19:41:35.492Z,1383248495.492 [Startup:A.GoToSurface] Running Loop=1 2013-10-31T19:41:35.492Z,1383248495.492 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-10-31T19:41:35.498Z,1383248495.498 [Startup:StartupSatComms] Running Loop=1 2013-10-31T19:41:35.498Z,1383248495.498 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms 2013-10-31T19:41:35.498Z,1383248495.498 [Startup:StartupSatComms:A] Running Loop=1 2013-10-31T19:41:35.897Z,1383248495.897 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2013-10-31T19:41:38.056Z,1383248498.056 [NAL9602](IMPORTANT): GPS fix at: 1383248518.00 2013-10-31T19:41:38.096Z,1383248498.096 [Startup:StartupSatComms:A] Stopped 2013-10-31T19:41:38.096Z,1383248498.096 [Startup:StartupSatComms:B] Running Loop=1 2013-10-31T19:41:38.532Z,1383248498.532 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2013-10-31T19:42:24.076Z,1383248544.076 [NAL9602](INFO): SBD MO Status=2, MOMSN=20388, MT Status=2, MTMSN=0 2013-10-31T19:42:24.076Z,1383248544.076 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T19:42:24.076Z,1383248544.076 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T19:42:38.297Z,1383248558.297 [Startup:StartupSatComms:B](INFO): Timed out from 2013-10-31T19:41:38.1Z 2013-10-31T19:42:38.297Z,1383248558.297 [Startup:StartupSatComms:B:A_Timeout] Running Loop=1 2013-10-31T19:42:38.297Z,1383248558.297 [Startup:StartupSatComms:B:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:B:A_Timeout 2013-10-31T19:42:38.298Z,1383248558.298 [Startup:StartupSatComms:B:A_Timeout](INFO): Completed Startup:StartupSatComms:B:A_Timeout 2013-10-31T19:42:38.298Z,1383248558.298 [Startup:StartupSatComms:B] Stopped 2013-10-31T19:42:38.298Z,1383248558.298 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2013-10-31T19:42:38.298Z,1383248558.298 [Startup:StartupSatComms] Stopped 2013-10-31T19:42:38.298Z,1383248558.298 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms 2013-10-31T19:42:38.299Z,1383248558.299 [Startup](INFO): Completed Startup 2013-10-31T19:42:38.299Z,1383248558.299 [Startup] Stopped 2013-10-31T19:42:38.299Z,1383248558.299 [Startup](INFO): Aggregate::uninitialize Startup 2013-10-31T19:42:38.299Z,1383248558.299 [Startup:A.GoToSurface] Stopped 2013-10-31T19:42:38.299Z,1383248558.299 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-10-31T19:42:38.693Z,1383248558.693 [MissionManager](IMPORTANT): Started mission Default 2013-10-31T19:42:38.693Z,1383248558.693 [Default] Running Loop=1 2013-10-31T19:42:38.693Z,1383248558.693 [Default](INFO): Aggregate::initialize Default 2013-10-31T19:42:38.693Z,1383248558.693 [Default:D.SetSpeed] Running Loop=1 2013-10-31T19:42:38.693Z,1383248558.693 [Default:D.SetSpeed](DEBUG): Initialize. 2013-10-31T19:42:38.693Z,1383248558.693 [Default:E.GoToSurface] Running Loop=1 2013-10-31T19:42:38.693Z,1383248558.693 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-10-31T19:42:38.694Z,1383248558.694 [Default:Iridium] Running Loop=1 2013-10-31T19:42:38.694Z,1383248558.694 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2013-10-31T19:42:38.694Z,1383248558.694 [Default:Iridium:A.SetSpeed] Running Loop=1 2013-10-31T19:42:38.694Z,1383248558.694 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2013-10-31T19:42:38.694Z,1383248558.694 [Default:Iridium:B.GoToSurface] Running Loop=1 2013-10-31T19:42:38.694Z,1383248558.694 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-10-31T19:42:38.695Z,1383248558.695 [Default:E.GoToSurface] Running Loop=1 2013-10-31T19:42:38.700Z,1383248558.700 [Default:D.SetSpeed] Running Loop=1 2013-10-31T19:42:38.705Z,1383248558.705 [Default:CallIridium] Running Loop=1 2013-10-31T19:42:38.705Z,1383248558.705 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2013-10-31T19:42:38.705Z,1383248558.705 [Default:CallIridium:A] Running Loop=1 2013-10-31T19:42:38.709Z,1383248558.709 [Default:CallIridium:A] Stopped 2013-10-31T19:42:38.709Z,1383248558.709 [Default:CallIridium:B] Running Loop=1 2013-10-31T19:42:38.710Z,1383248558.710 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2013-10-31T19:42:38.715Z,1383248558.715 [Default:Iridium:B.GoToSurface] Stopped 2013-10-31T19:42:38.715Z,1383248558.715 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-10-31T19:42:38.715Z,1383248558.715 [Default:Iridium:Read_Iridium] Running Loop=1 2013-10-31T19:42:38.715Z,1383248558.715 [Default:Iridium:A.SetSpeed] Running Loop=1 2013-10-31T19:42:38.720Z,1383248558.720 [Default:GPS] Running Loop=1 2013-10-31T19:42:38.720Z,1383248558.720 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2013-10-31T19:42:38.720Z,1383248558.720 [Default:GPS:A.SetSpeed] Running Loop=1 2013-10-31T19:42:38.720Z,1383248558.720 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2013-10-31T19:42:38.720Z,1383248558.720 [Default:GPS:B.GoToSurface] Running Loop=1 2013-10-31T19:42:38.720Z,1383248558.720 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-10-31T19:42:38.726Z,1383248558.726 [Default:GPS:B.GoToSurface] Stopped 2013-10-31T19:42:38.726Z,1383248558.726 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-10-31T19:42:38.726Z,1383248558.726 [Default:GPS:Read_GPS] Running Loop=1 2013-10-31T19:42:38.735Z,1383248558.735 [Default:GPS:A.SetSpeed] Running Loop=1 2013-10-31T19:42:39.157Z,1383248559.157 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2013-10-31T19:42:39.160Z,1383248559.160 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2013-10-31T19:42:51.779Z,1383248571.779 [NAL9602](INFO): SBD MO Status=2, MOMSN=20388, MT Status=2, MTMSN=0 2013-10-31T19:42:51.780Z,1383248571.780 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T19:42:51.780Z,1383248571.780 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T19:42:52.977Z,1383248572.977 [NAL9602](IMPORTANT): GPS fix at: 1383248594.00 2013-10-31T19:42:52.993Z,1383248572.993 [Default:GPS:Read_GPS] Stopped 2013-10-31T19:42:52.993Z,1383248572.993 [Default:GPS:D] Running Loop=1 2013-10-31T19:42:53.397Z,1383248573.397 [Default:GPS:D] Stopped 2013-10-31T19:42:53.398Z,1383248573.398 [Default:GPS](INFO): Completed Default:GPS 2013-10-31T19:42:53.398Z,1383248573.398 [Default:GPS] Stopped 2013-10-31T19:42:53.398Z,1383248573.398 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2013-10-31T19:42:53.398Z,1383248573.398 [Default:GPS:A.SetSpeed] Stopped 2013-10-31T19:42:53.398Z,1383248573.398 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2013-10-31T19:43:09.180Z,1383248589.180 [NAL9602](INFO): SBD MO Status=2, MOMSN=20388, MT Status=2, MTMSN=0 2013-10-31T19:43:09.180Z,1383248589.180 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T19:43:09.180Z,1383248589.180 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T19:43:17.465Z,1383248597.465 [NAL9602](INFO): SBD MO Status=2, MOMSN=20388, MT Status=2, MTMSN=0 2013-10-31T19:43:17.465Z,1383248597.465 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T19:43:17.465Z,1383248597.465 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T19:43:26.078Z,1383248606.078 [NAL9602](INFO): SBD MO Status=2, MOMSN=20388, MT Status=2, MTMSN=0 2013-10-31T19:43:26.078Z,1383248606.078 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T19:43:26.078Z,1383248606.078 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T19:43:35.060Z,1383248615.060 [NAL9602](INFO): SBD MO Status=2, MOMSN=20388, MT Status=2, MTMSN=0 2013-10-31T19:43:35.060Z,1383248615.060 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T19:43:35.060Z,1383248615.060 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T19:43:43.613Z,1383248623.613 [NAL9602](INFO): SBD MO Status=2, MOMSN=20388, MT Status=2, MTMSN=0 2013-10-31T19:43:43.613Z,1383248623.613 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T19:43:43.614Z,1383248623.614 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T19:43:52.259Z,1383248632.259 [NAL9602](INFO): SBD MO Status=2, MOMSN=20388, MT Status=2, MTMSN=0 2013-10-31T19:43:52.259Z,1383248632.259 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T19:43:52.259Z,1383248632.259 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T19:44:00.848Z,1383248640.848 [NAL9602](INFO): SBD MO Status=2, MOMSN=20388, MT Status=2, MTMSN=0 2013-10-31T19:44:00.848Z,1383248640.848 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T19:44:00.848Z,1383248640.848 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T19:44:17.065Z,1383248657.065 [NAL9602](INFO): SBD MO Status=2, MOMSN=20388, MT Status=2, MTMSN=0 2013-10-31T19:44:17.066Z,1383248657.066 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T19:44:17.066Z,1383248657.066 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T19:44:25.726Z,1383248665.726 [NAL9602](INFO): SBD MO Status=2, MOMSN=20388, MT Status=2, MTMSN=0 2013-10-31T19:44:25.727Z,1383248665.727 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T19:44:25.727Z,1383248665.727 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T19:44:34.356Z,1383248674.356 [NAL9602](INFO): SBD MO Status=2, MOMSN=20388, MT Status=2, MTMSN=0 2013-10-31T19:44:34.356Z,1383248674.356 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T19:44:34.356Z,1383248674.356 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T19:44:42.961Z,1383248682.961 [NAL9602](INFO): SBD MO Status=2, MOMSN=20388, MT Status=2, MTMSN=0 2013-10-31T19:44:42.961Z,1383248682.961 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T19:44:42.962Z,1383248682.962 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T19:44:51.983Z,1383248691.983 [NAL9602](INFO): SBD MO Status=2, MOMSN=20388, MT Status=2, MTMSN=0 2013-10-31T19:44:51.983Z,1383248691.983 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T19:44:51.983Z,1383248691.983 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T19:45:04.951Z,1383248704.951 [NAL9602](INFO): SBD MO Status=1, MOMSN=20388, MT Status=0, MTMSN=0 2013-10-31T19:45:05.001Z,1383248705.001 [NAL9602](INFO): Sent 163 bytes from file Logs/20131031T151102/Courier0012.lzma 2013-10-31T19:45:05.002Z,1383248705.002 [NAL9602](INFO): Packets left to send: 0 2013-10-31T19:45:05.004Z,1383248705.004 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T151102/Courier0012.lzma.parts/0000.sbd 2013-10-31T19:45:13.348Z,1383248713.348 [NAL9602](INFO): SBD MO Status=2, MOMSN=20389, MT Status=2, MTMSN=0 2013-10-31T19:45:13.348Z,1383248713.348 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T19:45:13.349Z,1383248713.349 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T19:45:24.059Z,1383248724.059 [NAL9602](INFO): SBD MO Status=2, MOMSN=20389, MT Status=2, MTMSN=0 2013-10-31T19:45:24.060Z,1383248724.060 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T19:45:24.060Z,1383248724.060 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T19:45:32.650Z,1383248732.650 [NAL9602](INFO): SBD MO Status=2, MOMSN=20389, MT Status=2, MTMSN=0 2013-10-31T19:45:32.650Z,1383248732.650 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T19:45:32.650Z,1383248732.650 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T19:45:40.960Z,1383248740.960 [NAL9602](INFO): SBD MO Status=2, MOMSN=20389, MT Status=2, MTMSN=0 2013-10-31T19:45:40.960Z,1383248740.960 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T19:45:40.960Z,1383248740.960 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T19:45:49.552Z,1383248749.552 [NAL9602](INFO): SBD MO Status=2, MOMSN=20389, MT Status=2, MTMSN=0 2013-10-31T19:45:49.553Z,1383248749.553 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T19:45:49.553Z,1383248749.553 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T19:45:58.566Z,1383248758.566 [NAL9602](INFO): SBD MO Status=2, MOMSN=20389, MT Status=2, MTMSN=0 2013-10-31T19:45:58.566Z,1383248758.566 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T19:45:58.567Z,1383248758.567 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T19:46:06.755Z,1383248766.755 [NAL9602](INFO): SBD MO Status=2, MOMSN=20389, MT Status=2, MTMSN=0 2013-10-31T19:46:06.755Z,1383248766.755 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T19:46:06.755Z,1383248766.755 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T19:46:15.356Z,1383248775.356 [NAL9602](INFO): SBD MO Status=2, MOMSN=20389, MT Status=2, MTMSN=0 2013-10-31T19:46:15.357Z,1383248775.357 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T19:46:15.357Z,1383248775.357 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T19:46:27.263Z,1383248787.263 [NAL9602](INFO): SBD MO Status=1, MOMSN=20389, MT Status=0, MTMSN=0 2013-10-31T19:46:27.317Z,1383248787.317 [NAL9602](INFO): Sent 193 bytes from file Logs/20131031T151102/Courier0016.lzma 2013-10-31T19:46:27.317Z,1383248787.317 [NAL9602](INFO): Packets left to send: 0 2013-10-31T19:46:27.322Z,1383248787.322 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T151102/Courier0016.lzma.parts/0000.sbd 2013-10-31T19:46:34.911Z,1383248794.911 [NAL9602](INFO): SBD MO Status=2, MOMSN=20390, MT Status=2, MTMSN=0 2013-10-31T19:46:34.911Z,1383248794.911 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T19:46:34.911Z,1383248794.911 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T19:46:54.781Z,1383248814.781 [NAL9602](INFO): SBD MO Status=1, MOMSN=20390, MT Status=0, MTMSN=0 2013-10-31T19:46:54.831Z,1383248814.831 [NAL9602](INFO): Sent 206 bytes from file Logs/20131031T194017/Courier0000.lzma 2013-10-31T19:46:54.832Z,1383248814.832 [NAL9602](INFO): Packets left to send: 0 2013-10-31T19:46:54.833Z,1383248814.833 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T194017/Courier0000.lzma.parts/0000.sbd 2013-10-31T19:47:06.359Z,1383248826.359 [NAL9602](INFO): SBD MO Status=1, MOMSN=20391, MT Status=0, MTMSN=0 2013-10-31T19:47:06.414Z,1383248826.414 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T151102/Express0009.lzma 2013-10-31T19:47:06.414Z,1383248826.414 [NAL9602](INFO): Packets left to send: 5 2013-10-31T19:47:06.415Z,1383248826.415 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T151102/Express0009.lzma.parts/0005.sbd 2013-10-31T19:47:19.277Z,1383248839.277 [NAL9602](INFO): SBD MO Status=1, MOMSN=20392, MT Status=0, MTMSN=0 2013-10-31T19:47:19.325Z,1383248839.325 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T151102/Express0009.lzma 2013-10-31T19:47:19.326Z,1383248839.326 [NAL9602](INFO): Packets left to send: 4 2013-10-31T19:47:19.326Z,1383248839.326 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T151102/Express0009.lzma.parts/0004.sbd 2013-10-31T19:47:32.278Z,1383248852.278 [NAL9602](INFO): SBD MO Status=1, MOMSN=20393, MT Status=0, MTMSN=0 2013-10-31T19:47:32.326Z,1383248852.326 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T151102/Express0009.lzma 2013-10-31T19:47:32.326Z,1383248852.326 [NAL9602](INFO): Packets left to send: 3 2013-10-31T19:47:32.327Z,1383248852.327 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T151102/Express0009.lzma.parts/0003.sbd 2013-10-31T19:47:45.260Z,1383248865.260 [NAL9602](INFO): SBD MO Status=1, MOMSN=20394, MT Status=0, MTMSN=0 2013-10-31T19:47:45.314Z,1383248865.314 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T151102/Express0009.lzma 2013-10-31T19:47:45.314Z,1383248865.314 [NAL9602](INFO): Packets left to send: 2 2013-10-31T19:47:45.315Z,1383248865.315 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T151102/Express0009.lzma.parts/0002.sbd 2013-10-31T19:48:03.073Z,1383248883.073 [NAL9602](INFO): SBD MO Status=1, MOMSN=20395, MT Status=0, MTMSN=0 2013-10-31T19:48:03.121Z,1383248883.121 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T151102/Express0009.lzma 2013-10-31T19:48:03.122Z,1383248883.122 [NAL9602](INFO): Packets left to send: 1 2013-10-31T19:48:03.123Z,1383248883.123 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T151102/Express0009.lzma.parts/0001.sbd 2013-10-31T19:48:27.273Z,1383248907.273 [NAL9602](INFO): SBD MO Status=1, MOMSN=20396, MT Status=0, MTMSN=0 2013-10-31T19:48:27.323Z,1383248907.323 [NAL9602](INFO): Sent 275 bytes from file Logs/20131031T151102/Express0009.lzma 2013-10-31T19:48:27.323Z,1383248907.323 [NAL9602](INFO): Packets left to send: 0 2013-10-31T19:48:27.324Z,1383248907.324 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T151102/Express0009.lzma.parts/0000.sbd 2013-10-31T19:48:39.279Z,1383248919.279 [NAL9602](INFO): SBD MO Status=1, MOMSN=20397, MT Status=0, MTMSN=0 2013-10-31T19:48:39.329Z,1383248919.329 [NAL9602](INFO): Sent 151 bytes from file Logs/20131031T151102/Express0013.lzma 2013-10-31T19:48:39.330Z,1383248919.330 [NAL9602](INFO): Packets left to send: 0 2013-10-31T19:48:39.331Z,1383248919.331 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T151102/Express0013.lzma.parts/0000.sbd 2013-10-31T19:49:08.501Z,1383248948.501 [NAL9602](INFO): SBD MO Status=2, MOMSN=20398, MT Status=2, MTMSN=0 2013-10-31T19:49:08.501Z,1383248948.501 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T19:49:08.501Z,1383248948.501 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T19:49:50.698Z,1383248990.698 [NAL9602](INFO): SBD MO Status=1, MOMSN=20398, MT Status=0, MTMSN=0 2013-10-31T19:49:50.748Z,1383248990.748 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T151102/Express0017.lzma 2013-10-31T19:49:50.749Z,1383248990.749 [NAL9602](INFO): Packets left to send: 1 2013-10-31T19:49:50.750Z,1383248990.750 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T151102/Express0017.lzma.parts/0001.sbd 2013-10-31T19:50:02.857Z,1383249002.857 [NAL9602](INFO): SBD MO Status=1, MOMSN=20399, MT Status=0, MTMSN=0 2013-10-31T19:50:02.911Z,1383249002.911 [NAL9602](INFO): Sent 105 bytes from file Logs/20131031T151102/Express0017.lzma 2013-10-31T19:50:02.911Z,1383249002.911 [NAL9602](INFO): Packets left to send: 0 2013-10-31T19:50:02.913Z,1383249002.913 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T151102/Express0017.lzma.parts/0000.sbd 2013-10-31T19:50:35.261Z,1383249035.261 [NAL9602](INFO): SBD MO Status=2, MOMSN=20400, MT Status=2, MTMSN=0 2013-10-31T19:50:35.262Z,1383249035.262 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T19:50:35.262Z,1383249035.262 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T19:52:39.260Z,1383249159.260 [NAL9602](INFO): SBD MO Status=1, MOMSN=20400, MT Status=0, MTMSN=0 2013-10-31T19:52:39.310Z,1383249159.310 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T194017/Express0001.lzma 2013-10-31T19:52:39.310Z,1383249159.310 [NAL9602](INFO): Packets left to send: 2 2013-10-31T19:52:39.312Z,1383249159.312 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T194017/Express0001.lzma.parts/0002.sbd 2013-10-31T19:53:00.192Z,1383249180.192 [NAL9602](INFO): SBD MO Status=1, MOMSN=20401, MT Status=0, MTMSN=0 2013-10-31T19:53:00.242Z,1383249180.242 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T194017/Express0001.lzma 2013-10-31T19:53:00.242Z,1383249180.242 [NAL9602](INFO): Packets left to send: 1 2013-10-31T19:53:00.243Z,1383249180.243 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T194017/Express0001.lzma.parts/0001.sbd 2013-10-31T19:53:07.577Z,1383249187.577 [NAL9602](INFO): SBD MO Status=1, MOMSN=20402, MT Status=0, MTMSN=0 2013-10-31T19:53:07.626Z,1383249187.626 [NAL9602](INFO): Sent 27 bytes from file Logs/20131031T194017/Express0001.lzma 2013-10-31T19:53:07.626Z,1383249187.626 [NAL9602](INFO): Packets left to send: 0 2013-10-31T19:53:07.627Z,1383249187.627 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T194017/Express0001.lzma.parts/0000.sbd 2013-10-31T19:53:18.156Z,1383249198.156 [NAL9602](INFO): SBD MO Status=0, MOMSN=20403, MT Status=0, MTMSN=0 2013-10-31T19:53:21.918Z,1383249201.918 [Default:Iridium:Read_Iridium] Stopped 2013-10-31T19:53:21.919Z,1383249201.919 [Default:Iridium](INFO): Completed Default:Iridium 2013-10-31T19:53:21.919Z,1383249201.919 [Default:Iridium] Stopped 2013-10-31T19:53:21.919Z,1383249201.919 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2013-10-31T19:53:21.919Z,1383249201.919 [Default:Iridium:A.SetSpeed] Stopped 2013-10-31T19:53:21.919Z,1383249201.919 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2013-10-31T19:53:21.919Z,1383249201.919 [Default:F.Wait] Running Loop=1 2013-10-31T19:53:21.919Z,1383249201.919 [Default:F.Wait](DEBUG): Initialize Wait Component. 2013-10-31T19:53:22.414Z,1383249202.414 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2013-10-31T19:53:22.414Z,1383249202.414 [Default:CallIridium:B] Stopped 2013-10-31T19:53:22.414Z,1383249202.414 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2013-10-31T19:53:22.414Z,1383249202.414 [Default:CallIridium](INFO): Completed Default:CallIridium 2013-10-31T19:53:22.414Z,1383249202.414 [Default:CallIridium] Stopped 2013-10-31T19:53:22.415Z,1383249202.415 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2013-10-31T19:53:27.352Z,1383249207.352 [Depth_Keller](ERROR): Pressure reading out of range: 1830.564087 decibar 2013-10-31T19:53:32.342Z,1383249212.342 [NAL9602](INFO): Powering down 2013-10-31T19:53:47.343Z,1383249227.343 [Depth_Keller](ERROR): Pressure reading out of range: 1830.558838 decibar 2013-10-31T19:53:57.347Z,1383249237.347 [Depth_Keller](ERROR): Pressure reading out of range: 1830.584229 decibar 2013-10-31T19:54:07.355Z,1383249247.355 [Depth_Keller](ERROR): Pressure reading out of range: 1830.558838 decibar 2013-10-31T19:54:17.350Z,1383249257.350 [Depth_Keller](ERROR): Pressure reading out of range: 1830.556274 decibar 2013-10-31T19:54:27.345Z,1383249267.345 [Depth_Keller](ERROR): Pressure reading out of range: 1830.572876 decibar 2013-10-31T19:54:37.345Z,1383249277.345 [Depth_Keller](ERROR): Pressure reading out of range: 1830.551025 decibar 2013-10-31T19:54:47.340Z,1383249287.340 [Depth_Keller](ERROR): Pressure reading out of range: 1830.551880 decibar 2013-10-31T19:54:57.346Z,1383249297.346 [Depth_Keller](ERROR): Pressure reading out of range: 1830.552734 decibar 2013-10-31T19:55:07.347Z,1383249307.347 [Depth_Keller](ERROR): Pressure reading out of range: 1830.581543 decibar 2013-10-31T19:55:17.347Z,1383249317.347 [Depth_Keller](ERROR): Pressure reading out of range: 1830.551880 decibar 2013-10-31T19:55:27.355Z,1383249327.355 [Depth_Keller](ERROR): Pressure reading out of range: 1830.585938 decibar 2013-10-31T19:55:37.354Z,1383249337.354 [Depth_Keller](ERROR): Pressure reading out of range: 1830.573730 decibar 2013-10-31T19:55:47.349Z,1383249347.349 [Depth_Keller](ERROR): Pressure reading out of range: 1830.568481 decibar 2013-10-31T19:55:57.349Z,1383249357.349 [Depth_Keller](ERROR): Pressure reading out of range: 1830.557129 decibar 2013-10-31T19:56:07.352Z,1383249367.352 [Depth_Keller](ERROR): Pressure reading out of range: 1830.578979 decibar 2013-10-31T19:56:17.362Z,1383249377.362 [Depth_Keller](ERROR): Pressure reading out of range: 1830.575439 decibar 2013-10-31T19:56:27.347Z,1383249387.347 [Depth_Keller](ERROR): Pressure reading out of range: 1830.575439 decibar 2013-10-31T19:56:37.359Z,1383249397.359 [Depth_Keller](ERROR): Pressure reading out of range: 1830.594604 decibar 2013-10-31T19:56:47.358Z,1383249407.358 [Depth_Keller](ERROR): Pressure reading out of range: 1830.587646 decibar 2013-10-31T19:56:57.350Z,1383249417.350 [Depth_Keller](ERROR): Pressure reading out of range: 1830.572876 decibar 2013-10-31T19:57:07.345Z,1383249427.345 [Depth_Keller](ERROR): Pressure reading out of range: 1830.562378 decibar 2013-10-31T19:57:17.345Z,1383249437.345 [Depth_Keller](ERROR): Pressure reading out of range: 1830.570190 decibar 2013-10-31T19:57:27.353Z,1383249447.353 [Depth_Keller](ERROR): Pressure reading out of range: 1830.564941 decibar 2013-10-31T19:57:37.348Z,1383249457.348 [Depth_Keller](ERROR): Pressure reading out of range: 1830.563232 decibar 2013-10-31T19:57:47.343Z,1383249467.343 [Depth_Keller](ERROR): Pressure reading out of range: 1830.549316 decibar 2013-10-31T19:57:57.347Z,1383249477.347 [Depth_Keller](ERROR): Pressure reading out of range: 1830.572876 decibar 2013-10-31T19:58:07.358Z,1383249487.358 [Depth_Keller](ERROR): Pressure reading out of range: 1830.552734 decibar 2013-10-31T19:58:17.346Z,1383249497.346 [Depth_Keller](ERROR): Pressure reading out of range: 1830.572876 decibar 2013-10-31T19:58:22.358Z,1383249502.358 [Default:CallIridium] Running Loop=1 2013-10-31T19:58:22.358Z,1383249502.358 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2013-10-31T19:58:22.358Z,1383249502.358 [Default:CallIridium:A] Running Loop=1 2013-10-31T19:58:22.358Z,1383249502.358 [Default:CallIridium:A] Stopped 2013-10-31T19:58:22.359Z,1383249502.359 [Default:CallIridium:B] Running Loop=1 2013-10-31T19:58:22.359Z,1383249502.359 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2013-10-31T19:58:27.349Z,1383249507.349 [Depth_Keller](ERROR): Pressure reading out of range: 1830.558838 decibar 2013-10-31T19:58:27.365Z,1383249507.365 [Default:Iridium] Running Loop=1 2013-10-31T19:58:27.365Z,1383249507.365 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2013-10-31T19:58:27.366Z,1383249507.366 [Default:Iridium:A.SetSpeed] Running Loop=1 2013-10-31T19:58:27.366Z,1383249507.366 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2013-10-31T19:58:27.366Z,1383249507.366 [Default:Iridium:B.GoToSurface] Running Loop=1 2013-10-31T19:58:27.366Z,1383249507.366 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-10-31T19:58:27.367Z,1383249507.367 [Default:Iridium:B.GoToSurface] Stopped 2013-10-31T19:58:27.367Z,1383249507.367 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-10-31T19:58:27.367Z,1383249507.367 [Default:Iridium:Read_Iridium] Running Loop=1 2013-10-31T19:58:27.367Z,1383249507.367 [Default:GPS] Running Loop=1 2013-10-31T19:58:27.367Z,1383249507.367 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2013-10-31T19:58:27.367Z,1383249507.367 [Default:GPS:A.SetSpeed] Running Loop=1 2013-10-31T19:58:27.367Z,1383249507.367 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2013-10-31T19:58:27.368Z,1383249507.368 [Default:GPS:B.GoToSurface] Running Loop=1 2013-10-31T19:58:27.368Z,1383249507.368 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-10-31T19:58:27.368Z,1383249507.368 [Default:GPS:B.GoToSurface] Stopped 2013-10-31T19:58:27.368Z,1383249507.368 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-10-31T19:58:27.368Z,1383249507.368 [Default:GPS:Read_GPS] Running Loop=1 2013-10-31T19:58:28.179Z,1383249508.179 [NAL9602](INFO): Powering up 2013-10-31T19:58:38.631Z,1383249518.631 [NAL9602](INFO): NAL9602 initialized 2013-10-31T19:59:22.555Z,1383249562.555 [NAL9602](INFO): SBD MO Status=1, MOMSN=20404, MT Status=0, MTMSN=0 2013-10-31T19:59:22.611Z,1383249562.611 [NAL9602](INFO): Sent 60 bytes from file Logs/20131031T194017/Courier0004.lzma 2013-10-31T19:59:22.611Z,1383249562.611 [NAL9602](INFO): Packets left to send: 0 2013-10-31T19:59:22.613Z,1383249562.613 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T194017/Courier0004.lzma.parts/0000.sbd 2013-10-31T19:59:34.780Z,1383249574.780 [NAL9602](INFO): SBD MO Status=1, MOMSN=20405, MT Status=0, MTMSN=0 2013-10-31T19:59:34.830Z,1383249574.830 [NAL9602](INFO): Sent 127 bytes from file Logs/20131031T194017/Express0005.lzma 2013-10-31T19:59:34.830Z,1383249574.830 [NAL9602](INFO): Packets left to send: 0 2013-10-31T19:59:34.832Z,1383249574.832 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T194017/Express0005.lzma.parts/0000.sbd 2013-10-31T19:59:43.590Z,1383249583.590 [NAL9602](INFO): SBD MO Status=0, MOMSN=20406, MT Status=0, MTMSN=0 2013-10-31T19:59:47.326Z,1383249587.326 [Default:Iridium:Read_Iridium] Stopped 2013-10-31T19:59:47.327Z,1383249587.327 [Default:Iridium](INFO): Completed Default:Iridium 2013-10-31T19:59:47.327Z,1383249587.327 [Default:Iridium] Stopped 2013-10-31T19:59:47.327Z,1383249587.327 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2013-10-31T19:59:47.327Z,1383249587.327 [Default:Iridium:A.SetSpeed] Stopped 2013-10-31T19:59:47.327Z,1383249587.327 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2013-10-31T19:59:47.792Z,1383249587.792 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2013-10-31T19:59:47.793Z,1383249587.793 [Default:CallIridium:B] Stopped 2013-10-31T19:59:47.793Z,1383249587.793 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2013-10-31T19:59:47.793Z,1383249587.793 [Default:CallIridium](INFO): Completed Default:CallIridium 2013-10-31T19:59:47.793Z,1383249587.793 [Default:CallIridium] Stopped 2013-10-31T19:59:47.793Z,1383249587.793 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2013-10-31T19:59:48.559Z,1383249588.559 [NAL9602](IMPORTANT): GPS fix at: 1383249609.00 2013-10-31T19:59:48.595Z,1383249588.595 [Default:GPS:Read_GPS] Stopped 2013-10-31T19:59:48.596Z,1383249588.596 [Default:GPS:D] Running Loop=1 2013-10-31T19:59:49.001Z,1383249589.001 [Default:GPS:D] Stopped 2013-10-31T19:59:49.002Z,1383249589.002 [Default:GPS](INFO): Completed Default:GPS 2013-10-31T19:59:49.002Z,1383249589.002 [Default:GPS] Stopped 2013-10-31T19:59:49.002Z,1383249589.002 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2013-10-31T19:59:49.002Z,1383249589.002 [Default:GPS:A.SetSpeed] Stopped 2013-10-31T19:59:49.002Z,1383249589.002 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2013-10-31T19:59:54.454Z,1383249594.454 [Depth_Keller](ERROR): Pressure reading out of range: 1372.867676 decibar 2013-10-31T20:00:04.426Z,1383249604.426 [Depth_Keller](ERROR): Pressure reading out of range: 1354.975464 decibar 2013-10-31T20:00:09.445Z,1383249609.445 [NAL9602](INFO): Powering down 2013-10-31T20:00:24.433Z,1383249624.433 [Depth_Keller](ERROR): Pressure reading out of range: 1830.551025 decibar 2013-10-31T20:00:34.428Z,1383249634.428 [Depth_Keller](ERROR): Pressure reading out of range: 1830.548340 decibar 2013-10-31T20:00:44.434Z,1383249644.434 [Radio_Freewave](INFO): Powering down 2013-10-31T20:00:49.426Z,1383249649.426 [Depth_Keller](ERROR): Pressure reading out of range: 1830.579834 decibar 2013-10-31T20:00:49.432Z,1383249649.432 [Radio_Freewave](FAULT): LCB fault: Software Overcurrent. 2013-10-31T20:00:49.432Z,1383249649.432 [Radio_Freewave] Hardware Fault, FailCount= 1 2013-10-31T20:00:49.432Z,1383249649.432 [Radio_Freewave](ERROR): Hardware Fault 2013-10-31T20:00:49.451Z,1383249649.451 [CBIT](ERROR): Hardware Fault in component: Radio_Freewave 2013-10-31T20:00:54.484Z,1383249654.484 [CBIT](INFO): Clearing failed state for component Radio_Freewave 2013-10-31T20:00:54.484Z,1383249654.484 [Radio_Freewave] No Fault, FailCount= 1 2013-10-31T20:00:59.438Z,1383249659.438 [Radio_Freewave](INFO): Powering up 2013-10-31T20:01:09.438Z,1383249669.438 [Radio_Freewave](INFO): Powering down 2013-10-31T20:02:24.437Z,1383249744.437 [Radio_Freewave](INFO): Powering up 2013-10-31T20:02:34.454Z,1383249754.454 [Depth_Keller](ERROR): Pressure reading out of range: 1830.572876 decibar 2013-10-31T20:02:49.436Z,1383249769.436 [Depth_Keller](ERROR): Pressure reading out of range: 1830.538818 decibar 2013-10-31T20:03:24.424Z,1383249804.424 [Depth_Keller](ERROR): Pressure reading out of range: 1830.572876 decibar 2013-10-31T20:04:04.426Z,1383249844.426 [Depth_Keller](ERROR): Pressure reading out of range: 1830.578979 decibar 2013-10-31T20:04:14.425Z,1383249854.425 [Depth_Keller](ERROR): Pressure reading out of range: 1354.979858 decibar 2013-10-31T20:04:24.433Z,1383249864.433 [Depth_Keller](ERROR): Pressure reading out of range: 1830.550171 decibar 2013-10-31T20:04:34.428Z,1383249874.428 [Depth_Keller](ERROR): Pressure reading out of range: 1830.538818 decibar 2013-10-31T20:04:44.424Z,1383249884.424 [Depth_Keller](ERROR): Pressure reading out of range: 1830.564087 decibar 2013-10-31T20:04:44.439Z,1383249884.439 [Default:CallIridium] Running Loop=1 2013-10-31T20:04:44.439Z,1383249884.439 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2013-10-31T20:04:44.440Z,1383249884.440 [Default:CallIridium:A] Running Loop=1 2013-10-31T20:04:44.440Z,1383249884.440 [Default:CallIridium:A] Stopped 2013-10-31T20:04:44.440Z,1383249884.440 [Default:CallIridium:B] Running Loop=1 2013-10-31T20:04:44.440Z,1383249884.440 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2013-10-31T20:04:49.442Z,1383249889.442 [Default:Iridium] Running Loop=1 2013-10-31T20:04:49.442Z,1383249889.442 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2013-10-31T20:04:49.442Z,1383249889.442 [Default:Iridium:A.SetSpeed] Running Loop=1 2013-10-31T20:04:49.442Z,1383249889.442 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2013-10-31T20:04:49.442Z,1383249889.442 [Default:Iridium:B.GoToSurface] Running Loop=1 2013-10-31T20:04:49.442Z,1383249889.442 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-10-31T20:04:49.443Z,1383249889.443 [Default:Iridium:B.GoToSurface] Stopped 2013-10-31T20:04:49.443Z,1383249889.443 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-10-31T20:04:49.443Z,1383249889.443 [Default:Iridium:Read_Iridium] Running Loop=1 2013-10-31T20:04:49.443Z,1383249889.443 [Default:GPS] Running Loop=1 2013-10-31T20:04:49.444Z,1383249889.444 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2013-10-31T20:04:49.444Z,1383249889.444 [Default:GPS:A.SetSpeed] Running Loop=1 2013-10-31T20:04:49.444Z,1383249889.444 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2013-10-31T20:04:49.444Z,1383249889.444 [Default:GPS:B.GoToSurface] Running Loop=1 2013-10-31T20:04:49.444Z,1383249889.444 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-10-31T20:04:49.445Z,1383249889.445 [Default:GPS:B.GoToSurface] Stopped 2013-10-31T20:04:49.445Z,1383249889.445 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-10-31T20:04:49.445Z,1383249889.445 [Default:GPS:Read_GPS] Running Loop=1 2013-10-31T20:04:50.229Z,1383249890.229 [NAL9602](INFO): Powering up 2013-10-31T20:05:00.727Z,1383249900.727 [NAL9602](INFO): NAL9602 initialized 2013-10-31T20:05:23.861Z,1383249923.861 [NAL9602](INFO): SBD MO Status=1, MOMSN=20407, MT Status=0, MTMSN=0 2013-10-31T20:05:23.911Z,1383249923.911 [NAL9602](INFO): Sent 60 bytes from file Logs/20131031T194017/Courier0008.lzma 2013-10-31T20:05:23.911Z,1383249923.911 [NAL9602](INFO): Packets left to send: 0 2013-10-31T20:05:23.913Z,1383249923.913 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T194017/Courier0008.lzma.parts/0000.sbd 2013-10-31T20:05:58.879Z,1383249958.879 [NAL9602](INFO): SBD MO Status=2, MOMSN=20408, MT Status=2, MTMSN=0 2013-10-31T20:05:58.880Z,1383249958.880 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:05:58.880Z,1383249958.880 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:06:00.078Z,1383249960.078 [NAL9602](IMPORTANT): GPS fix at: 1383249981.00 2013-10-31T20:06:00.094Z,1383249960.094 [Default:GPS:Read_GPS] Stopped 2013-10-31T20:06:00.095Z,1383249960.095 [Default:GPS:D] Running Loop=1 2013-10-31T20:06:00.509Z,1383249960.509 [Default:GPS:D] Stopped 2013-10-31T20:06:00.509Z,1383249960.509 [Default:GPS](INFO): Completed Default:GPS 2013-10-31T20:06:00.509Z,1383249960.509 [Default:GPS] Stopped 2013-10-31T20:06:00.509Z,1383249960.509 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2013-10-31T20:06:00.509Z,1383249960.509 [Default:GPS:A.SetSpeed] Stopped 2013-10-31T20:06:00.510Z,1383249960.510 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2013-10-31T20:06:10.679Z,1383249970.679 [NAL9602](INFO): SBD MO Status=1, MOMSN=20408, MT Status=0, MTMSN=0 2013-10-31T20:06:10.728Z,1383249970.728 [NAL9602](INFO): Sent 220 bytes from file Logs/20131031T194017/Express0009.lzma 2013-10-31T20:06:10.728Z,1383249970.728 [NAL9602](INFO): Packets left to send: 0 2013-10-31T20:06:10.730Z,1383249970.730 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T194017/Express0009.lzma.parts/0000.sbd 2013-10-31T20:06:23.274Z,1383249983.274 [NAL9602](INFO): SBD MO Status=0, MOMSN=20409, MT Status=0, MTMSN=0 2013-10-31T20:06:26.841Z,1383249986.841 [Default:Iridium:Read_Iridium] Stopped 2013-10-31T20:06:26.841Z,1383249986.841 [Default:Iridium](INFO): Completed Default:Iridium 2013-10-31T20:06:26.841Z,1383249986.841 [Default:Iridium] Stopped 2013-10-31T20:06:26.842Z,1383249986.842 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2013-10-31T20:06:26.842Z,1383249986.842 [Default:Iridium:A.SetSpeed] Stopped 2013-10-31T20:06:26.842Z,1383249986.842 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2013-10-31T20:06:27.295Z,1383249987.295 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2013-10-31T20:06:27.295Z,1383249987.295 [Default:CallIridium:B] Stopped 2013-10-31T20:06:27.295Z,1383249987.295 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2013-10-31T20:06:27.296Z,1383249987.296 [Default:CallIridium](INFO): Completed Default:CallIridium 2013-10-31T20:06:27.296Z,1383249987.296 [Default:CallIridium] Stopped 2013-10-31T20:06:27.296Z,1383249987.296 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2013-10-31T20:06:37.261Z,1383249997.261 [NAL9602](INFO): Powering down 2013-10-31T20:11:27.287Z,1383250287.287 [Default:CallIridium] Running Loop=1 2013-10-31T20:11:27.288Z,1383250287.288 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2013-10-31T20:11:27.288Z,1383250287.288 [Default:CallIridium:A] Running Loop=1 2013-10-31T20:11:27.288Z,1383250287.288 [Default:CallIridium:A] Stopped 2013-10-31T20:11:27.288Z,1383250287.288 [Default:CallIridium:B] Running Loop=1 2013-10-31T20:11:27.288Z,1383250287.288 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2013-10-31T20:11:32.290Z,1383250292.290 [Default:Iridium] Running Loop=1 2013-10-31T20:11:32.291Z,1383250292.291 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2013-10-31T20:11:32.291Z,1383250292.291 [Default:Iridium:A.SetSpeed] Running Loop=1 2013-10-31T20:11:32.291Z,1383250292.291 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2013-10-31T20:11:32.291Z,1383250292.291 [Default:Iridium:B.GoToSurface] Running Loop=1 2013-10-31T20:11:32.291Z,1383250292.291 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-10-31T20:11:32.292Z,1383250292.292 [Default:Iridium:B.GoToSurface] Stopped 2013-10-31T20:11:32.292Z,1383250292.292 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-10-31T20:11:32.292Z,1383250292.292 [Default:Iridium:Read_Iridium] Running Loop=1 2013-10-31T20:11:32.292Z,1383250292.292 [Default:GPS] Running Loop=1 2013-10-31T20:11:32.292Z,1383250292.292 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2013-10-31T20:11:32.292Z,1383250292.292 [Default:GPS:A.SetSpeed] Running Loop=1 2013-10-31T20:11:32.292Z,1383250292.292 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2013-10-31T20:11:32.293Z,1383250292.293 [Default:GPS:B.GoToSurface] Running Loop=1 2013-10-31T20:11:32.293Z,1383250292.293 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-10-31T20:11:32.293Z,1383250292.293 [Default:GPS:B.GoToSurface] Stopped 2013-10-31T20:11:32.294Z,1383250292.294 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-10-31T20:11:32.294Z,1383250292.294 [Default:GPS:Read_GPS] Running Loop=1 2013-10-31T20:11:33.050Z,1383250293.050 [NAL9602](INFO): Powering up 2013-10-31T20:11:43.516Z,1383250303.516 [NAL9602](INFO): NAL9602 initialized 2013-10-31T20:12:08.564Z,1383250328.564 [NAL9602](INFO): SBD MO Status=1, MOMSN=20410, MT Status=0, MTMSN=0 2013-10-31T20:12:08.615Z,1383250328.615 [NAL9602](INFO): Sent 60 bytes from file Logs/20131031T194017/Courier0012.lzma 2013-10-31T20:12:08.615Z,1383250328.615 [NAL9602](INFO): Packets left to send: 0 2013-10-31T20:12:08.618Z,1383250328.618 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T194017/Courier0012.lzma.parts/0000.sbd 2013-10-31T20:12:20.158Z,1383250340.158 [NAL9602](INFO): SBD MO Status=1, MOMSN=20411, MT Status=0, MTMSN=0 2013-10-31T20:12:20.216Z,1383250340.216 [NAL9602](INFO): Sent 122 bytes from file Logs/20131031T194017/Express0013.lzma 2013-10-31T20:12:20.217Z,1383250340.217 [NAL9602](INFO): Packets left to send: 0 2013-10-31T20:12:20.218Z,1383250340.218 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T194017/Express0013.lzma.parts/0000.sbd 2013-10-31T20:12:24.357Z,1383250344.357 [NAL9602](INFO): SBD MO Status=0, MOMSN=20412, MT Status=0, MTMSN=0 2013-10-31T20:12:28.087Z,1383250348.087 [Default:Iridium:Read_Iridium] Stopped 2013-10-31T20:12:28.087Z,1383250348.087 [Default:Iridium](INFO): Completed Default:Iridium 2013-10-31T20:12:28.087Z,1383250348.087 [Default:Iridium] Stopped 2013-10-31T20:12:28.088Z,1383250348.088 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2013-10-31T20:12:28.088Z,1383250348.088 [Default:Iridium:A.SetSpeed] Stopped 2013-10-31T20:12:28.088Z,1383250348.088 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2013-10-31T20:12:28.543Z,1383250348.543 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2013-10-31T20:12:28.544Z,1383250348.544 [Default:CallIridium:B] Stopped 2013-10-31T20:12:28.544Z,1383250348.544 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2013-10-31T20:12:28.544Z,1383250348.544 [Default:CallIridium](INFO): Completed Default:CallIridium 2013-10-31T20:12:28.544Z,1383250348.544 [Default:CallIridium] Stopped 2013-10-31T20:12:28.544Z,1383250348.544 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2013-10-31T20:12:29.328Z,1383250349.328 [NAL9602](IMPORTANT): GPS fix at: 1383250370.00 2013-10-31T20:12:29.343Z,1383250349.343 [Default:GPS:Read_GPS] Stopped 2013-10-31T20:12:29.343Z,1383250349.343 [Default:GPS:D] Running Loop=1 2013-10-31T20:12:29.763Z,1383250349.763 [Default:GPS:D] Stopped 2013-10-31T20:12:29.764Z,1383250349.764 [Default:GPS](INFO): Completed Default:GPS 2013-10-31T20:12:29.764Z,1383250349.764 [Default:GPS] Stopped 2013-10-31T20:12:29.764Z,1383250349.764 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2013-10-31T20:12:29.764Z,1383250349.764 [Default:GPS:A.SetSpeed] Stopped 2013-10-31T20:12:29.764Z,1383250349.764 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2013-10-31T20:12:50.211Z,1383250370.211 [NAL9602](INFO): Powering down 2013-10-31T20:17:25.221Z,1383250645.221 [Default:CallIridium] Running Loop=1 2013-10-31T20:17:25.221Z,1383250645.221 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2013-10-31T20:17:25.221Z,1383250645.221 [Default:CallIridium:A] Running Loop=1 2013-10-31T20:17:25.222Z,1383250645.222 [Default:CallIridium:A] Stopped 2013-10-31T20:17:25.222Z,1383250645.222 [Default:CallIridium:B] Running Loop=1 2013-10-31T20:17:25.222Z,1383250645.222 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2013-10-31T20:17:30.221Z,1383250650.221 [Default:Iridium] Running Loop=1 2013-10-31T20:17:30.221Z,1383250650.221 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2013-10-31T20:17:30.221Z,1383250650.221 [Default:Iridium:A.SetSpeed] Running Loop=1 2013-10-31T20:17:30.221Z,1383250650.221 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2013-10-31T20:17:30.221Z,1383250650.221 [Default:Iridium:B.GoToSurface] Running Loop=1 2013-10-31T20:17:30.221Z,1383250650.221 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-10-31T20:17:30.222Z,1383250650.222 [Default:Iridium:B.GoToSurface] Stopped 2013-10-31T20:17:30.222Z,1383250650.222 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-10-31T20:17:30.222Z,1383250650.222 [Default:Iridium:Read_Iridium] Running Loop=1 2013-10-31T20:17:30.223Z,1383250650.223 [Default:GPS] Running Loop=1 2013-10-31T20:17:30.223Z,1383250650.223 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2013-10-31T20:17:30.223Z,1383250650.223 [Default:GPS:A.SetSpeed] Running Loop=1 2013-10-31T20:17:30.223Z,1383250650.223 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2013-10-31T20:17:30.223Z,1383250650.223 [Default:GPS:B.GoToSurface] Running Loop=1 2013-10-31T20:17:30.223Z,1383250650.223 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-10-31T20:17:30.224Z,1383250650.224 [Default:GPS:B.GoToSurface] Stopped 2013-10-31T20:17:30.224Z,1383250650.224 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-10-31T20:17:30.224Z,1383250650.224 [Default:GPS:Read_GPS] Running Loop=1 2013-10-31T20:17:30.989Z,1383250650.989 [NAL9602](INFO): Powering up 2013-10-31T20:17:41.831Z,1383250661.831 [NAL9602](INFO): NAL9602 initialized 2013-10-31T20:18:30.664Z,1383250710.664 [NAL9602](IMPORTANT): GPS fix at: 1383250731.00 2013-10-31T20:18:30.697Z,1383250710.697 [Default:GPS:Read_GPS] Stopped 2013-10-31T20:18:30.697Z,1383250710.697 [Default:GPS:D] Running Loop=1 2013-10-31T20:18:31.108Z,1383250711.109 [Default:GPS:D] Stopped 2013-10-31T20:18:31.109Z,1383250711.109 [Default:GPS](INFO): Completed Default:GPS 2013-10-31T20:18:31.109Z,1383250711.109 [Default:GPS] Stopped 2013-10-31T20:18:31.109Z,1383250711.109 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2013-10-31T20:18:31.109Z,1383250711.109 [Default:GPS:A.SetSpeed] Stopped 2013-10-31T20:18:31.109Z,1383250711.109 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2013-10-31T20:19:26.363Z,1383250766.363 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:19:26.363Z,1383250766.363 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:19:26.363Z,1383250766.363 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:19:43.053Z,1383250783.053 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:19:43.053Z,1383250783.053 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:19:43.054Z,1383250783.054 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:19:51.275Z,1383250791.275 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:19:51.275Z,1383250791.275 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:19:51.275Z,1383250791.275 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:20:00.654Z,1383250800.654 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:20:00.655Z,1383250800.655 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:20:00.655Z,1383250800.655 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:20:08.497Z,1383250808.497 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:20:08.497Z,1383250808.497 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:20:08.497Z,1383250808.497 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:20:17.050Z,1383250817.050 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:20:17.050Z,1383250817.050 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:20:17.050Z,1383250817.050 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:20:25.651Z,1383250825.651 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:20:25.651Z,1383250825.651 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:20:25.652Z,1383250825.652 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:20:34.661Z,1383250834.661 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:20:34.661Z,1383250834.661 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:20:34.661Z,1383250834.661 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:20:43.250Z,1383250843.250 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:20:43.251Z,1383250843.251 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:20:43.251Z,1383250843.251 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:20:51.860Z,1383250851.860 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:20:51.860Z,1383250851.860 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:20:51.860Z,1383250851.860 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:21:00.517Z,1383250860.517 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:21:00.518Z,1383250860.518 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:21:00.518Z,1383250860.518 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:21:09.151Z,1383250869.151 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:21:09.151Z,1383250869.151 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:21:09.151Z,1383250869.151 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:21:17.508Z,1383250877.508 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:21:17.508Z,1383250877.508 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:21:17.508Z,1383250877.508 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:21:26.157Z,1383250886.157 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:21:26.157Z,1383250886.157 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:21:26.157Z,1383250886.157 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:21:34.754Z,1383250894.754 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:21:34.754Z,1383250894.754 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:21:34.755Z,1383250894.755 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:21:43.348Z,1383250903.348 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:21:43.348Z,1383250903.348 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:21:43.348Z,1383250903.348 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:21:51.953Z,1383250911.953 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:21:51.953Z,1383250911.953 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:21:51.953Z,1383250911.953 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:22:00.562Z,1383250920.562 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:22:00.563Z,1383250920.563 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:22:00.563Z,1383250920.563 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:22:09.177Z,1383250929.177 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:22:09.178Z,1383250929.178 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:22:09.178Z,1383250929.178 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:22:18.166Z,1383250938.166 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:22:18.166Z,1383250938.166 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:22:18.166Z,1383250938.166 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:22:26.755Z,1383250946.755 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:22:26.755Z,1383250946.755 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:22:26.755Z,1383250946.755 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:22:35.360Z,1383250955.360 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:22:35.360Z,1383250955.360 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:22:35.360Z,1383250955.360 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:22:43.958Z,1383250963.958 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:22:43.958Z,1383250963.958 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:22:43.958Z,1383250963.958 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:22:52.201Z,1383250972.201 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:22:52.201Z,1383250972.201 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:22:52.201Z,1383250972.201 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:23:01.148Z,1383250981.148 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:23:01.148Z,1383250981.148 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:23:01.148Z,1383250981.148 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:23:09.778Z,1383250989.778 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:23:09.778Z,1383250989.778 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:23:09.778Z,1383250989.778 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:23:18.355Z,1383250998.355 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:23:18.355Z,1383250998.355 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:23:18.355Z,1383250998.355 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:23:27.075Z,1383251007.075 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:23:27.075Z,1383251007.075 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:23:27.075Z,1383251007.075 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:23:36.477Z,1383251016.477 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:23:36.478Z,1383251016.478 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:23:36.478Z,1383251016.478 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:23:45.080Z,1383251025.080 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:23:45.080Z,1383251025.080 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:23:45.081Z,1383251025.081 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:23:53.642Z,1383251033.642 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:23:53.642Z,1383251033.642 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:23:53.643Z,1383251033.643 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:24:02.247Z,1383251042.247 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:24:02.247Z,1383251042.247 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:24:02.247Z,1383251042.247 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:24:10.857Z,1383251050.857 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:24:10.857Z,1383251050.857 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:24:10.857Z,1383251050.857 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:24:19.878Z,1383251059.878 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:24:19.878Z,1383251059.878 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:24:19.879Z,1383251059.879 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:24:28.873Z,1383251068.873 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:24:28.874Z,1383251068.874 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:24:28.874Z,1383251068.874 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:24:45.194Z,1383251085.194 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:24:45.194Z,1383251085.194 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:24:45.194Z,1383251085.194 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:24:53.759Z,1383251093.759 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:24:53.759Z,1383251093.759 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:24:53.759Z,1383251093.759 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:25:02.781Z,1383251102.781 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:25:02.781Z,1383251102.781 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:25:02.781Z,1383251102.781 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:25:11.751Z,1383251111.751 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:25:11.751Z,1383251111.751 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:25:11.751Z,1383251111.751 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:25:20.352Z,1383251120.352 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:25:20.352Z,1383251120.352 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:25:20.352Z,1383251120.352 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:25:28.965Z,1383251128.965 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:25:28.966Z,1383251128.966 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:25:28.966Z,1383251128.966 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:25:37.960Z,1383251137.960 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:25:37.960Z,1383251137.960 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:25:37.960Z,1383251137.960 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:26:08.955Z,1383251168.955 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:26:08.956Z,1383251168.956 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:26:08.956Z,1383251168.956 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:26:17.653Z,1383251177.653 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:26:17.653Z,1383251177.653 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:26:17.653Z,1383251177.653 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:26:26.262Z,1383251186.262 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:26:26.262Z,1383251186.262 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:26:26.263Z,1383251186.263 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:26:34.856Z,1383251194.856 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:26:34.856Z,1383251194.856 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:26:34.856Z,1383251194.856 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:26:53.160Z,1383251213.160 [NAL9602](INFO): SBD MO Status=2, MOMSN=20413, MT Status=2, MTMSN=0 2013-10-31T20:26:53.160Z,1383251213.160 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-10-31T20:26:53.160Z,1383251213.160 [NAL9602](INFO): XMIT Failed. Starting over. 2013-10-31T20:28:03.130Z,1383251283.130 [CommandLine](IMPORTANT): got command report mod platform_pitch_angle 2013-10-31T20:28:03.325Z,1383251283.325 [Reporter](INFO): platform_pitch_angle -1.140742 arcdeg 2013-10-31T20:28:03.720Z,1383251283.720 [Reporter](INFO): platform_pitch_angle -1.250606 arcdeg 2013-10-31T20:28:04.101Z,1383251284.101 [Reporter](INFO): platform_pitch_angle -1.162715 arcdeg 2013-10-31T20:28:04.501Z,1383251284.501 [Reporter](INFO): platform_pitch_angle -1.250606 arcdeg 2013-10-31T20:28:05.302Z,1383251285.302 [Reporter](INFO): platform_pitch_angle -1.162715 arcdeg 2013-10-31T20:28:06.214Z,1383251286.214 [Reporter](INFO): platform_pitch_angle -1.228633 arcdeg 2013-10-31T20:28:07.000Z,1383251287.000 [Reporter](INFO): platform_pitch_angle -1.184688 arcdeg 2013-10-31T20:28:07.403Z,1383251287.403 [Reporter](INFO): platform_pitch_angle -1.228633 arcdeg 2013-10-31T20:28:07.803Z,1383251287.803 [Reporter](INFO): platform_pitch_angle -1.250606 arcdeg 2013-10-31T20:28:08.198Z,1383251288.198 [Reporter](INFO): platform_pitch_angle -1.206660 arcdeg 2013-10-31T20:28:08.597Z,1383251288.597 [Reporter](INFO): platform_pitch_angle -1.228633 arcdeg 2013-10-31T20:28:08.992Z,1383251288.992 [CommandLine](IMPORTANT): got command report clear 2013-10-31T20:28:32.127Z,1383251312.127 [CommandLine](IMPORTANT): got command restart application 2013-10-31T20:28:33.213Z,1383251313.213 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2013-10-31T20:28:33.213Z,1383251313.213 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2013-10-31T20:28:33.533Z,1383251313.533 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2013-10-31T20:28:33.854Z,1383251313.854 [WetLabsBB2FL](INFO): Powering down 2013-10-31T20:28:33.874Z,1383251313.874 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler 2013-10-31T20:28:33.926Z,1383251313.926 [CTD_NeilBrown](INFO): Powering down 2013-10-31T20:28:33.934Z,1383251313.934 [ComponentRegistry](INFO): Shutting down DVL_micro ThreadHandler 2013-10-31T20:28:34.167Z,1383251314.167 [DVL_micro](INFO): uninitialize:Powering down 2013-10-31T20:28:34.174Z,1383251314.174 [ComponentRegistry](INFO): Shutting down AsyncPiEstimator ThreadHandler 2013-10-31T20:28:34.371Z,1383251314.371 [AsyncPiEstimator](DEBUG): Uninitialize AsyncPiEstimator. 2013-10-31T20:28:34.380Z,1383251314.380 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2013-10-31T20:28:34.483Z,1383251314.483 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2013-10-31T20:28:34.485Z,1383251314.485 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2013-10-31T20:28:34.792Z,1383251314.792 [controlThread](DEBUG): Uninitializing ControlThread 2013-10-31T20:28:34.792Z,1383251314.792 [AHRS_sp3003D](INFO): Powering down 2013-10-31T20:28:34.880Z,1383251314.880 [NAL9602](INFO): Powering down 2013-10-31T20:28:34.881Z,1383251314.881 [DAT](INFO): Powering down 2013-10-31T20:28:34.882Z,1383251314.882 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2013-10-31T20:28:34.883Z,1383251314.883 [NavChart](DEBUG): Uninitialize NavChart Derivation. 2013-10-31T20:28:34.884Z,1383251314.884 [Default] Stopped 2013-10-31T20:28:34.884Z,1383251314.884 [Default](INFO): Aggregate::uninitialize Default 2013-10-31T20:28:34.884Z,1383251314.884 [Default:Iridium] Stopped 2013-10-31T20:28:34.885Z,1383251314.885 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2013-10-31T20:28:34.885Z,1383251314.885 [Default:Iridium:A.SetSpeed] Stopped 2013-10-31T20:28:34.885Z,1383251314.885 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2013-10-31T20:28:34.885Z,1383251314.885 [Default:Iridium:Read_Iridium] Stopped 2013-10-31T20:28:34.885Z,1383251314.885 [Default:CallIridium] Stopped 2013-10-31T20:28:34.885Z,1383251314.885 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2013-10-31T20:28:34.885Z,1383251314.885 [Default:CallIridium:B] Stopped 2013-10-31T20:28:34.885Z,1383251314.885 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2013-10-31T20:28:34.885Z,1383251314.885 [Default:D.SetSpeed] Stopped 2013-10-31T20:28:34.885Z,1383251314.885 [Default:D.SetSpeed](DEBUG): Uninitialize. 2013-10-31T20:28:34.885Z,1383251314.885 [Default:E.GoToSurface] Stopped 2013-10-31T20:28:34.885Z,1383251314.885 [Default:E.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-10-31T20:28:34.885Z,1383251314.885 [Default:F.Wait] Stopped 2013-10-31T20:28:34.886Z,1383251314.886 [Default:F.Wait](DEBUG): Uninitialize Wait Component. 2013-10-31T20:28:34.890Z,1383251314.890 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2013-10-31T20:28:34.890Z,1383251314.890 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2013-10-31T20:28:34.890Z,1383251314.890 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2013-10-31T20:28:34.891Z,1383251314.891 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2013-10-31T20:28:34.891Z,1383251314.891 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2013-10-31T20:28:34.891Z,1383251314.891 [BuoyancyServo](INFO): Powering down 2013-10-31T20:28:34.904Z,1383251314.904 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2013-10-31T20:28:34.904Z,1383251314.904 [ElevatorServo](INFO): Powering down 2013-10-31T20:28:34.905Z,1383251314.905 [MassServo](DEBUG): Uninitialize Mass Servo. 2013-10-31T20:28:34.905Z,1383251314.905 [MassServo](INFO): Powering down 2013-10-31T20:28:34.906Z,1383251314.906 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2013-10-31T20:28:34.906Z,1383251314.906 [RudderServo](INFO): Powering down 2013-10-31T20:28:34.906Z,1383251314.906 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2013-10-31T20:28:34.907Z,1383251314.907 [ThrusterServo](INFO): Powering down 2013-10-31T20:28:34.907Z,1383251314.907 [SBIT](DEBUG): Uninitialize SBIT Component. 2013-10-31T20:28:34.908Z,1383251314.908 [IBIT](DEBUG): Uninitialize IBIT Component. 2013-10-31T20:28:34.908Z,1383251314.908 [CBIT](DEBUG): Uninitialize CBIT Component.