2011-02-22T22:24:00.71300Z,1298413440.713 [Supervisor](DEBUG): Initializing supervisor. 2011-02-22T22:24:00.71600Z,1298413440.716 [SyncHandler](DEBUG): Created PCaller Thread at 1077007584 2011-02-22T22:24:00.71680Z,1298413440.7168 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2011-02-22T22:24:00.71790Z,1298413440.7179 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 1077073120 2011-02-22T22:24:00.71900Z,1298413440.719 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2011-02-22T22:24:00.72970Z,1298413440.7297 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2011-02-22T22:24:00.73090Z,1298413440.7309 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 1077138656 2011-02-22T22:24:00.73150Z,1298413440.7315 [ComponentRegistry](DEBUG): SyncComponent "logger" handled in the control thread. 2011-02-22T22:24:00.73200Z,1298413440.732 [Supervisor](INFO): Looking for Config files in directory: Config/ 2011-02-22T22:24:00.73320Z,1298413440.7332 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2011-02-22T22:24:01.34870Z,1298413441.3487 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2011-02-22T22:24:01.34930Z,1298413441.3493 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2011-02-22T22:24:01.53740Z,1298413441.5374 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2011-02-22T22:24:01.53790Z,1298413441.5379 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2011-02-22T22:24:01.62420Z,1298413441.6242 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2011-02-22T22:24:01.62470Z,1298413441.6247 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2011-02-22T22:24:01.80110Z,1298413441.8011 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2011-02-22T22:24:01.80160Z,1298413441.8016 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2011-02-22T22:24:01.89560Z,1298413441.8956 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2011-02-22T22:24:01.89610Z,1298413441.8961 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2011-02-22T22:24:02.22650Z,1298413442.2265 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2011-02-22T22:24:02.22710Z,1298413442.2271 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2011-02-22T22:24:02.38440Z,1298413442.3844 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2011-02-22T22:24:02.38500Z,1298413442.385 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2011-02-22T22:24:02.48080Z,1298413442.4808 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2011-02-22T22:24:02.48140Z,1298413442.4814 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2011-02-22T22:24:02.58080Z,1298413442.5808 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2011-02-22T22:24:02.58140Z,1298413442.5814 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2011-02-22T22:24:02.92530Z,1298413442.9253 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2011-02-22T22:24:02.92590Z,1298413442.9259 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2011-02-22T22:24:03.04360Z,1298413443.0436 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2011-02-22T22:24:03.04430Z,1298413443.0443 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2011-02-22T22:24:03.12960Z,1298413443.1296 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-tethys/ 2011-02-22T22:24:03.13050Z,1298413443.1305 [Supervisor](INFO): Opening Config file at: Config/lrauv-tethys/vehicle.cfg 2011-02-22T22:24:03.22390Z,1298413443.2239 [ComponentRegistry](DEBUG): Attempting to register duplicate component named "Config/vehicle" 2011-02-22T22:24:03.22450Z,1298413443.2245 [Supervisor](INFO): Opening Config file at: Config/lrauv-tethys/Sensor.cfg 2011-02-22T22:24:03.34870Z,1298413443.3487 [ComponentRegistry](DEBUG): Attempting to register duplicate component named "Config/Sensor" 2011-02-22T22:24:03.34930Z,1298413443.3493 [Supervisor](INFO): Opening Config file at: Config/lrauv-tethys/BIT.cfg 2011-02-22T22:24:03.43750Z,1298413443.4375 [ComponentRegistry](DEBUG): Attempting to register duplicate component named "Config/BIT" 2011-02-22T22:24:03.43810Z,1298413443.4381 [Supervisor](INFO): Opening Config file at: Config/lrauv-tethys/Servo.cfg 2011-02-22T22:24:03.53480Z,1298413443.5348 [ComponentRegistry](DEBUG): Attempting to register duplicate component named "Config/Servo" 2011-02-22T22:24:03.53540Z,1298413443.5354 [Supervisor](INFO): Opening Config file at: Config/lrauv-tethys/Science.cfg 2011-02-22T22:24:03.62920Z,1298413443.6292 [ComponentRegistry](DEBUG): Attempting to register duplicate component named "Config/Science" 2011-02-22T22:24:03.62980Z,1298413443.6298 [Supervisor](INFO): Opening Config file at: Config/lrauv-tethys/workSite.cfg 2011-02-22T22:24:03.71730Z,1298413443.7173 [ComponentRegistry](DEBUG): Attempting to register duplicate component named "Config/workSite" 2011-02-22T22:24:03.71790Z,1298413443.7179 [Supervisor](INFO): Opening Config file at: Config/lrauv-tethys/Simulator.cfg 2011-02-22T22:24:03.80410Z,1298413443.8041 [ComponentRegistry](DEBUG): Attempting to register duplicate component named "Config/Simulator" 2011-02-22T22:24:03.80460Z,1298413443.8046 [Supervisor](INFO): Opening Config file at: Config/lrauv-tethys/Derivation.cfg 2011-02-22T22:24:03.89000Z,1298413443.89 [ComponentRegistry](DEBUG): Attempting to register duplicate component named "Config/Derivation" 2011-02-22T22:24:03.89170Z,1298413443.8917 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-tethys// 2011-02-22T22:24:03.89250Z,1298413443.8925 [Supervisor](INFO): Opening Config file at: Config/lrauv-tethys//vehicle.cfg 2011-02-22T22:24:03.98430Z,1298413443.9843 [ComponentRegistry](DEBUG): Attempting to register duplicate component named "Config/vehicle" 2011-02-22T22:24:03.98490Z,1298413443.9849 [Supervisor](INFO): Opening Config file at: Config/lrauv-tethys//Sensor.cfg 2011-02-22T22:24:04.09930Z,1298413444.0993 [ComponentRegistry](DEBUG): Attempting to register duplicate component named "Config/Sensor" 2011-02-22T22:24:04.09990Z,1298413444.0999 [Supervisor](INFO): Opening Config file at: Config/lrauv-tethys//BIT.cfg 2011-02-22T22:24:04.18700Z,1298413444.187 [ComponentRegistry](DEBUG): Attempting to register duplicate component named "Config/BIT" 2011-02-22T22:24:04.18760Z,1298413444.1876 [Supervisor](INFO): Opening Config file at: Config/lrauv-tethys//Servo.cfg 2011-02-22T22:24:04.28280Z,1298413444.2828 [ComponentRegistry](DEBUG): Attempting to register duplicate component named "Config/Servo" 2011-02-22T22:24:04.28340Z,1298413444.2834 [Supervisor](INFO): Opening Config file at: Config/lrauv-tethys//Science.cfg 2011-02-22T22:24:04.37520Z,1298413444.3752 [ComponentRegistry](DEBUG): Attempting to register duplicate component named "Config/Science" 2011-02-22T22:24:04.37570Z,1298413444.3757 [Supervisor](INFO): Opening Config file at: Config/lrauv-tethys//workSite.cfg 2011-02-22T22:24:04.46330Z,1298413444.4633 [ComponentRegistry](DEBUG): Attempting to register duplicate component named "Config/workSite" 2011-02-22T22:24:04.46390Z,1298413444.4639 [Supervisor](INFO): Opening Config file at: Config/lrauv-tethys//Simulator.cfg 2011-02-22T22:24:04.54920Z,1298413444.5492 [ComponentRegistry](DEBUG): Attempting to register duplicate component named "Config/Simulator" 2011-02-22T22:24:04.54980Z,1298413444.5498 [Supervisor](INFO): Opening Config file at: Config/lrauv-tethys//Derivation.cfg 2011-02-22T22:24:04.63500Z,1298413444.635 [ComponentRegistry](DEBUG): Attempting to register duplicate component named "Config/Derivation" 2011-02-22T22:24:04.65330Z,1298413444.6533 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2011-02-22T22:24:04.75110Z,1298413444.7511 [InternalSim] Loaded 2011-02-22T22:24:04.75140Z,1298413444.7514 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread. 2011-02-22T22:24:04.75230Z,1298413444.7523 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2011-02-22T22:24:04.75290Z,1298413444.7529 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2011-02-22T22:24:04.76720Z,1298413444.7672 [SBIT](DEBUG): Construct Startup Built In Test. 2011-02-22T22:24:04.79930Z,1298413444.7993 [SBIT] Loaded 2011-02-22T22:24:04.79960Z,1298413444.7996 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2011-02-22T22:24:04.80070Z,1298413444.8007 [IBIT](DEBUG): Construct Initiated Built In Test. 2011-02-22T22:24:04.83350Z,1298413444.8335 [IBIT] Loaded 2011-02-22T22:24:04.83380Z,1298413444.8338 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2011-02-22T22:24:04.83500Z,1298413444.835 [CBIT](DEBUG): Construct CBIT Built In Test. 2011-02-22T22:24:04.86540Z,1298413444.8654 [CBIT] Loaded 2011-02-22T22:24:04.86570Z,1298413444.8657 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2011-02-22T22:24:04.86620Z,1298413444.8662 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2011-02-22T22:24:04.86680Z,1298413444.8668 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2011-02-22T22:24:04.96650Z,1298413444.9665 [BuoyancyServo] Loaded 2011-02-22T22:24:04.96690Z,1298413444.9669 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2011-02-22T22:24:04.97500Z,1298413444.975 [ElevatorServo] Loaded 2011-02-22T22:24:04.97530Z,1298413444.9753 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2011-02-22T22:24:04.98320Z,1298413444.9832 [MassServo] Loaded 2011-02-22T22:24:04.98350Z,1298413444.9835 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2011-02-22T22:24:04.99140Z,1298413444.9914 [RudderServo] Loaded 2011-02-22T22:24:04.99170Z,1298413444.9917 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2011-02-22T22:24:05.00200Z,1298413445.002 [ThrusterServo] Loaded 2011-02-22T22:24:05.00230Z,1298413445.0023 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2011-02-22T22:24:05.00290Z,1298413445.0029 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2011-02-22T22:24:05.00340Z,1298413445.0034 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2011-02-22T22:24:05.02760Z,1298413445.0276 [Bathymetry] Loaded 2011-02-22T22:24:05.02790Z,1298413445.0279 [ComponentRegistry](DEBUG): SyncComponent "Bathymetry" handled in the control thread. 2011-02-22T22:24:05.03480Z,1298413445.0348 [DepthRateCalculator] Loaded 2011-02-22T22:24:05.03510Z,1298413445.0351 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2011-02-22T22:24:05.04200Z,1298413445.042 [PitchRateCalculator] Loaded 2011-02-22T22:24:05.04240Z,1298413445.0424 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2011-02-22T22:24:05.04930Z,1298413445.0493 [SpeedCalculator] Loaded 2011-02-22T22:24:05.04960Z,1298413445.0496 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2011-02-22T22:24:05.06670Z,1298413445.0667 [TempGradientCalculator] Loaded 2011-02-22T22:24:05.06700Z,1298413445.067 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2011-02-22T22:24:05.07380Z,1298413445.0738 [YawRateCalculator] Loaded 2011-02-22T22:24:05.07410Z,1298413445.0741 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2011-02-22T22:24:05.11010Z,1298413445.1101 [Navigation] Loaded 2011-02-22T22:24:05.11050Z,1298413445.1105 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread. 2011-02-22T22:24:05.11100Z,1298413445.111 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2011-02-22T22:24:05.11160Z,1298413445.1116 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2011-02-22T22:24:05.15830Z,1298413445.1583 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2011-02-22T22:24:05.15900Z,1298413445.159 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2011-02-22T22:24:05.16840Z,1298413445.1684 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2011-02-22T22:24:05.16900Z,1298413445.169 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2011-02-22T22:24:05.18230Z,1298413445.1823 [VerticalControl](DEBUG): Construct VerticalControl. 2011-02-22T22:24:05.40520Z,1298413445.4052 [VerticalControl] Loaded 2011-02-22T22:24:05.40550Z,1298413445.4055 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2011-02-22T22:24:05.40660Z,1298413445.4066 [HorizontalControl](DEBUG): Construct HorizontalControl. 2011-02-22T22:24:05.46440Z,1298413445.4644 [HorizontalControl] Loaded 2011-02-22T22:24:05.46470Z,1298413445.4647 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2011-02-22T22:24:05.46590Z,1298413445.4659 [SpeedControl](DEBUG): Construct SpeedControl. 2011-02-22T22:24:05.46810Z,1298413445.4681 [SpeedControl] Loaded 2011-02-22T22:24:05.46840Z,1298413445.4684 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2011-02-22T22:24:05.46960Z,1298413445.4696 [LoopControl](DEBUG): Construct LoopControl. 2011-02-22T22:24:05.47430Z,1298413445.4743 [LoopControl] Loaded 2011-02-22T22:24:05.47460Z,1298413445.4746 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2011-02-22T22:24:05.47510Z,1298413445.4751 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2011-02-22T22:24:05.47570Z,1298413445.4757 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2011-02-22T22:24:05.48110Z,1298413445.4811 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator. 2011-02-22T22:24:05.48700Z,1298413445.487 [AsyncPiEstimator] Loaded 2011-02-22T22:24:05.48740Z,1298413445.4874 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread. 2011-02-22T22:24:05.48870Z,1298413445.4887 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 1078576352 2011-02-22T22:24:05.48940Z,1298413445.4894 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2011-02-22T22:24:05.49010Z,1298413445.4901 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2011-02-22T22:24:05.59630Z,1298413445.5963 [AHRS_sp3003D] Loaded 2011-02-22T22:24:05.59660Z,1298413445.5966 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread. 2011-02-22T22:24:05.64740Z,1298413445.6474 [AHRS_3DMGX3] Loaded 2011-02-22T22:24:05.64780Z,1298413445.6478 [ComponentRegistry](DEBUG): SyncComponent "AHRS_3DMGX3" handled in the control thread. 2011-02-22T22:24:06.02580Z,1298413446.0258 [Batt_Ocean_Server] Loaded 2011-02-22T22:24:06.02620Z,1298413446.0262 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread. 2011-02-22T22:24:06.04070Z,1298413446.0407 [Depth_Keller] Loaded 2011-02-22T22:24:06.04100Z,1298413446.041 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2011-02-22T22:24:06.04740Z,1298413446.0474 [DropWeight] Loaded 2011-02-22T22:24:06.04770Z,1298413446.0477 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2011-02-22T22:24:06.15900Z,1298413446.159 [DVL_micro] Loaded 2011-02-22T22:24:06.15930Z,1298413446.1593 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2011-02-22T22:24:06.25210Z,1298413446.2521 [NAL9601] Loaded 2011-02-22T22:24:06.25240Z,1298413446.2524 [ComponentRegistry](DEBUG): SyncComponent "NAL9601" handled in the control thread. 2011-02-22T22:24:06.30220Z,1298413446.3022 [Onboard] Loaded 2011-02-22T22:24:06.30250Z,1298413446.3025 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2011-02-22T22:24:06.31000Z,1298413446.31 [Radio_Freewave] Loaded 2011-02-22T22:24:06.31040Z,1298413446.3104 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread. 2011-02-22T22:24:06.31090Z,1298413446.3109 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2011-02-22T22:24:06.31150Z,1298413446.3115 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2011-02-22T22:24:06.36270Z,1298413446.3627 [CTD_NeilBrown] Loaded 2011-02-22T22:24:06.36320Z,1298413446.3632 [ComponentRegistry](DEBUG): SyncComponent "CTD_NeilBrown" handled in the control thread. 2011-02-22T22:24:06.39650Z,1298413446.3965 [WetLabsBB2FL] Loaded 2011-02-22T22:24:06.39680Z,1298413446.3968 [ComponentRegistry](DEBUG): SyncComponent "WetLabsBB2FL" handled in the control thread. 2011-02-22T22:24:06.41770Z,1298413446.4177 [Aanderaa_O2] Loaded 2011-02-22T22:24:06.41820Z,1298413446.4182 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread. 2011-02-22T22:24:06.42900Z,1298413446.429 [ISUS] Loaded 2011-02-22T22:24:06.42940Z,1298413446.4294 [ComponentRegistry](DEBUG): SyncComponent "ISUS" handled in the control thread. 2011-02-22T22:24:06.42980Z,1298413446.4298 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2011-02-22T22:24:06.43270Z,1298413446.4327 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2011-02-22T22:24:06.43360Z,1298413446.4336 [ComponentRegistry](DEBUG): SyncComponent "Maintainer" handled in the control thread. 2011-02-22T22:24:06.43460Z,1298413446.4346 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2011-02-22T22:24:06.43480Z,1298413446.4348 [Supervisor](DEBUG): Running supervisor. 2011-02-22T22:24:06.43820Z,1298413446.4382 [controlThread](DEBUG): Initializing ControlThread 2011-02-22T22:24:06.43940Z,1298413446.4394 [InternalSim](DEBUG): InternalSim initializing... 2011-02-22T22:24:06.47210Z,1298413446.4721 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator. 2011-02-22T22:24:06.50290Z,1298413446.5029 [SBIT](INFO): Initialize SBIT Component. 2011-02-22T22:24:06.50550Z,1298413446.5055 [IBIT](INFO): Initialize IBIT Component. 2011-02-22T22:24:06.50790Z,1298413446.5079 [CBIT](DEBUG): Initialize CBIT Component. 2011-02-22T22:24:06.51090Z,1298413446.5109 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2011-02-22T22:24:06.53650Z,1298413446.5365 [Bathymetry](DEBUG): Initialize Bathymetry Derivation. 2011-02-22T22:24:06.54210Z,1298413446.5421 [Bathymetry](DEBUG): Opened 2011-02-22T22:24:06.55440Z,1298413446.5544 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2011-02-22T22:24:06.55490Z,1298413446.5549 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2011-02-22T22:24:06.55540Z,1298413446.5554 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2011-02-22T22:24:06.55620Z,1298413446.5562 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2011-02-22T22:24:06.55780Z,1298413446.5578 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2011-02-22T22:24:06.55830Z,1298413446.5583 [Navigation](DEBUG): Initializing Navigation. 2011-02-22T22:24:06.55880Z,1298413446.5588 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2011-02-22T22:24:06.57390Z,1298413446.5739 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2011-02-22T22:24:06.57720Z,1298413446.5772 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2011-02-22T22:24:06.57800Z,1298413446.578 [LoopControl](DEBUG): Initialize LoopControlComponent. 2011-02-22T22:24:08.34850Z,1298413448.3485 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized 2011-02-22T22:24:08.35500Z,1298413448.355 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2011-02-22T22:24:08.36780Z,1298413448.3678 [Startup:0.GoToSurface](DEBUG): Construct GoToSurface. 2011-02-22T22:24:08.37930Z,1298413448.3793 [MissionManager](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2011-02-22T22:24:08.38250Z,1298413448.3825 [MissionManager](DEBUG): Initialize ReadDataComponent to sense platform_communications 2011-02-22T22:24:08.38510Z,1298413448.3851 [MissionManager](DEBUG): 2011-02-22T22:24:08.38600Z,1298413448.386 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2011-02-22T22:24:08.42050Z,1298413448.4205 [Default:GPS:0.SetSpeed](DEBUG): Construct. 2011-02-22T22:24:08.43620Z,1298413448.4362 [Default:GPS:1.GoToSurface](DEBUG): Construct GoToSurface. 2011-02-22T22:24:08.44620Z,1298413448.4462 [MissionManager](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2011-02-22T22:24:08.44860Z,1298413448.4486 [Default:Iridium:0.SetSpeed](DEBUG): Construct. 2011-02-22T22:24:08.46400Z,1298413448.464 [Default:Iridium:1.GoToSurface](DEBUG): Construct GoToSurface. 2011-02-22T22:24:08.48260Z,1298413448.4826 [MissionManager](DEBUG): Initialize ReadDataComponent to sense platform_communications 2011-02-22T22:24:08.48520Z,1298413448.4852 [Default:Iridium:0_Timeout:0.Execute](DEBUG): Construct Execute. 2011-02-22T22:24:08.50570Z,1298413448.5057 [Default:4.SetSpeed](DEBUG): Construct. 2011-02-22T22:24:08.52300Z,1298413448.523 [Default:5.GoToSurface](DEBUG): Construct GoToSurface. 2011-02-22T22:24:08.53890Z,1298413448.5389 [Default:6.Wait](DEBUG): Construct Wait. 2011-02-22T22:24:08.55360Z,1298413448.5536 [MissionManager](DEBUG): 400 400 Burn on Dropped drop weight due to communications timeout 1.0 5.0 5.0 1.0 5 2011-02-22T22:24:08.56010Z,1298413448.5601 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,AHRS_3DMGX3,Batt_Ocean_Server,Depth_Keller,DropWeight,DVL_micro,NAL9601,Onboard,Radio_Freewave,CTD_NeilBrown,WetLabsBB2FL,Aanderaa_O2,ISUS,Depth_Keller,Bathymetry,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintainer,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,logger, 2011-02-22T22:24:08.59080Z,1298413448.5908 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2011-02-22T22:24:08.65410Z,1298413448.6541 [AHRS_3DMGX3](DEBUG): Initializing AHRS_3DMGX3. 2011-02-22T22:24:08.82730Z,1298413448.8273 [DVL_micro](DEBUG): Initializing DVL_micro. 2011-02-22T22:24:08.85100Z,1298413448.851 [Radio_Freewave](INFO): Powering up 2011-02-22T22:24:08.85700Z,1298413448.857 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown. 2011-02-22T22:24:08.92190Z,1298413448.9219 [WetLabsBB2FL](INFO): Powering down 2011-02-22T22:24:09.07530Z,1298413449.0753 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2011-02-22T22:24:09.13110Z,1298413449.1311 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2011-02-22T22:24:09.14230Z,1298413449.1423 [ElevatorServo](DEBUG): Initializing EZServoServo. 2011-02-22T22:24:09.19900Z,1298413449.199 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2011-02-22T22:24:09.20830Z,1298413449.2083 [MassServo](DEBUG): Initializing EZServoServo. 2011-02-22T22:24:09.26320Z,1298413449.2632 [MassServo](DEBUG): Initializing MassServo. 2011-02-22T22:24:09.27230Z,1298413449.2723 [RudderServo](DEBUG): Initializing EZServoServo. 2011-02-22T22:24:09.32700Z,1298413449.327 [RudderServo](DEBUG): Initializing RudderServo. 2011-02-22T22:24:09.33640Z,1298413449.3364 [ThrusterServo](DEBUG): Initializing EZServoServo. 2011-02-22T22:24:09.39110Z,1298413449.3911 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2011-02-22T22:24:11.47090Z,1298413451.4709 [NAL9601](INFO): Powering up NAL9601 2011-02-22T22:24:13.17510Z,1298413453.1751 [Aanderaa_O2](INFO): Powering down 2011-02-22T22:24:22.33670Z,1298413462.3367 [SBIT](INFO): Beginning Startup BIT 2011-02-22T22:25:00.30060Z,1298413500.3006 [SBIT](IMPORTANT): SBIT PASSED 2011-02-22T22:25:00.65000Z,1298413500.65 [MissionManager](IMPORTANT): Started mission Startup 2011-02-22T22:25:00.65010Z,1298413500.6501 [Startup] Running Loop=1 2011-02-22T22:25:00.65030Z,1298413500.6503 [Startup](INFO): Aggregate::initialize Startup 2011-02-22T22:25:00.65050Z,1298413500.6505 [Startup:0.GoToSurface] Running Loop=1 2011-02-22T22:25:00.65060Z,1298413500.6506 [Startup:0.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2011-02-22T22:25:00.65780Z,1298413500.6578 [Startup:StartupSatComms] Running Loop=1 2011-02-22T22:25:00.65790Z,1298413500.6579 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms 2011-02-22T22:25:00.65820Z,1298413500.6582 [Startup:StartupSatComms:0] Running Loop=1 2011-02-22T22:25:17.08340Z,1298413517.0834 [NAL9601](INFO): NAL9601 initialized 2011-02-22T22:25:18.24590Z,1298413518.2459 [NAL9601](IMPORTANT): GPS fix at: 1298413538 2011-02-22T22:25:18.26150Z,1298413518.2615 [Startup:StartupSatComms:0] Stopped 2011-02-22T22:25:18.26170Z,1298413518.2617 [Startup:StartupSatComms:1] Running Loop=1 2011-02-22T22:25:53.46210Z,1298413553.4621 [NAL9601](IMPORTANT): SBD MO Status=1, MOMSN=12750, MT Status=1, MTMSN=1581 2011-02-22T22:25:53.61530Z,1298413553.6153 [NAL9601](INFO): Sent 166 bytes from file Logs/20110222T210900/shore0009.lzma 2011-02-22T22:25:53.61560Z,1298413553.6156 [NAL9601](INFO): Packets left to send: 0 2011-02-22T22:25:53.61690Z,1298413553.6169 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000000 2011-02-22T22:25:54.03400Z,1298413554.034 [NAL9601](INFO): Received command:run Insert/Surface.xml 2011-02-22T22:25:54.04340Z,1298413554.0434 [CommandLine](IMPORTANT): got command run ./Missions/Insert/Surface.xml 2011-02-22T22:25:54.04390Z,1298413554.0439 [MissionManager](INFO): Loading Mission: ./Missions/Insert/Surface.xml 2011-02-22T22:25:54.05990Z,1298413554.0599 [MissionManager](INFO): DefineArg IridiumTimeout = 30 min 2011-02-22T22:25:54.06120Z,1298413554.0612 [SurfaceComms:0.GoToSurface](DEBUG): Construct GoToSurface. 2011-02-22T22:25:54.07670Z,1298413554.0767 [MissionManager](DEBUG): Initialize ReadDataComponent to sense time_fix 2011-02-22T22:25:54.07890Z,1298413554.0789 [MissionManager](DEBUG): Initialize ReadDataComponent to sense platform_communications 2011-02-22T22:25:54.08200Z,1298413554.082 [MissionManager](DEBUG): Initialize ReadDataComponent to sense time_fix 2011-02-22T22:25:54.08830Z,1298413554.0883 [MissionManager](DEBUG): 30 2011-02-22T22:25:54.08870Z,1298413554.0887 [CommandLine](IMPORTANT): Running ./Missions/Insert/Surface.xml 2011-02-22T22:26:09.44400Z,1298413569.444 [NAL9601](IMPORTANT): SBD MO Status=1, MOMSN=12751, MT Status=1, MTMSN=1582 2011-02-22T22:26:09.58750Z,1298413569.5875 [NAL9601](INFO): Sent 332 bytes from file Logs/20110222T222400/shore0000.lzma 2011-02-22T22:26:09.58770Z,1298413569.5877 [NAL9601](INFO): Packets left to send: 1 2011-02-22T22:26:09.58880Z,1298413569.5888 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000001 2011-02-22T22:26:10.02090Z,1298413570.0209 [NAL9601](INFO): Received command:run Maintenance/calibrateSparton.xml 2011-02-22T22:26:10.08720Z,1298413570.0872 [CommandLine](IMPORTANT): got command run ./Missions/Maintenance/calibrateSparton.xml 2011-02-22T22:26:10.08890Z,1298413570.0889 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/calibrateSparton.xml 2011-02-22T22:26:10.24050Z,1298413570.2405 [MissionManager](INFO): DefineArg Depth = 20 m 2011-02-22T22:26:10.25630Z,1298413570.2563 [MissionManager](INFO): DefineArg Speed = 1 m/s 2011-02-22T22:26:10.25990Z,1298413570.2599 [MissionManager](INFO): DefineArg WaitDuration = 20 s 2011-02-22T22:26:10.26340Z,1298413570.2634 [MissionManager](INFO): DefineArg RudderAngle = 10 arcdeg 2011-02-22T22:26:10.27280Z,1298413570.2728 [MissionManager](INFO): DefineArg MagNorthHeading = 15 arcdeg 2011-02-22T22:26:10.27730Z,1298413570.2773 [MissionManager](INFO): DefineArg MinAltitude = 7 m 2011-02-22T22:26:10.28110Z,1298413570.2811 [MissionManager](INFO): DefineArg MaxDepth = 30 m 2011-02-22T22:26:10.28560Z,1298413570.2856 [MissionManager](INFO): DefineArg MinWaterDepth = 15 m 2011-02-22T22:26:10.29010Z,1298413570.2901 [MissionManager](INFO): DefineArg MinOffshore = 2000 m 2011-02-22T22:26:10.32210Z,1298413570.3221 [MissionManager](INFO): DefineArg NeedCommsTime = 30 min 2011-02-22T22:26:10.32580Z,1298413570.3258 [MissionManager](INFO): DefineArg ManualLoops = 1 count 2011-02-22T22:26:10.32950Z,1298413570.3295 [MissionManager](INFO): DefineArg AutoLoops = 3 count 2011-02-22T22:26:10.34520Z,1298413570.3452 [MissionManager](INFO): DefineArg CheckLoops = 2 count 2011-02-22T22:26:10.34890Z,1298413570.3489 [MissionManager](INFO): DefineArg NeutralBuoyancy = 348 cc 2011-02-22T22:26:10.35250Z,1298413570.3525 [MissionManager](INFO): DefineArg TimeoutDuration = 60 min 2011-02-22T22:26:10.36710Z,1298413570.3671 [calibrateSparton:0.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope. 2011-02-22T22:26:10.46140Z,1298413570.4614 [calibrateSparton:1.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2011-02-22T22:26:10.56950Z,1298413570.5695 [calibrateSparton:2.WaterDepthEnvelope](DEBUG): Construct WaterDepthEnvelope. 2011-02-22T22:26:10.62240Z,1298413570.6224 [calibrateSparton:3.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope. 2011-02-22T22:26:10.67180Z,1298413570.6718 [MissionManager](DEBUG): Initialize ReadDataComponent to sense platform_orientation 2011-02-22T22:26:10.67340Z,1298413570.6734 [calibrateSparton:5.Buoyancy](DEBUG): Construct Buoyancy. 2011-02-22T22:26:10.69760Z,1298413570.6976 [calibrateSparton:6.SetSpeed](DEBUG): Construct. 2011-02-22T22:26:10.73050Z,1298413570.7305 [calibrateSparton:7.Pitch](DEBUG): Construct. 2011-02-22T22:26:10.81630Z,1298413570.8163 [calibrateSparton:MassOff:0.Pitch](DEBUG): Construct. 2011-02-22T22:26:10.89860Z,1298413570.8986 [calibrateSparton:MassOff:Initialization:0.Point](DEBUG): Construct. 2011-02-22T22:26:11.01670Z,1298413571.0167 [calibrateSparton:MassOff:Initialization:1.Wait](DEBUG): Construct Wait. 2011-02-22T22:26:11.03000Z,1298413571.03 [calibrateSparton:MassOff:PreCircles:0.Point](DEBUG): Construct. 2011-02-22T22:26:11.15800Z,1298413571.158 [calibrateSparton:MassOff:PreCircles:1.Wait](DEBUG): Construct Wait. 2011-02-22T22:26:11.18250Z,1298413571.1825 [calibrateSparton:MassOff:PreCircles:2.Point](DEBUG): Construct. 2011-02-22T22:26:11.30830Z,1298413571.3083 [calibrateSparton:MassOff:Calibration:Manual Loop:0.Point](DEBUG): Construct. 2011-02-22T22:26:11.41310Z,1298413571.4131 [calibrateSparton:MassOff:Calibration:Manual Loop:1.Wait](DEBUG): Construct Wait. 2011-02-22T22:26:11.42560Z,1298413571.4256 [calibrateSparton:MassOff:Calibration:Manual Loop:2.Point](DEBUG): Construct. 2011-02-22T22:26:11.55530Z,1298413571.5553 [calibrateSparton:MassOff:Calibration:1.Wait](DEBUG): Construct Wait. 2011-02-22T22:26:11.58740Z,1298413571.5874 [calibrateSparton:MassOff:Calibration:Auto Loop:0.Point](DEBUG): Construct. 2011-02-22T22:26:11.71080Z,1298413571.7108 [calibrateSparton:MassOff:Calibration:Auto Loop:1.Wait](DEBUG): Construct Wait. 2011-02-22T22:26:11.73560Z,1298413571.7356 [calibrateSparton:MassOff:Calibration:Auto Loop:2.Point](DEBUG): Construct. 2011-02-22T22:26:11.80550Z,1298413571.8055 [calibrateSparton:MassOff:Calibration:3.CalibrateSparton](DEBUG): Construct CalibrateSparton. 2011-02-22T22:26:11.81070Z,1298413571.8107 [calibrateSparton:MassOff:PostCircles:0.Point](DEBUG): Construct. 2011-02-22T22:26:11.91840Z,1298413571.9184 [calibrateSparton:MassOff:PostCircles:1.Wait](DEBUG): Construct Wait. 2011-02-22T22:26:11.93520Z,1298413571.9352 [calibrateSparton:MassOff:PostCircles:2.Point](DEBUG): Construct. 2011-02-22T22:26:12.07700Z,1298413572.077 [calibrateSparton:PostCirclesMass:0.Point](DEBUG): Construct. 2011-02-22T22:26:12.19340Z,1298413572.1934 [calibrateSparton:PostCirclesMass:1.Wait](DEBUG): Construct Wait. 2011-02-22T22:26:12.20710Z,1298413572.2071 [calibrateSparton:PostCirclesMass:2.Point](DEBUG): Construct. 2011-02-22T22:26:12.32340Z,1298413572.3234 [MissionManager](DEBUG): 20.0 1 20 10 15 7 30 15 2000 30 1 3 2 348 60 0 0 2011-02-22T22:26:12.32400Z,1298413572.324 [CommandLine](IMPORTANT): Running ./Missions/Maintenance/calibrateSparton.xml 2011-02-22T22:26:18.63930Z,1298413578.6393 [Startup:StartupSatComms:1](INFO): Timed out from 2011-02-22T22:25:18.Z 2011-02-22T22:26:18.63940Z,1298413578.6394 [Startup:StartupSatComms:0_Timeout] Running Loop=1 2011-02-22T22:26:18.63960Z,1298413578.6396 [Startup:StartupSatComms:0_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:0_Timeout 2011-02-22T22:26:18.63990Z,1298413578.6399 [Startup:StartupSatComms:0_Timeout](INFO): Completed Startup:StartupSatComms:0_Timeout 2011-02-22T22:26:18.64000Z,1298413578.64 [Startup:StartupSatComms:1] Stopped 2011-02-22T22:26:18.64020Z,1298413578.6402 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2011-02-22T22:26:18.64030Z,1298413578.6403 [Startup:StartupSatComms] Stopped 2011-02-22T22:26:18.64050Z,1298413578.6405 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms 2011-02-22T22:26:18.64100Z,1298413578.641 [Startup](INFO): Completed Startup 2011-02-22T22:26:18.64120Z,1298413578.6412 [Startup] Stopped 2011-02-22T22:26:18.64130Z,1298413578.6413 [Startup](INFO): Aggregate::uninitialize Startup 2011-02-22T22:26:18.64140Z,1298413578.6414 [Startup:0.GoToSurface] Stopped 2011-02-22T22:26:18.64150Z,1298413578.6415 [Startup:0.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2011-02-22T22:26:19.03900Z,1298413579.039 [MissionManager](IMPORTANT): Started mission calibrateSparton 2011-02-22T22:26:19.03920Z,1298413579.0392 [calibrateSparton] Running Loop=1 2011-02-22T22:26:19.03940Z,1298413579.0394 [calibrateSparton](INFO): Aggregate::initialize calibrateSparton 2011-02-22T22:26:19.03970Z,1298413579.0397 [calibrateSparton:0.AltitudeEnvelope] Running Loop=1 2011-02-22T22:26:19.03980Z,1298413579.0398 [calibrateSparton:0.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent. 2011-02-22T22:26:19.04040Z,1298413579.0404 [calibrateSparton:1.DepthEnvelope] Running Loop=1 2011-02-22T22:26:19.04050Z,1298413579.0405 [calibrateSparton:1.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent. 2011-02-22T22:26:19.04240Z,1298413579.0424 [calibrateSparton:2.WaterDepthEnvelope] Running Loop=1 2011-02-22T22:26:19.04250Z,1298413579.0425 [calibrateSparton:2.WaterDepthEnvelope](DEBUG): Initialize WaterDepthEnvelopeComponent. 2011-02-22T22:26:19.04600Z,1298413579.046 [calibrateSparton:2.WaterDepthEnvelope](DEBUG): Opened Resources/cencalBathymetry.nc 2011-02-22T22:26:19.05790Z,1298413579.0579 [calibrateSparton:3.OffshoreEnvelope] Running Loop=1 2011-02-22T22:26:19.05800Z,1298413579.058 [calibrateSparton:3.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent. 2011-02-22T22:26:19.06110Z,1298413579.0611 [calibrateSparton:3.OffshoreEnvelope](DEBUG): Opened Resources/cencalShoreDist.nc 2011-02-22T22:26:19.07710Z,1298413579.0771 [calibrateSparton:4] Running Loop=1 2011-02-22T22:26:19.07750Z,1298413579.0775 [calibrateSparton:5.Buoyancy] Running Loop=1 2011-02-22T22:26:19.07760Z,1298413579.0776 [calibrateSparton:5.Buoyancy](DEBUG): Initialize Buoyancy Component. 2011-02-22T22:26:19.07840Z,1298413579.0784 [calibrateSparton:6.SetSpeed] Running Loop=1 2011-02-22T22:26:19.07850Z,1298413579.0785 [calibrateSparton:6.SetSpeed](DEBUG): Initialize. 2011-02-22T22:26:19.07900Z,1298413579.079 [calibrateSparton:7.Pitch] Running Loop=1 2011-02-22T22:26:19.07910Z,1298413579.0791 [calibrateSparton:7.Pitch](DEBUG): Initialize. 2011-02-22T22:26:19.08640Z,1298413579.0864 [calibrateSparton:6.SetSpeed] Running Loop=1 2011-02-22T22:26:19.09900Z,1298413579.099 [calibrateSparton:4] Running Loop=1 2011-02-22T22:26:19.10140Z,1298413579.1014 [calibrateSparton:3.OffshoreEnvelope] Running Loop=1 2011-02-22T22:26:19.10880Z,1298413579.1088 [calibrateSparton:2.WaterDepthEnvelope] Running Loop=1 2011-02-22T22:26:19.11580Z,1298413579.1158 [calibrateSparton:1.DepthEnvelope] Running Loop=1 2011-02-22T22:26:19.12250Z,1298413579.1225 [calibrateSparton:0.AltitudeEnvelope] Running Loop=1 2011-02-22T22:26:19.90370Z,1298413579.9037 [BuoyancyServo](ERROR): EZ Servo:6 reading outside of valid range:0 2011-02-22T22:26:19.90400Z,1298413579.904 [BuoyancyServo](FAULT): Buoyancy engine reporting null position 2011-02-22T22:26:19.90490Z,1298413579.9049 [BuoyancyServo] Hardware Fault, FailCount= 1 2011-02-22T22:26:19.90550Z,1298413579.9055 [BuoyancyServo](ERROR): Hardware Fault 2011-02-22T22:26:19.98160Z,1298413579.9816 [CBIT](ERROR): Hardware Fault in component: BuoyancyServo 2011-02-22T22:26:20.26290Z,1298413580.2629 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2011-02-22T22:26:20.26320Z,1298413580.2632 [BuoyancyServo](INFO): Powering down 2011-02-22T22:26:20.36110Z,1298413580.3611 [CBIT](INFO): Clearing failed state for component BuoyancyServo 2011-02-22T22:26:20.36120Z,1298413580.3612 [BuoyancyServo] No Fault, FailCount= 1 2011-02-22T22:26:21.06220Z,1298413581.0622 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2011-02-22T22:26:21.23510Z,1298413581.2351 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2011-02-22T22:26:21.84260Z,1298413581.8426 [NAL9601](INFO): SBD MO Status=1, MOMSN=12752, MT Status=0, MTMSN=0 2011-02-22T22:26:21.97130Z,1298413581.9713 [NAL9601](INFO): Sent 53 bytes from file Logs/20110222T222400/shore0000.lzma 2011-02-22T22:26:21.97150Z,1298413581.9715 [NAL9601](INFO): Packets left to send: 0 2011-02-22T22:26:21.97260Z,1298413581.9726 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000002 2011-02-22T22:26:32.64130Z,1298413592.6413 [NAL9601](INFO): SBD MO Status=0, MOMSN=12753, MT Status=0, MTMSN=0 2011-02-22T22:26:38.35320Z,1298413598.3532 [NAL9601](INFO): Powering down 2011-02-22T22:27:11.96290Z,1298413631.9629 [Radio_Freewave](INFO): Powering down 2011-02-22T22:27:19.56150Z,1298413639.5615 [Radio_Freewave](INFO): Powering up 2011-02-22T22:27:39.18790Z,1298413659.1879 [Batt_Ocean_Server](DEBUG): Bus busy reported for battery bank#8 STATUS: 65535 2011-02-22T22:27:41.58500Z,1298413661.585 [Batt_Ocean_Server](DEBUG): Bus busy reported for battery bank#8 STATUS: 65535 2011-02-22T22:27:43.98550Z,1298413663.9855 [Batt_Ocean_Server](DEBUG): Bus busy reported for battery bank#8 STATUS: 65535 2011-02-22T22:27:46.38970Z,1298413666.3897 [Batt_Ocean_Server](DEBUG): Bus busy reported for battery bank#8 STATUS: 65535 2011-02-22T22:27:48.78740Z,1298413668.7874 [Batt_Ocean_Server](DEBUG): Bus busy reported for battery bank#8 STATUS: 65535 2011-02-22T22:27:51.18870Z,1298413671.1887 [Batt_Ocean_Server](DEBUG): Bus busy reported for battery bank#8 STATUS: 65535 2011-02-22T22:27:53.58490Z,1298413673.5849 [Batt_Ocean_Server](DEBUG): Bus busy reported for battery bank#8 STATUS: 65535 2011-02-22T22:29:16.37610Z,1298413756.3761 [Radio_Freewave](INFO): Powering down 2011-02-22T22:30:45.17220Z,1298413845.1722 [calibrateSparton:MassOff] Running Loop=1 2011-02-22T22:30:45.17240Z,1298413845.1724 [calibrateSparton:MassOff](INFO): Aggregate::initialize calibrateSparton:MassOff 2011-02-22T22:30:45.17250Z,1298413845.1725 [calibrateSparton:MassOff:0.Pitch] Running Loop=1 2011-02-22T22:30:45.17260Z,1298413845.1726 [calibrateSparton:MassOff:0.Pitch](DEBUG): Initialize. 2011-02-22T22:30:45.17300Z,1298413845.173 [calibrateSparton:MassOff:Initialization] Running Loop=1 2011-02-22T22:30:45.17320Z,1298413845.1732 [calibrateSparton:MassOff:Initialization](INFO): Aggregate::initialize calibrateSparton:MassOff:Initialization 2011-02-22T22:30:45.17360Z,1298413845.1736 [calibrateSparton:MassOff:Initialization:0.Point] Running Loop=1 2011-02-22T22:30:45.17370Z,1298413845.1737 [calibrateSparton:MassOff:Initialization:0.Point](DEBUG): Initialize. 2011-02-22T22:30:45.59370Z,1298413845.5937 [calibrateSparton:MassOff:0.Pitch] Running Loop=1 2011-02-22T22:30:49.17270Z,1298413849.1727 [calibrateSparton:MassOff:Initialization:1.Wait] Running Loop=1 2011-02-22T22:30:49.17290Z,1298413849.1729 [calibrateSparton:MassOff:Initialization:1.Wait](DEBUG): Initialize Wait Component. 2011-02-22T22:31:09.58470Z,1298413869.5847 [calibrateSparton:MassOff:Initialization:1.Wait](INFO): Done Waiting. 2011-02-22T22:31:09.58500Z,1298413869.585 [calibrateSparton:MassOff:Initialization:1.Wait] Stopped 2011-02-22T22:31:09.58510Z,1298413869.5851 [calibrateSparton:MassOff:Initialization:1.Wait](DEBUG): Uninitialize Wait Component. 2011-02-22T22:31:09.58580Z,1298413869.5858 [calibrateSparton:MassOff:Initialization](INFO): Completed calibrateSparton:MassOff:Initialization 2011-02-22T22:31:09.58590Z,1298413869.5859 [calibrateSparton:MassOff:Initialization] Stopped 2011-02-22T22:31:09.58610Z,1298413869.5861 [calibrateSparton:MassOff:Initialization](INFO): Aggregate::uninitialize calibrateSparton:MassOff:Initialization 2011-02-22T22:31:09.58620Z,1298413869.5862 [calibrateSparton:MassOff:Initialization:0.Point] Stopped 2011-02-22T22:31:09.58640Z,1298413869.5864 [calibrateSparton:MassOff:PreCircles] Running Loop=1 2011-02-22T22:31:09.58660Z,1298413869.5866 [calibrateSparton:MassOff:PreCircles](INFO): Aggregate::initialize calibrateSparton:MassOff:PreCircles 2011-02-22T22:31:09.58700Z,1298413869.587 [calibrateSparton:MassOff:PreCircles:0.Point] Running Loop=1 2011-02-22T22:31:09.58710Z,1298413869.5871 [calibrateSparton:MassOff:PreCircles:0.Point](DEBUG): Initialize. 2011-02-22T22:31:09.58780Z,1298413869.5878 [calibrateSparton:MassOff:PreCircles:1.Wait] Running Loop=1 2011-02-22T22:31:09.58790Z,1298413869.5879 [calibrateSparton:MassOff:PreCircles:1.Wait](DEBUG): Initialize Wait Component. 2011-02-22T22:31:09.97760Z,1298413869.9776 [calibrateSparton:MassOff:PreCircles:0.Point] Running Loop=1 2011-02-22T22:31:30.00310Z,1298413890.0031 [calibrateSparton:MassOff:PreCircles:1.Wait](INFO): Done Waiting. 2011-02-22T22:31:30.00340Z,1298413890.0034 [calibrateSparton:MassOff:PreCircles:1.Wait] Stopped 2011-02-22T22:31:30.00350Z,1298413890.0035 [calibrateSparton:MassOff:PreCircles:1.Wait](DEBUG): Uninitialize Wait Component. 2011-02-22T22:31:30.00400Z,1298413890.004 [calibrateSparton:MassOff:PreCircles:2.Point] Running Loop=1 2011-02-22T22:31:30.00410Z,1298413890.0041 [calibrateSparton:MassOff:PreCircles:2.Point](DEBUG): Initialize. 2011-02-22T22:31:35.57120Z,1298413895.5712 [calibrateSparton:MassOff:PreCircles:2.Point] Stopped 2011-02-22T22:31:35.57200Z,1298413895.572 [calibrateSparton:MassOff:PreCircles](INFO): Completed calibrateSparton:MassOff:PreCircles 2011-02-22T22:31:35.57210Z,1298413895.5721 [calibrateSparton:MassOff:PreCircles] Stopped 2011-02-22T22:31:35.57220Z,1298413895.5722 [calibrateSparton:MassOff:PreCircles](INFO): Aggregate::uninitialize calibrateSparton:MassOff:PreCircles 2011-02-22T22:31:35.57240Z,1298413895.5724 [calibrateSparton:MassOff:PreCircles:0.Point] Stopped 2011-02-22T22:31:35.57260Z,1298413895.5726 [calibrateSparton:MassOff:PreCircles](INFO): Running loop #2 2011-02-22T22:31:35.57280Z,1298413895.5728 [calibrateSparton:MassOff:PreCircles] Running Loop=2 2011-02-22T22:31:35.57290Z,1298413895.5729 [calibrateSparton:MassOff:PreCircles](INFO): Aggregate::initialize calibrateSparton:MassOff:PreCircles 2011-02-22T22:31:35.57310Z,1298413895.5731 [calibrateSparton:MassOff:PreCircles:0.Point] Running Loop=1 2011-02-22T22:31:35.57320Z,1298413895.5732 [calibrateSparton:MassOff:PreCircles:0.Point](DEBUG): Initialize. 2011-02-22T22:31:35.57350Z,1298413895.5735 [calibrateSparton:MassOff:PreCircles:1.Wait] Running Loop=1 2011-02-22T22:31:35.57360Z,1298413895.5736 [calibrateSparton:MassOff:PreCircles:1.Wait](DEBUG): Initialize Wait Component. 2011-02-22T22:31:55.98680Z,1298413915.9868 [calibrateSparton:MassOff:PreCircles:1.Wait](INFO): Done Waiting. 2011-02-22T22:31:55.98720Z,1298413915.9872 [calibrateSparton:MassOff:PreCircles:1.Wait] Stopped 2011-02-22T22:31:55.98730Z,1298413915.9873 [calibrateSparton:MassOff:PreCircles:1.Wait](DEBUG): Uninitialize Wait Component. 2011-02-22T22:31:55.98750Z,1298413915.9875 [calibrateSparton:MassOff:PreCircles:2.Point] Running Loop=1 2011-02-22T22:31:55.98760Z,1298413915.9876 [calibrateSparton:MassOff:PreCircles:2.Point](DEBUG): Initialize. 2011-02-22T22:32:02.38830Z,1298413922.3883 [calibrateSparton:MassOff:PreCircles:2.Point] Stopped 2011-02-22T22:32:02.38890Z,1298413922.3889 [calibrateSparton:MassOff:PreCircles](INFO): Completed calibrateSparton:MassOff:PreCircles 2011-02-22T22:32:02.38900Z,1298413922.389 [calibrateSparton:MassOff:PreCircles] Stopped 2011-02-22T22:32:02.38920Z,1298413922.3892 [calibrateSparton:MassOff:PreCircles](INFO): Aggregate::uninitialize calibrateSparton:MassOff:PreCircles 2011-02-22T22:32:02.38930Z,1298413922.3893 [calibrateSparton:MassOff:PreCircles:0.Point] Stopped 2011-02-22T22:32:02.38950Z,1298413922.3895 [calibrateSparton:MassOff:Calibration] Running Loop=1 2011-02-22T22:32:02.38960Z,1298413922.3896 [calibrateSparton:MassOff:Calibration](INFO): Aggregate::initialize calibrateSparton:MassOff:Calibration 2011-02-22T22:32:02.38970Z,1298413922.3897 [calibrateSparton:MassOff:Calibration:3.CalibrateSparton] Running Loop=1 2011-02-22T22:32:02.38980Z,1298413922.3898 [calibrateSparton:MassOff:Calibration:3.CalibrateSparton](INFO): Initialize CalibrateSpartonComponent. 2011-02-22T22:32:02.45700Z,1298413922.457 [calibrateSparton:MassOff:Calibration:Manual Loop] Running Loop=1 2011-02-22T22:32:02.45720Z,1298413922.4572 [calibrateSparton:MassOff:Calibration:Manual Loop](INFO): Aggregate::initialize calibrateSparton:MassOff:Calibration:Manual Loop 2011-02-22T22:32:02.45750Z,1298413922.4575 [calibrateSparton:MassOff:Calibration:Manual Loop:0.Point] Running Loop=1 2011-02-22T22:32:02.45760Z,1298413922.4576 [calibrateSparton:MassOff:Calibration:Manual Loop:0.Point](DEBUG): Initialize. 2011-02-22T22:32:02.45840Z,1298413922.4584 [calibrateSparton:MassOff:Calibration:Manual Loop:1.Wait] Running Loop=1 2011-02-22T22:32:02.45850Z,1298413922.4585 [calibrateSparton:MassOff:Calibration:Manual Loop:1.Wait](DEBUG): Initialize Wait Component. 2011-02-22T22:32:02.74480Z,1298413922.7448 [calibrateSparton:MassOff:Calibration:3.CalibrateSparton] Running Loop=1 2011-02-22T22:32:02.75670Z,1298413922.7567 [calibrateSparton:MassOff:Calibration:Manual Loop:0.Point] Running Loop=1 2011-02-22T22:32:22.77900Z,1298413942.779 [calibrateSparton:MassOff:Calibration:Manual Loop:1.Wait](INFO): Done Waiting. 2011-02-22T22:32:22.77930Z,1298413942.7793 [calibrateSparton:MassOff:Calibration:Manual Loop:1.Wait] Stopped 2011-02-22T22:32:22.77940Z,1298413942.7794 [calibrateSparton:MassOff:Calibration:Manual Loop:1.Wait](DEBUG): Uninitialize Wait Component. 2011-02-22T22:32:22.77990Z,1298413942.7799 [calibrateSparton:MassOff:Calibration:Manual Loop:2.Point] Running Loop=1 2011-02-22T22:32:22.78000Z,1298413942.78 [calibrateSparton:MassOff:Calibration:Manual Loop:2.Point](DEBUG): Initialize. 2011-02-22T22:32:57.94590Z,1298413977.9459 [calibrateSparton:MassOff:Calibration:Manual Loop:2.Point] Stopped 2011-02-22T22:32:57.94660Z,1298413977.9466 [calibrateSparton:MassOff:Calibration:Manual Loop](INFO): Completed calibrateSparton:MassOff:Calibration:Manual Loop 2011-02-22T22:32:57.94680Z,1298413977.9468 [calibrateSparton:MassOff:Calibration:Manual Loop] Stopped 2011-02-22T22:32:57.94700Z,1298413977.947 [calibrateSparton:MassOff:Calibration:Manual Loop](INFO): Aggregate::uninitialize calibrateSparton:MassOff:Calibration:Manual Loop 2011-02-22T22:32:57.94710Z,1298413977.9471 [calibrateSparton:MassOff:Calibration:Manual Loop:0.Point] Stopped 2011-02-22T22:32:57.94730Z,1298413977.9473 [calibrateSparton:MassOff:Calibration:1.Wait] Running Loop=1 2011-02-22T22:32:57.94740Z,1298413977.9474 [calibrateSparton:MassOff:Calibration:1.Wait](DEBUG): Initialize Wait Component. 2011-02-22T22:32:58.42190Z,1298413978.4219 [calibrateSparton:MassOff:Calibration:3.CalibrateSparton] Preempted 2011-02-22T22:32:58.42210Z,1298413978.4221 [calibrateSparton:MassOff:Calibration:3.CalibrateSparton](INFO): Preempted CalibrateSpartonComponent. 2011-02-22T22:32:58.45220Z,1298413978.4522 [calibrateSparton:MassOff:Calibration:1.Wait](INFO): Done Waiting. 2011-02-22T22:32:58.45810Z,1298413978.4581 [calibrateSparton:MassOff:Calibration:1.Wait] Stopped 2011-02-22T22:32:58.45820Z,1298413978.4582 [calibrateSparton:MassOff:Calibration:1.Wait](DEBUG): Uninitialize Wait Component. 2011-02-22T22:32:58.45850Z,1298413978.4585 [calibrateSparton:MassOff:Calibration:Auto Loop] Running Loop=1 2011-02-22T22:32:58.45870Z,1298413978.4587 [calibrateSparton:MassOff:Calibration:Auto Loop](INFO): Aggregate::initialize calibrateSparton:MassOff:Calibration:Auto Loop 2011-02-22T22:32:58.45910Z,1298413978.4591 [calibrateSparton:MassOff:Calibration:Auto Loop:0.Point] Running Loop=1 2011-02-22T22:32:58.45920Z,1298413978.4592 [calibrateSparton:MassOff:Calibration:Auto Loop:0.Point](DEBUG): Initialize. 2011-02-22T22:32:58.45990Z,1298413978.4599 [calibrateSparton:MassOff:Calibration:Auto Loop:1.Wait] Running Loop=1 2011-02-22T22:32:58.46000Z,1298413978.46 [calibrateSparton:MassOff:Calibration:Auto Loop:1.Wait](DEBUG): Initialize Wait Component. 2011-02-22T22:32:58.74690Z,1298413978.7469 [calibrateSparton:MassOff:Calibration:3.CalibrateSparton] Running Loop=1 2011-02-22T22:32:58.75380Z,1298413978.7538 [calibrateSparton:MassOff:Calibration:Auto Loop:0.Point] Running Loop=1 2011-02-22T22:33:18.77770Z,1298413998.7777 [calibrateSparton:MassOff:Calibration:Auto Loop:1.Wait](INFO): Done Waiting. 2011-02-22T22:33:18.77810Z,1298413998.7781 [calibrateSparton:MassOff:Calibration:Auto Loop:1.Wait] Stopped 2011-02-22T22:33:18.77820Z,1298413998.7782 [calibrateSparton:MassOff:Calibration:Auto Loop:1.Wait](DEBUG): Uninitialize Wait Component. 2011-02-22T22:33:18.77880Z,1298413998.7788 [calibrateSparton:MassOff:Calibration:Auto Loop:2.Point] Running Loop=1 2011-02-22T22:33:18.77890Z,1298413998.7789 [calibrateSparton:MassOff:Calibration:Auto Loop:2.Point](DEBUG): Initialize. 2011-02-22T22:34:09.14790Z,1298414049.1479 [calibrateSparton:MassOff:Calibration:Auto Loop:2.Point] Stopped 2011-02-22T22:34:09.14860Z,1298414049.1486 [calibrateSparton:MassOff:Calibration:Auto Loop](INFO): Completed calibrateSparton:MassOff:Calibration:Auto Loop 2011-02-22T22:34:09.14870Z,1298414049.1487 [calibrateSparton:MassOff:Calibration:Auto Loop] Stopped 2011-02-22T22:34:09.14890Z,1298414049.1489 [calibrateSparton:MassOff:Calibration:Auto Loop](INFO): Aggregate::uninitialize calibrateSparton:MassOff:Calibration:Auto Loop 2011-02-22T22:34:09.14900Z,1298414049.149 [calibrateSparton:MassOff:Calibration:Auto Loop:0.Point] Stopped 2011-02-22T22:34:09.14920Z,1298414049.1492 [calibrateSparton:MassOff:Calibration:Auto Loop](INFO): Running loop #2 2011-02-22T22:34:09.14940Z,1298414049.1494 [calibrateSparton:MassOff:Calibration:Auto Loop] Running Loop=2 2011-02-22T22:34:09.14960Z,1298414049.1496 [calibrateSparton:MassOff:Calibration:Auto Loop](INFO): Aggregate::initialize calibrateSparton:MassOff:Calibration:Auto Loop 2011-02-22T22:34:09.14970Z,1298414049.1497 [calibrateSparton:MassOff:Calibration:Auto Loop:0.Point] Running Loop=1 2011-02-22T22:34:09.14980Z,1298414049.1498 [calibrateSparton:MassOff:Calibration:Auto Loop:0.Point](DEBUG): Initialize. 2011-02-22T22:34:09.15010Z,1298414049.1501 [calibrateSparton:MassOff:Calibration:Auto Loop:1.Wait] Running Loop=1 2011-02-22T22:34:09.15020Z,1298414049.1502 [calibrateSparton:MassOff:Calibration:Auto Loop:1.Wait](DEBUG): Initialize Wait Component. 2011-02-22T22:34:29.55960Z,1298414069.5596 [calibrateSparton:MassOff:Calibration:Auto Loop:1.Wait](INFO): Done Waiting. 2011-02-22T22:34:29.56000Z,1298414069.56 [calibrateSparton:MassOff:Calibration:Auto Loop:1.Wait] Stopped 2011-02-22T22:34:29.56010Z,1298414069.5601 [calibrateSparton:MassOff:Calibration:Auto Loop:1.Wait](DEBUG): Uninitialize Wait Component. 2011-02-22T22:34:29.56030Z,1298414069.5603 [calibrateSparton:MassOff:Calibration:Auto Loop:2.Point] Running Loop=1 2011-02-22T22:34:29.56040Z,1298414069.5604 [calibrateSparton:MassOff:Calibration:Auto Loop:2.Point](DEBUG): Initialize. 2011-02-22T22:35:19.54500Z,1298414119.545 [calibrateSparton:MassOff:Calibration:Auto Loop:2.Point] Stopped 2011-02-22T22:35:19.54570Z,1298414119.5457 [calibrateSparton:MassOff:Calibration:Auto Loop](INFO): Completed calibrateSparton:MassOff:Calibration:Auto Loop 2011-02-22T22:35:19.54580Z,1298414119.5458 [calibrateSparton:MassOff:Calibration:Auto Loop] Stopped 2011-02-22T22:35:19.54590Z,1298414119.5459 [calibrateSparton:MassOff:Calibration:Auto Loop](INFO): Aggregate::uninitialize calibrateSparton:MassOff:Calibration:Auto Loop 2011-02-22T22:35:19.54600Z,1298414119.546 [calibrateSparton:MassOff:Calibration:Auto Loop:0.Point] Stopped 2011-02-22T22:35:19.54630Z,1298414119.5463 [calibrateSparton:MassOff:Calibration:Auto Loop](INFO): Running loop #3 2011-02-22T22:35:19.54650Z,1298414119.5465 [calibrateSparton:MassOff:Calibration:Auto Loop] Running Loop=3 2011-02-22T22:35:19.54660Z,1298414119.5466 [calibrateSparton:MassOff:Calibration:Auto Loop](INFO): Aggregate::initialize calibrateSparton:MassOff:Calibration:Auto Loop 2011-02-22T22:35:19.54700Z,1298414119.547 [calibrateSparton:MassOff:Calibration:Auto Loop:0.Point] Running Loop=1 2011-02-22T22:35:19.54710Z,1298414119.5471 [calibrateSparton:MassOff:Calibration:Auto Loop:0.Point](DEBUG): Initialize. 2011-02-22T22:35:19.54750Z,1298414119.5475 [calibrateSparton:MassOff:Calibration:Auto Loop:1.Wait] Running Loop=1 2011-02-22T22:35:19.54760Z,1298414119.5476 [calibrateSparton:MassOff:Calibration:Auto Loop:1.Wait](DEBUG): Initialize Wait Component. 2011-02-22T22:35:40.40540Z,1298414140.4054 [calibrateSparton:MassOff:Calibration:Auto Loop:1.Wait](INFO): Done Waiting. 2011-02-22T22:35:40.40580Z,1298414140.4058 [calibrateSparton:MassOff:Calibration:Auto Loop:1.Wait] Stopped 2011-02-22T22:35:40.40590Z,1298414140.4059 [calibrateSparton:MassOff:Calibration:Auto Loop:1.Wait](DEBUG): Uninitialize Wait Component. 2011-02-22T22:35:40.40610Z,1298414140.4061 [calibrateSparton:MassOff:Calibration:Auto Loop:2.Point] Running Loop=1 2011-02-22T22:35:40.40620Z,1298414140.4062 [calibrateSparton:MassOff:Calibration:Auto Loop:2.Point](DEBUG): Initialize. 2011-02-22T22:36:30.74480Z,1298414190.7448 [calibrateSparton:MassOff:Calibration:Auto Loop:2.Point] Stopped 2011-02-22T22:36:30.74550Z,1298414190.7455 [calibrateSparton:MassOff:Calibration:Auto Loop](INFO): Completed calibrateSparton:MassOff:Calibration:Auto Loop 2011-02-22T22:36:30.74560Z,1298414190.7456 [calibrateSparton:MassOff:Calibration:Auto Loop] Stopped 2011-02-22T22:36:30.74580Z,1298414190.7458 [calibrateSparton:MassOff:Calibration:Auto Loop](INFO): Aggregate::uninitialize calibrateSparton:MassOff:Calibration:Auto Loop 2011-02-22T22:36:30.74590Z,1298414190.7459 [calibrateSparton:MassOff:Calibration:Auto Loop:0.Point] Stopped 2011-02-22T22:36:30.74610Z,1298414190.7461 [calibrateSparton:MassOff:Calibration](INFO): Completed calibrateSparton:MassOff:Calibration 2011-02-22T22:36:30.74620Z,1298414190.7462 [calibrateSparton:MassOff:Calibration] Stopped 2011-02-22T22:36:30.74640Z,1298414190.7464 [calibrateSparton:MassOff:Calibration](INFO): Aggregate::uninitialize calibrateSparton:MassOff:Calibration 2011-02-22T22:36:30.74650Z,1298414190.7465 [calibrateSparton:MassOff:Calibration:3.CalibrateSparton] Stopped 2011-02-22T22:36:30.74660Z,1298414190.7466 [calibrateSparton:MassOff:Calibration:3.CalibrateSparton](INFO): Uninitialize CalibrateSpartonComponent. 2011-02-22T22:36:30.78730Z,1298414190.7873 [AHRS_sp3003D](IMPORTANT): Magnetic calibration quality (0[best] to 10000) is 1 2011-02-22T22:36:30.78860Z,1298414190.7886 [calibrateSparton:MassOff:PostCircles] Running Loop=1 2011-02-22T22:36:30.78880Z,1298414190.7888 [calibrateSparton:MassOff:PostCircles](INFO): Aggregate::initialize calibrateSparton:MassOff:PostCircles 2011-02-22T22:36:30.78920Z,1298414190.7892 [calibrateSparton:MassOff:PostCircles:0.Point] Running Loop=1 2011-02-22T22:36:30.78930Z,1298414190.7893 [calibrateSparton:MassOff:PostCircles:0.Point](DEBUG): Initialize. 2011-02-22T22:36:30.79000Z,1298414190.79 [calibrateSparton:MassOff:PostCircles:1.Wait] Running Loop=1 2011-02-22T22:36:30.79010Z,1298414190.7901 [calibrateSparton:MassOff:PostCircles:1.Wait](DEBUG): Initialize Wait Component. 2011-02-22T22:36:31.19180Z,1298414191.1918 [calibrateSparton:MassOff:PostCircles:0.Point] Running Loop=1 2011-02-22T22:36:51.18640Z,1298414211.1864 [calibrateSparton:MassOff:PostCircles:1.Wait](INFO): Done Waiting. 2011-02-22T22:36:51.18680Z,1298414211.1868 [calibrateSparton:MassOff:PostCircles:1.Wait] Stopped 2011-02-22T22:36:51.18690Z,1298414211.1869 [calibrateSparton:MassOff:PostCircles:1.Wait](DEBUG): Uninitialize Wait Component. 2011-02-22T22:36:51.18740Z,1298414211.1874 [calibrateSparton:MassOff:PostCircles:2.Point] Running Loop=1 2011-02-22T22:36:51.18750Z,1298414211.1875 [calibrateSparton:MassOff:PostCircles:2.Point](DEBUG): Initialize. 2011-02-22T22:36:52.81780Z,1298414212.8178 [calibrateSparton:MassOff:PostCircles:2.Point] Stopped 2011-02-22T22:36:52.81840Z,1298414212.8184 [calibrateSparton:MassOff:PostCircles](INFO): Completed calibrateSparton:MassOff:PostCircles 2011-02-22T22:36:52.81850Z,1298414212.8185 [calibrateSparton:MassOff:PostCircles] Stopped 2011-02-22T22:36:52.81860Z,1298414212.8186 [calibrateSparton:MassOff:PostCircles](INFO): Aggregate::uninitialize calibrateSparton:MassOff:PostCircles 2011-02-22T22:36:52.81900Z,1298414212.819 [calibrateSparton:MassOff:PostCircles:0.Point] Stopped 2011-02-22T22:36:52.81930Z,1298414212.8193 [calibrateSparton:MassOff:PostCircles](INFO): Running loop #2 2011-02-22T22:36:52.81950Z,1298414212.8195 [calibrateSparton:MassOff:PostCircles] Running Loop=2 2011-02-22T22:36:52.81960Z,1298414212.8196 [calibrateSparton:MassOff:PostCircles](INFO): Aggregate::initialize calibrateSparton:MassOff:PostCircles 2011-02-22T22:36:52.81970Z,1298414212.8197 [calibrateSparton:MassOff:PostCircles:0.Point] Running Loop=1 2011-02-22T22:36:52.81980Z,1298414212.8198 [calibrateSparton:MassOff:PostCircles:0.Point](DEBUG): Initialize. 2011-02-22T22:36:52.82020Z,1298414212.8202 [calibrateSparton:MassOff:PostCircles:1.Wait] Running Loop=1 2011-02-22T22:36:52.82030Z,1298414212.8203 [calibrateSparton:MassOff:PostCircles:1.Wait](DEBUG): Initialize Wait Component. 2011-02-22T22:37:13.58370Z,1298414233.5837 [calibrateSparton:MassOff:PostCircles:1.Wait](INFO): Done Waiting. 2011-02-22T22:37:13.58410Z,1298414233.5841 [calibrateSparton:MassOff:PostCircles:1.Wait] Stopped 2011-02-22T22:37:13.58420Z,1298414233.5842 [calibrateSparton:MassOff:PostCircles:1.Wait](DEBUG): Uninitialize Wait Component. 2011-02-22T22:37:13.58440Z,1298414233.5844 [calibrateSparton:MassOff:PostCircles:2.Point] Running Loop=1 2011-02-22T22:37:13.58450Z,1298414233.5845 [calibrateSparton:MassOff:PostCircles:2.Point](DEBUG): Initialize. 2011-02-22T22:37:14.38340Z,1298414234.3834 [calibrateSparton:MassOff:PostCircles:2.Point] Stopped 2011-02-22T22:37:14.38400Z,1298414234.384 [calibrateSparton:MassOff:PostCircles](INFO): Completed calibrateSparton:MassOff:PostCircles 2011-02-22T22:37:14.38410Z,1298414234.3841 [calibrateSparton:MassOff:PostCircles] Stopped 2011-02-22T22:37:14.38430Z,1298414234.3843 [calibrateSparton:MassOff:PostCircles](INFO): Aggregate::uninitialize calibrateSparton:MassOff:PostCircles 2011-02-22T22:37:14.38440Z,1298414234.3844 [calibrateSparton:MassOff:PostCircles:0.Point] Stopped 2011-02-22T22:37:14.38500Z,1298414234.385 [calibrateSparton:MassOff](INFO): Completed calibrateSparton:MassOff 2011-02-22T22:37:14.38510Z,1298414234.3851 [calibrateSparton:MassOff] Stopped 2011-02-22T22:37:14.38530Z,1298414234.3853 [calibrateSparton:MassOff](INFO): Aggregate::uninitialize calibrateSparton:MassOff 2011-02-22T22:37:14.38540Z,1298414234.3854 [calibrateSparton:MassOff:0.Pitch] Stopped 2011-02-22T22:37:14.38560Z,1298414234.3856 [calibrateSparton:PostCirclesMass] Running Loop=1 2011-02-22T22:37:14.38580Z,1298414234.3858 [calibrateSparton:PostCirclesMass](INFO): Aggregate::initialize calibrateSparton:PostCirclesMass 2011-02-22T22:37:14.38610Z,1298414234.3861 [calibrateSparton:PostCirclesMass:0.Point] Running Loop=1 2011-02-22T22:37:14.38620Z,1298414234.3862 [calibrateSparton:PostCirclesMass:0.Point](DEBUG): Initialize. 2011-02-22T22:37:14.38700Z,1298414234.387 [calibrateSparton:PostCirclesMass:1.Wait] Running Loop=1 2011-02-22T22:37:14.38710Z,1298414234.3871 [calibrateSparton:PostCirclesMass:1.Wait](DEBUG): Initialize Wait Component. 2011-02-22T22:37:14.77340Z,1298414234.7734 [calibrateSparton:PostCirclesMass:0.Point] Running Loop=1 2011-02-22T22:37:34.77090Z,1298414254.7709 [calibrateSparton:PostCirclesMass:1.Wait](INFO): Done Waiting. 2011-02-22T22:37:34.77130Z,1298414254.7713 [calibrateSparton:PostCirclesMass:1.Wait] Stopped 2011-02-22T22:37:34.77140Z,1298414254.7714 [calibrateSparton:PostCirclesMass:1.Wait](DEBUG): Uninitialize Wait Component. 2011-02-22T22:37:34.77190Z,1298414254.7719 [calibrateSparton:PostCirclesMass:2.Point] Running Loop=1 2011-02-22T22:37:34.77200Z,1298414254.772 [calibrateSparton:PostCirclesMass:2.Point](DEBUG): Initialize. 2011-02-22T22:37:39.21800Z,1298414259.218 [calibrateSparton:PostCirclesMass:2.Point] Stopped 2011-02-22T22:37:39.21890Z,1298414259.2189 [calibrateSparton:PostCirclesMass](INFO): Completed calibrateSparton:PostCirclesMass 2011-02-22T22:37:39.21900Z,1298414259.219 [calibrateSparton:PostCirclesMass] Stopped 2011-02-22T22:37:39.21920Z,1298414259.2192 [calibrateSparton:PostCirclesMass](INFO): Aggregate::uninitialize calibrateSparton:PostCirclesMass 2011-02-22T22:37:39.21930Z,1298414259.2193 [calibrateSparton:PostCirclesMass:0.Point] Stopped 2011-02-22T22:37:39.21960Z,1298414259.2196 [calibrateSparton:PostCirclesMass](INFO): Running loop #2 2011-02-22T22:37:39.21980Z,1298414259.2198 [calibrateSparton:PostCirclesMass] Running Loop=2 2011-02-22T22:37:39.21990Z,1298414259.2199 [calibrateSparton:PostCirclesMass](INFO): Aggregate::initialize calibrateSparton:PostCirclesMass 2011-02-22T22:37:39.22010Z,1298414259.2201 [calibrateSparton:PostCirclesMass:0.Point] Running Loop=1 2011-02-22T22:37:39.22020Z,1298414259.2202 [calibrateSparton:PostCirclesMass:0.Point](DEBUG): Initialize. 2011-02-22T22:37:39.22060Z,1298414259.2206 [calibrateSparton:PostCirclesMass:1.Wait] Running Loop=1 2011-02-22T22:37:39.22060Z,1298414259.2206 [calibrateSparton:PostCirclesMass:1.Wait](DEBUG): Initialize Wait Component. 2011-02-22T22:37:59.56830Z,1298414279.5683 [calibrateSparton:PostCirclesMass:1.Wait](INFO): Done Waiting. 2011-02-22T22:37:59.56860Z,1298414279.5686 [calibrateSparton:PostCirclesMass:1.Wait] Stopped 2011-02-22T22:37:59.56870Z,1298414279.5687 [calibrateSparton:PostCirclesMass:1.Wait](DEBUG): Uninitialize Wait Component. 2011-02-22T22:37:59.56900Z,1298414279.569 [calibrateSparton:PostCirclesMass:2.Point] Running Loop=1 2011-02-22T22:37:59.56910Z,1298414279.5691 [calibrateSparton:PostCirclesMass:2.Point](DEBUG): Initialize. 2011-02-22T22:38:09.58330Z,1298414289.5833 [calibrateSparton:PostCirclesMass:2.Point] Stopped 2011-02-22T22:38:09.58390Z,1298414289.5839 [calibrateSparton:PostCirclesMass](INFO): Completed calibrateSparton:PostCirclesMass 2011-02-22T22:38:09.58400Z,1298414289.584 [calibrateSparton:PostCirclesMass] Stopped 2011-02-22T22:38:09.58420Z,1298414289.5842 [calibrateSparton:PostCirclesMass](INFO): Aggregate::uninitialize calibrateSparton:PostCirclesMass 2011-02-22T22:38:09.58430Z,1298414289.5843 [calibrateSparton:PostCirclesMass:0.Point] Stopped 2011-02-22T22:38:09.58750Z,1298414289.5875 [calibrateSparton](INFO): Completed calibrateSparton 2011-02-22T22:38:09.58760Z,1298414289.5876 [calibrateSparton] Stopped 2011-02-22T22:38:09.58780Z,1298414289.5878 [calibrateSparton](INFO): Aggregate::uninitialize calibrateSparton 2011-02-22T22:38:09.58790Z,1298414289.5879 [calibrateSparton:0.AltitudeEnvelope] Stopped 2011-02-22T22:38:09.58800Z,1298414289.588 [calibrateSparton:0.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent. 2011-02-22T22:38:09.58800Z,1298414289.588 [calibrateSparton:1.DepthEnvelope] Stopped 2011-02-22T22:38:09.58810Z,1298414289.5881 [calibrateSparton:1.DepthEnvelope](DEBUG): Uninitialize. 2011-02-22T22:38:09.58820Z,1298414289.5882 [calibrateSparton:2.WaterDepthEnvelope] Stopped 2011-02-22T22:38:09.58830Z,1298414289.5883 [calibrateSparton:2.WaterDepthEnvelope](DEBUG): Uninitialize WaterDepthEnvelopeComponent. 2011-02-22T22:38:09.58900Z,1298414289.589 [calibrateSparton:3.OffshoreEnvelope] Stopped 2011-02-22T22:38:09.58920Z,1298414289.5892 [calibrateSparton:3.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent. 2011-02-22T22:38:09.58970Z,1298414289.5897 [calibrateSparton:4] Stopped 2011-02-22T22:38:09.58980Z,1298414289.5898 [calibrateSparton:5.Buoyancy] Stopped 2011-02-22T22:38:09.58990Z,1298414289.5899 [calibrateSparton:5.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2011-02-22T22:38:09.59000Z,1298414289.59 [calibrateSparton:6.SetSpeed] Stopped 2011-02-22T22:38:09.59000Z,1298414289.59 [calibrateSparton:6.SetSpeed](DEBUG): Uninitialize. 2011-02-22T22:38:09.59010Z,1298414289.5901 [calibrateSparton:7.Pitch] Stopped 2011-02-22T22:38:09.96900Z,1298414289.969 [MissionManager](IMPORTANT): Started mission Default 2011-02-22T22:38:09.96910Z,1298414289.9691 [Default] Running Loop=1 2011-02-22T22:38:09.96920Z,1298414289.9692 [Default](INFO): Aggregate::initialize Default 2011-02-22T22:38:09.96940Z,1298414289.9694 [Default:4.SetSpeed] Running Loop=1 2011-02-22T22:38:09.96950Z,1298414289.9695 [Default:4.SetSpeed](DEBUG): Initialize. 2011-02-22T22:38:09.96960Z,1298414289.9696 [Default:5.GoToSurface] Running Loop=1 2011-02-22T22:38:09.96970Z,1298414289.9697 [Default:5.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2011-02-22T22:38:09.97040Z,1298414289.9704 [Default:GPS] Running Loop=1 2011-02-22T22:38:09.97050Z,1298414289.9705 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2011-02-22T22:38:09.97060Z,1298414289.9706 [Default:GPS:0.SetSpeed] Running Loop=1 2011-02-22T22:38:09.97080Z,1298414289.9708 [Default:GPS:0.SetSpeed](DEBUG): Initialize. 2011-02-22T22:38:09.97110Z,1298414289.9711 [Default:GPS:1.GoToSurface] Running Loop=1 2011-02-22T22:38:09.97120Z,1298414289.9712 [Default:GPS:1.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2011-02-22T22:38:09.97220Z,1298414289.9722 [Default:5.GoToSurface] Running Loop=1 2011-02-22T22:38:09.97900Z,1298414289.979 [Default:4.SetSpeed] Running Loop=1 2011-02-22T22:38:09.98550Z,1298414289.9855 [Default:CallIridium] Running Loop=1 2011-02-22T22:38:09.98560Z,1298414289.9856 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2011-02-22T22:38:09.98600Z,1298414289.986 [Default:CallIridium:0] Running Loop=1 2011-02-22T22:38:09.98610Z,1298414289.9861 [Default:CallIridium:0](INFO): Aggregate::initialize Default:CallIridium:0 2011-02-22T22:38:09.98630Z,1298414289.9863 [Default:CallGPS] Running Loop=1 2011-02-22T22:38:09.98650Z,1298414289.9865 [Default:CallGPS](INFO): Aggregate::initialize Default:CallGPS 2011-02-22T22:38:09.98680Z,1298414289.9868 [Default:CallGPS:0] Running Loop=1 2011-02-22T22:38:09.98690Z,1298414289.9869 [Default:CallGPS:0](INFO): Aggregate::initialize Default:CallGPS:0 2011-02-22T22:38:09.99360Z,1298414289.9936 [Default:GPS:0.SetSpeed] Running Loop=1 2011-02-22T22:38:10.45210Z,1298414290.4521 [Default:Iridium] Running Loop=1 2011-02-22T22:38:10.45230Z,1298414290.4523 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2011-02-22T22:38:10.45250Z,1298414290.4525 [Default:Iridium:0.SetSpeed] Running Loop=1 2011-02-22T22:38:10.45250Z,1298414290.4525 [Default:Iridium:0.SetSpeed](DEBUG): Initialize. 2011-02-22T22:38:10.45290Z,1298414290.4529 [Default:Iridium:1.GoToSurface] Running Loop=1 2011-02-22T22:38:10.45300Z,1298414290.453 [Default:Iridium:1.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2011-02-22T22:38:10.46020Z,1298414290.4602 [Default:Iridium:0.SetSpeed] Running Loop=1 2011-02-22T22:40:13.25100Z,1298414413.251 [Radio_Freewave](INFO): Powering up 2011-02-22T22:40:13.26290Z,1298414413.2629 [Default:Iridium:1.GoToSurface] Stopped 2011-02-22T22:40:13.26300Z,1298414413.263 [Default:Iridium:1.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2011-02-22T22:40:13.26320Z,1298414413.2632 [Default:Iridium:Read Iridium] Running Loop=1 2011-02-22T22:40:13.26410Z,1298414413.2641 [Default:GPS:1.GoToSurface] Stopped 2011-02-22T22:40:13.26420Z,1298414413.2642 [Default:GPS:1.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2011-02-22T22:40:13.26440Z,1298414413.2644 [Default:GPS:Read GPS] Running Loop=1 2011-02-22T22:40:14.06080Z,1298414414.0608 [NAL9601](INFO): Powering up 2011-02-22T22:41:19.77140Z,1298414479.7714 [NAL9601](INFO): NAL9601 initialized 2011-02-22T22:41:20.87220Z,1298414480.8722 [NAL9601](IMPORTANT): GPS fix at: 1298414502 2011-02-22T22:41:20.88980Z,1298414480.8898 [Default:GPS:Read GPS] Stopped 2011-02-22T22:41:20.89020Z,1298414480.8902 [Default:GPS](INFO): Completed Default:GPS 2011-02-22T22:41:20.89030Z,1298414480.8903 [Default:GPS] Stopped 2011-02-22T22:41:20.89050Z,1298414480.8905 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2011-02-22T22:41:20.89060Z,1298414480.8906 [Default:GPS:0.SetSpeed] Stopped 2011-02-22T22:41:20.89060Z,1298414480.8906 [Default:GPS:0.SetSpeed](DEBUG): Uninitialize. 2011-02-22T22:41:21.52450Z,1298414481.5245 [Default:CallGPS:0](INFO): Completed Default:CallGPS:0 2011-02-22T22:41:21.52460Z,1298414481.5246 [Default:CallGPS:0] Stopped 2011-02-22T22:41:21.52480Z,1298414481.5248 [Default:CallGPS:0](INFO): Aggregate::uninitialize Default:CallGPS:0 2011-02-22T22:41:21.52500Z,1298414481.525 [Default:CallGPS](INFO): Completed Default:CallGPS 2011-02-22T22:41:21.52510Z,1298414481.5251 [Default:CallGPS] Stopped 2011-02-22T22:41:21.52520Z,1298414481.5252 [Default:CallGPS](INFO): Aggregate::uninitialize Default:CallGPS 2011-02-22T22:42:00.66600Z,1298414520.666 [NAL9601](INFO): SBD MO Status=2, MOMSN=12754, MT Status=2, MTMSN=0 2011-02-22T22:42:00.66630Z,1298414520.6663 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2 2011-02-22T22:42:26.19390Z,1298414546.1939 [NAL9601](INFO): SBD MO Status=2, MOMSN=12754, MT Status=2, MTMSN=0 2011-02-22T22:42:26.19420Z,1298414546.1942 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2 2011-02-22T22:42:52.14470Z,1298414572.1447 [NAL9601](INFO): SBD MO Status=2, MOMSN=12754, MT Status=2, MTMSN=0 2011-02-22T22:42:52.14500Z,1298414572.145 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2 2011-02-22T22:43:09.42490Z,1298414589.4249 [NAL9601](INFO): SBD MO Status=2, MOMSN=12754, MT Status=2, MTMSN=0 2011-02-22T22:43:09.42510Z,1298414589.4251 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2 2011-02-22T22:43:35.30990Z,1298414615.3099 [NAL9601](INFO): SBD MO Status=2, MOMSN=12754, MT Status=2, MTMSN=0 2011-02-22T22:43:35.31020Z,1298414615.3102 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2 2011-02-22T22:43:52.43420Z,1298414632.4342 [NAL9601](INFO): SBD MO Status=2, MOMSN=12754, MT Status=2, MTMSN=0 2011-02-22T22:43:52.43440Z,1298414632.4344 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2 2011-02-22T22:44:18.03020Z,1298414658.0302 [NAL9601](INFO): SBD MO Status=2, MOMSN=12754, MT Status=2, MTMSN=0 2011-02-22T22:44:18.03040Z,1298414658.0304 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2 2011-02-22T22:44:41.94610Z,1298414681.9461 [NAL9601](INFO): SBD MO Status=1, MOMSN=12754, MT Status=0, MTMSN=0 2011-02-22T22:44:42.14730Z,1298414682.1473 [NAL9601](INFO): Sent 332 bytes from file Logs/20110222T222400/shore0001.lzma 2011-02-22T22:44:42.14760Z,1298414682.1476 [NAL9601](INFO): Packets left to send: 2 2011-02-22T22:44:42.14870Z,1298414682.1487 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000003 2011-02-22T22:44:58.86200Z,1298414698.862 [NAL9601](INFO): SBD MO Status=1, MOMSN=12755, MT Status=0, MTMSN=0 2011-02-22T22:44:59.01930Z,1298414699.0193 [NAL9601](INFO): Sent 332 bytes from file Logs/20110222T222400/shore0001.lzma 2011-02-22T22:44:59.01950Z,1298414699.0195 [NAL9601](INFO): Packets left to send: 1 2011-02-22T22:44:59.02060Z,1298414699.0206 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000004 2011-02-22T22:45:15.37390Z,1298414715.3739 [NAL9601](INFO): SBD MO Status=2, MOMSN=12756, MT Status=2, MTMSN=0 2011-02-22T22:45:15.37410Z,1298414715.3741 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2 2011-02-22T22:45:34.10190Z,1298414734.1019 [NAL9601](INFO): SBD MO Status=1, MOMSN=12756, MT Status=0, MTMSN=0 2011-02-22T22:45:34.26730Z,1298414734.2673 [NAL9601](INFO): Sent 14 bytes from file Logs/20110222T222400/shore0001.lzma 2011-02-22T22:45:34.26760Z,1298414734.2676 [NAL9601](INFO): Packets left to send: 0 2011-02-22T22:45:34.26940Z,1298414734.2694 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000005 2011-02-22T22:45:46.90210Z,1298414746.9021 [NAL9601](INFO): SBD MO Status=0, MOMSN=12757, MT Status=0, MTMSN=0 2011-02-22T22:45:47.06360Z,1298414747.0636 [Default:Iridium:Read Iridium] Stopped 2011-02-22T22:45:47.06420Z,1298414747.0642 [Default:Iridium](INFO): Completed Default:Iridium 2011-02-22T22:45:47.06430Z,1298414747.0643 [Default:Iridium] Stopped 2011-02-22T22:45:47.06440Z,1298414747.0644 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2011-02-22T22:45:47.06450Z,1298414747.0645 [Default:Iridium:0.SetSpeed] Stopped 2011-02-22T22:45:47.06460Z,1298414747.0646 [Default:Iridium:0.SetSpeed](DEBUG): Uninitialize. 2011-02-22T22:45:47.06490Z,1298414747.0649 [Default:6.Wait] Running Loop=1 2011-02-22T22:45:47.06490Z,1298414747.0649 [Default:6.Wait](DEBUG): Initialize Wait Component. 2011-02-22T22:45:47.32230Z,1298414747.3223 [Default:CallIridium:0](INFO): Completed Default:CallIridium:0 2011-02-22T22:45:47.32240Z,1298414747.3224 [Default:CallIridium:0] Stopped 2011-02-22T22:45:47.32250Z,1298414747.3225 [Default:CallIridium:0](INFO): Aggregate::uninitialize Default:CallIridium:0 2011-02-22T22:45:47.32280Z,1298414747.3228 [Default:CallIridium](INFO): Completed Default:CallIridium 2011-02-22T22:45:47.32300Z,1298414747.323 [Default:CallIridium] Stopped 2011-02-22T22:45:47.32310Z,1298414747.3231 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2011-02-22T22:45:57.32630Z,1298414757.3263 [NAL9601](INFO): Powering down 2011-02-22T22:46:22.45140Z,1298414782.4514 [Default:CallGPS] Running Loop=1 2011-02-22T22:46:22.45160Z,1298414782.4516 [Default:CallGPS](INFO): Aggregate::initialize Default:CallGPS 2011-02-22T22:46:22.45180Z,1298414782.4518 [Default:CallGPS:0] Running Loop=1 2011-02-22T22:46:22.45190Z,1298414782.4519 [Default:CallGPS:0](INFO): Aggregate::initialize Default:CallGPS:0 2011-02-22T22:46:27.43550Z,1298414787.4355 [Default:GPS] Running Loop=1 2011-02-22T22:46:27.43570Z,1298414787.4357 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2011-02-22T22:46:27.43580Z,1298414787.4358 [Default:GPS:0.SetSpeed] Running Loop=1 2011-02-22T22:46:27.43590Z,1298414787.4359 [Default:GPS:0.SetSpeed](DEBUG): Initialize. 2011-02-22T22:46:27.43620Z,1298414787.4362 [Default:GPS:1.GoToSurface] Running Loop=1 2011-02-22T22:46:27.43630Z,1298414787.4363 [Default:GPS:1.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2011-02-22T22:46:27.43710Z,1298414787.4371 [Default:GPS:1.GoToSurface] Stopped 2011-02-22T22:46:27.43720Z,1298414787.4372 [Default:GPS:1.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2011-02-22T22:46:27.43740Z,1298414787.4374 [Default:GPS:Read GPS] Running Loop=1 2011-02-22T22:46:28.10060Z,1298414788.1006 [NAL9601](INFO): Powering up 2011-02-22T22:47:33.81140Z,1298414853.8114 [NAL9601](INFO): NAL9601 initialized 2011-02-22T22:47:34.90380Z,1298414854.9038 [NAL9601](IMPORTANT): GPS fix at: 1298414877 2011-02-22T22:47:34.92040Z,1298414854.9204 [Default:GPS:Read GPS] Stopped 2011-02-22T22:47:34.92090Z,1298414854.9209 [Default:GPS](INFO): Completed Default:GPS 2011-02-22T22:47:34.92100Z,1298414854.921 [Default:GPS] Stopped 2011-02-22T22:47:34.92120Z,1298414854.9212 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2011-02-22T22:47:34.92130Z,1298414854.9213 [Default:GPS:0.SetSpeed] Stopped 2011-02-22T22:47:34.92140Z,1298414854.9214 [Default:GPS:0.SetSpeed](DEBUG): Uninitialize. 2011-02-22T22:47:35.32140Z,1298414855.3214 [Default:CallGPS:0](INFO): Completed Default:CallGPS:0 2011-02-22T22:47:35.32150Z,1298414855.3215 [Default:CallGPS:0] Stopped 2011-02-22T22:47:35.32160Z,1298414855.3216 [Default:CallGPS:0](INFO): Aggregate::uninitialize Default:CallGPS:0 2011-02-22T22:47:35.32190Z,1298414855.3219 [Default:CallGPS](INFO): Completed Default:CallGPS 2011-02-22T22:47:35.32200Z,1298414855.322 [Default:CallGPS] Stopped 2011-02-22T22:47:35.32210Z,1298414855.3221 [Default:CallGPS](INFO): Aggregate::uninitialize Default:CallGPS 2011-02-22T22:47:55.43540Z,1298414875.4354 [NAL9601](INFO): Powering down 2011-02-22T22:50:50.39700Z,1298415050.397 [Default:CallIridium] Running Loop=1 2011-02-22T22:50:50.39720Z,1298415050.3972 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2011-02-22T22:50:50.39740Z,1298415050.3974 [Default:CallIridium:0] Running Loop=1 2011-02-22T22:50:50.39750Z,1298415050.3975 [Default:CallIridium:0](INFO): Aggregate::initialize Default:CallIridium:0 2011-02-22T22:50:55.39560Z,1298415055.3956 [Default:Iridium] Running Loop=1 2011-02-22T22:50:55.39580Z,1298415055.3958 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2011-02-22T22:50:55.39590Z,1298415055.3959 [Default:Iridium:0.SetSpeed] Running Loop=1 2011-02-22T22:50:55.39600Z,1298415055.396 [Default:Iridium:0.SetSpeed](DEBUG): Initialize. 2011-02-22T22:50:55.39630Z,1298415055.3963 [Default:Iridium:1.GoToSurface] Running Loop=1 2011-02-22T22:50:55.39640Z,1298415055.3964 [Default:Iridium:1.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2011-02-22T22:50:55.39720Z,1298415055.3972 [Default:Iridium:1.GoToSurface] Stopped 2011-02-22T22:50:55.39730Z,1298415055.3973 [Default:Iridium:1.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2011-02-22T22:50:55.39750Z,1298415055.3975 [Default:Iridium:Read Iridium] Running Loop=1 2011-02-22T22:50:56.12610Z,1298415056.1261 [NAL9601](INFO): Powering up 2011-02-22T22:52:01.83540Z,1298415121.8354 [NAL9601](INFO): NAL9601 initialized 2011-02-22T22:52:26.48620Z,1298415146.4862 [NAL9601](INFO): SBD MO Status=1, MOMSN=12758, MT Status=0, MTMSN=0 2011-02-22T22:52:26.68730Z,1298415146.6873 [NAL9601](INFO): Sent 121 bytes from file Logs/20110222T222400/shore0002.lzma 2011-02-22T22:52:26.68760Z,1298415146.6876 [NAL9601](INFO): Packets left to send: 0 2011-02-22T22:52:26.68870Z,1298415146.6887 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000006 2011-02-22T22:52:35.27210Z,1298415155.2721 [Default:CallGPS] Running Loop=1 2011-02-22T22:52:35.27230Z,1298415155.2723 [Default:CallGPS](INFO): Aggregate::initialize Default:CallGPS 2011-02-22T22:52:35.27250Z,1298415155.2725 [Default:CallGPS:0] Running Loop=1 2011-02-22T22:52:35.27270Z,1298415155.2727 [Default:CallGPS:0](INFO): Aggregate::initialize Default:CallGPS:0 2011-02-22T22:52:35.67710Z,1298415155.6771 [Default:GPS] Running Loop=1 2011-02-22T22:52:35.67730Z,1298415155.6773 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2011-02-22T22:52:35.67740Z,1298415155.6774 [Default:GPS:0.SetSpeed] Running Loop=1 2011-02-22T22:52:35.67750Z,1298415155.6775 [Default:GPS:0.SetSpeed](DEBUG): Initialize. 2011-02-22T22:52:35.67780Z,1298415155.6778 [Default:GPS:1.GoToSurface] Running Loop=1 2011-02-22T22:52:35.67790Z,1298415155.6779 [Default:GPS:1.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2011-02-22T22:52:35.67880Z,1298415155.6788 [Default:GPS:1.GoToSurface] Stopped 2011-02-22T22:52:35.67890Z,1298415155.6789 [Default:GPS:1.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2011-02-22T22:52:35.67920Z,1298415155.6792 [Default:GPS:Read GPS] Running Loop=1 2011-02-22T22:52:41.65820Z,1298415161.6582 [NAL9601](INFO): SBD MO Status=2, MOMSN=12759, MT Status=2, MTMSN=0 2011-02-22T22:52:41.65840Z,1298415161.6584 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2 2011-02-22T22:52:42.86020Z,1298415162.8602 [NAL9601](IMPORTANT): GPS fix at: 1298415186 2011-02-22T22:52:42.87690Z,1298415162.8769 [Default:GPS:Read GPS] Stopped 2011-02-22T22:52:42.87730Z,1298415162.8773 [Default:GPS](INFO): Completed Default:GPS 2011-02-22T22:52:42.87740Z,1298415162.8774 [Default:GPS] Stopped 2011-02-22T22:52:42.87750Z,1298415162.8775 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2011-02-22T22:52:42.87760Z,1298415162.8776 [Default:GPS:0.SetSpeed] Stopped 2011-02-22T22:52:42.87770Z,1298415162.8777 [Default:GPS:0.SetSpeed](DEBUG): Uninitialize. 2011-02-22T22:52:43.27250Z,1298415163.2725 [Default:CallGPS:0](INFO): Completed Default:CallGPS:0 2011-02-22T22:52:43.27260Z,1298415163.2726 [Default:CallGPS:0] Stopped 2011-02-22T22:52:43.27280Z,1298415163.2728 [Default:CallGPS:0](INFO): Aggregate::uninitialize Default:CallGPS:0 2011-02-22T22:52:43.27300Z,1298415163.273 [Default:CallGPS](INFO): Completed Default:CallGPS 2011-02-22T22:52:43.27310Z,1298415163.2731 [Default:CallGPS] Stopped 2011-02-22T22:52:43.27320Z,1298415163.2732 [Default:CallGPS](INFO): Aggregate::uninitialize Default:CallGPS 2011-02-22T22:52:58.72030Z,1298415178.7203 [NAL9601](INFO): SBD MO Status=2, MOMSN=12759, MT Status=2, MTMSN=0 2011-02-22T22:52:58.72060Z,1298415178.7206 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2 2011-02-22T22:53:18.50610Z,1298415198.5061 [NAL9601](INFO): SBD MO Status=2, MOMSN=12759, MT Status=2, MTMSN=0 2011-02-22T22:53:18.50640Z,1298415198.5064 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2 2011-02-22T22:53:29.52200Z,1298415209.522 [NAL9601](INFO): SBD MO Status=0, MOMSN=12759, MT Status=0, MTMSN=0 2011-02-22T22:53:29.70350Z,1298415209.7035 [Default:Iridium:Read Iridium] Stopped 2011-02-22T22:53:29.70400Z,1298415209.704 [Default:Iridium](INFO): Completed Default:Iridium 2011-02-22T22:53:29.70410Z,1298415209.7041 [Default:Iridium] Stopped 2011-02-22T22:53:29.70430Z,1298415209.7043 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2011-02-22T22:53:29.70440Z,1298415209.7044 [Default:Iridium:0.SetSpeed] Stopped 2011-02-22T22:53:29.70450Z,1298415209.7045 [Default:Iridium:0.SetSpeed](DEBUG): Uninitialize. 2011-02-22T22:53:29.93670Z,1298415209.9367 [Default:CallIridium:0](INFO): Completed Default:CallIridium:0 2011-02-22T22:53:29.93680Z,1298415209.9368 [Default:CallIridium:0] Stopped 2011-02-22T22:53:29.93700Z,1298415209.937 [Default:CallIridium:0](INFO): Aggregate::uninitialize Default:CallIridium:0 2011-02-22T22:53:29.93720Z,1298415209.9372 [Default:CallIridium](INFO): Completed Default:CallIridium 2011-02-22T22:53:29.93730Z,1298415209.9373 [Default:CallIridium] Stopped 2011-02-22T22:53:29.93750Z,1298415209.9375 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2011-02-22T22:53:40.00040Z,1298415220.0004 [NAL9601](INFO): Powering down 2011-02-22T22:57:45.01530Z,1298415465.0153 [Default:CallGPS] Running Loop=1 2011-02-22T22:57:45.01550Z,1298415465.0155 [Default:CallGPS](INFO): Aggregate::initialize Default:CallGPS 2011-02-22T22:57:45.01570Z,1298415465.0157 [Default:CallGPS:0] Running Loop=1 2011-02-22T22:57:45.01590Z,1298415465.0159 [Default:CallGPS:0](INFO): Aggregate::initialize Default:CallGPS:0 2011-02-22T22:57:50.06960Z,1298415470.0696 [Default:GPS] Running Loop=1 2011-02-22T22:57:50.06980Z,1298415470.0698 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2011-02-22T22:57:50.06990Z,1298415470.0699 [Default:GPS:0.SetSpeed] Running Loop=1 2011-02-22T22:57:50.07000Z,1298415470.07 [Default:GPS:0.SetSpeed](DEBUG): Initialize. 2011-02-22T22:57:50.07030Z,1298415470.0703 [Default:GPS:1.GoToSurface] Running Loop=1 2011-02-22T22:57:50.07040Z,1298415470.0704 [Default:GPS:1.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2011-02-22T22:57:50.07120Z,1298415470.0712 [Default:GPS:1.GoToSurface] Stopped 2011-02-22T22:57:50.07130Z,1298415470.0713 [Default:GPS:1.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2011-02-22T22:57:50.07150Z,1298415470.0715 [Default:GPS:Read GPS] Running Loop=1 2011-02-22T22:57:50.72040Z,1298415470.7204 [NAL9601](INFO): Powering up 2011-02-22T22:58:29.93580Z,1298415509.9358 [Default:CallIridium] Running Loop=1 2011-02-22T22:58:29.93600Z,1298415509.936 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2011-02-22T22:58:29.93620Z,1298415509.9362 [Default:CallIridium:0] Running Loop=1 2011-02-22T22:58:29.93640Z,1298415509.9364 [Default:CallIridium:0](INFO): Aggregate::initialize Default:CallIridium:0 2011-02-22T22:58:30.33600Z,1298415510.336 [Default:Iridium] Running Loop=1 2011-02-22T22:58:30.33620Z,1298415510.3362 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2011-02-22T22:58:30.33630Z,1298415510.3363 [Default:Iridium:0.SetSpeed] Running Loop=1 2011-02-22T22:58:30.33640Z,1298415510.3364 [Default:Iridium:0.SetSpeed](DEBUG): Initialize. 2011-02-22T22:58:30.33670Z,1298415510.3367 [Default:Iridium:1.GoToSurface] Running Loop=1 2011-02-22T22:58:30.33680Z,1298415510.3368 [Default:Iridium:1.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2011-02-22T22:58:30.33760Z,1298415510.3376 [Default:Iridium:1.GoToSurface] Stopped 2011-02-22T22:58:30.33770Z,1298415510.3377 [Default:Iridium:1.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2011-02-22T22:58:30.33790Z,1298415510.3379 [Default:Iridium:Read Iridium] Running Loop=1 2011-02-22T22:58:56.43140Z,1298415536.4314 [NAL9601](INFO): NAL9601 initialized 2011-02-22T22:59:23.84610Z,1298415563.8461 [NAL9601](IMPORTANT): SBD MO Status=1, MOMSN=12760, MT Status=1, MTMSN=1583 2011-02-22T22:59:23.97930Z,1298415563.9793 [NAL9601](INFO): Sent 120 bytes from file Logs/20110222T222400/shore0003.lzma 2011-02-22T22:59:23.97950Z,1298415563.9795 [NAL9601](INFO): Packets left to send: 0 2011-02-22T22:59:23.98070Z,1298415563.9807 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000007 2011-02-22T22:59:24.39750Z,1298415564.3975 [NAL9601](INFO): Received command:run Transport/transit_3km.xml 2011-02-22T22:59:24.46330Z,1298415564.4633 [CommandLine](IMPORTANT): got command run ./Missions/Transport/transit_3km.xml 2011-02-22T22:59:24.46360Z,1298415564.4636 [MissionManager](INFO): Loading Mission: ./Missions/Transport/transit_3km.xml 2011-02-22T22:59:24.53010Z,1298415564.5301 [MissionManager](INFO): DefineArg ApproachDepth = 10 m 2011-02-22T22:59:24.53380Z,1298415564.5338 [MissionManager](INFO): DefineArg Wpt1Lat = 36.806966 arcdeg 2011-02-22T22:59:24.53750Z,1298415564.5375 [MissionManager](INFO): DefineArg Wpt1Lon = -121.824326 arcdeg 2011-02-22T22:59:24.54100Z,1298415564.541 [MissionManager](INFO): DefineArg Speed = 1 m/s 2011-02-22T22:59:24.54300Z,1298415564.543 [transit_3km:0.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope. 2011-02-22T22:59:24.59200Z,1298415564.592 [transit_3km:1.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2011-02-22T22:59:24.73610Z,1298415564.7361 [transit_3km:2.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope. 2011-02-22T22:59:24.76990Z,1298415564.7699 [transit_3km:SURFACECOMMS:0.GoToSurface](DEBUG): Construct GoToSurface. 2011-02-22T22:59:24.78880Z,1298415564.7888 [transit_3km:SURFACECOMMS:1:0.SetSpeed](DEBUG): Construct. 2011-02-22T22:59:24.82900Z,1298415564.829 [MissionManager](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2011-02-22T22:59:24.84340Z,1298415564.8434 [MissionManager](DEBUG): Initialize ReadDataComponent to sense platform_communications 2011-02-22T22:59:24.84870Z,1298415564.8487 [MissionManager](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2011-02-22T22:59:24.85380Z,1298415564.8538 [transit_3km:5.Buoyancy](DEBUG): Construct Buoyancy. 2011-02-22T22:59:24.87790Z,1298415564.8779 [transit_3km:WaypointOne:0.Pitch](DEBUG): Construct. 2011-02-22T22:59:24.96610Z,1298415564.9661 [transit_3km:WaypointOne:1.SetSpeed](DEBUG): Construct. 2011-02-22T22:59:24.98870Z,1298415564.9887 [transit_3km:WaypointOne:WaypointW1.Waypoint](DEBUG): Construct Waypoint. 2011-02-22T22:59:25.06230Z,1298415565.0623 [MissionManager](DEBUG):  10.0 36.806966 -121.824326 1 7 20 1 0 35 275 2011-02-22T22:59:25.07500Z,1298415565.075 [CommandLine](IMPORTANT): Running ./Missions/Transport/transit_3km.xml 2011-02-22T22:59:25.12720Z,1298415565.1272 [Default] Stopped 2011-02-22T22:59:25.12740Z,1298415565.1274 [Default](INFO): Aggregate::uninitialize Default 2011-02-22T22:59:25.12750Z,1298415565.1275 [Default:GPS] Stopped 2011-02-22T22:59:25.12770Z,1298415565.1277 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2011-02-22T22:59:25.12780Z,1298415565.1278 [Default:GPS:0.SetSpeed] Stopped 2011-02-22T22:59:25.12790Z,1298415565.1279 [Default:GPS:0.SetSpeed](DEBUG): Uninitialize. 2011-02-22T22:59:25.12800Z,1298415565.128 [Default:GPS:Read GPS] Stopped 2011-02-22T22:59:25.12810Z,1298415565.1281 [Default:Iridium] Stopped 2011-02-22T22:59:25.12820Z,1298415565.1282 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2011-02-22T22:59:25.12830Z,1298415565.1283 [Default:Iridium:0.SetSpeed] Stopped 2011-02-22T22:59:25.12840Z,1298415565.1284 [Default:Iridium:0.SetSpeed](DEBUG): Uninitialize. 2011-02-22T22:59:25.12850Z,1298415565.1285 [Default:Iridium:Read Iridium] Stopped 2011-02-22T22:59:25.12860Z,1298415565.1286 [Default:CallGPS] Stopped 2011-02-22T22:59:25.12870Z,1298415565.1287 [Default:CallGPS](INFO): Aggregate::uninitialize Default:CallGPS 2011-02-22T22:59:25.12880Z,1298415565.1288 [Default:CallGPS:0] Stopped 2011-02-22T22:59:25.12890Z,1298415565.1289 [Default:CallGPS:0](INFO): Aggregate::uninitialize Default:CallGPS:0 2011-02-22T22:59:25.12900Z,1298415565.129 [Default:CallIridium] Stopped 2011-02-22T22:59:25.12920Z,1298415565.1292 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2011-02-22T22:59:25.12930Z,1298415565.1293 [Default:CallIridium:0] Stopped 2011-02-22T22:59:25.12940Z,1298415565.1294 [Default:CallIridium:0](INFO): Aggregate::uninitialize Default:CallIridium:0 2011-02-22T22:59:25.12950Z,1298415565.1295 [Default:4.SetSpeed] Stopped 2011-02-22T22:59:25.12960Z,1298415565.1296 [Default:4.SetSpeed](DEBUG): Uninitialize. 2011-02-22T22:59:25.12970Z,1298415565.1297 [Default:5.GoToSurface] Stopped 2011-02-22T22:59:25.12980Z,1298415565.1298 [Default:5.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2011-02-22T22:59:25.12990Z,1298415565.1299 [Default:6.Wait] Stopped 2011-02-22T22:59:25.12990Z,1298415565.1299 [Default:6.Wait](DEBUG): Uninitialize Wait Component. 2011-02-22T22:59:25.13010Z,1298415565.1301 [MissionManager](IMPORTANT): Started mission transit_3km 2011-02-22T22:59:25.13020Z,1298415565.1302 [transit_3km] Running Loop=1 2011-02-22T22:59:25.13040Z,1298415565.1304 [transit_3km](INFO): Aggregate::initialize transit_3km 2011-02-22T22:59:25.13050Z,1298415565.1305 [transit_3km:0.AltitudeEnvelope] Running Loop=1 2011-02-22T22:59:25.13060Z,1298415565.1306 [transit_3km:0.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent. 2011-02-22T22:59:25.13090Z,1298415565.1309 [transit_3km:1.DepthEnvelope] Running Loop=1 2011-02-22T22:59:25.13100Z,1298415565.131 [transit_3km:1.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent. 2011-02-22T22:59:25.13220Z,1298415565.1322 [transit_3km:2.OffshoreEnvelope] Running Loop=1 2011-02-22T22:59:25.13230Z,1298415565.1323 [transit_3km:2.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent. 2011-02-22T22:59:25.13540Z,1298415565.1354 [transit_3km:2.OffshoreEnvelope](DEBUG): Opened Resources/cencalShoreDist.nc 2011-02-22T22:59:25.15440Z,1298415565.1544 [transit_3km:5.Buoyancy] Running Loop=1 2011-02-22T22:59:25.15450Z,1298415565.1545 [transit_3km:5.Buoyancy](DEBUG): Initialize Buoyancy Component. 2011-02-22T22:59:25.15540Z,1298415565.1554 [transit_3km:SURFACECOMMS] Running Loop=1 2011-02-22T22:59:25.15550Z,1298415565.1555 [transit_3km:SURFACECOMMS](INFO): Aggregate::initialize transit_3km:SURFACECOMMS 2011-02-22T22:59:25.15570Z,1298415565.1557 [transit_3km:SURFACECOMMS:0.GoToSurface] Running Loop=1 2011-02-22T22:59:25.15580Z,1298415565.1558 [transit_3km:SURFACECOMMS:0.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2011-02-22T22:59:25.15670Z,1298415565.1567 [transit_3km:5.Buoyancy] Running Loop=1 2011-02-22T22:59:25.16820Z,1298415565.1682 [transit_3km:SURFACECOMMS:1] Running Loop=1 2011-02-22T22:59:25.16840Z,1298415565.1684 [transit_3km:SURFACECOMMS:1](INFO): Aggregate::initialize transit_3km:SURFACECOMMS:1 2011-02-22T22:59:25.16850Z,1298415565.1685 [transit_3km:SURFACECOMMS:1:0.SetSpeed] Running Loop=1 2011-02-22T22:59:25.16860Z,1298415565.1686 [transit_3km:SURFACECOMMS:1:0.SetSpeed](DEBUG): Initialize. 2011-02-22T22:59:25.16900Z,1298415565.169 [transit_3km:SURFACECOMMS:1:1] Running Loop=1 2011-02-22T22:59:25.16910Z,1298415565.1691 [transit_3km:2.OffshoreEnvelope] Running Loop=1 2011-02-22T22:59:25.17550Z,1298415565.1755 [transit_3km:1.DepthEnvelope] Running Loop=1 2011-02-22T22:59:25.18150Z,1298415565.1815 [transit_3km:0.AltitudeEnvelope] Running Loop=1 2011-02-22T22:59:25.55930Z,1298415565.5593 [transit_3km:5.Buoyancy] Preempted 2011-02-22T22:59:25.56140Z,1298415565.5614 [transit_3km:SURFACECOMMS:1:0.SetSpeed] Running Loop=1 2011-02-22T23:00:33.53450Z,1298415633.5345 [NAL9601](IMPORTANT): GPS fix at: 1298415657 2011-02-22T23:00:33.55060Z,1298415633.5506 [transit_3km:SURFACECOMMS:1:1] Stopped 2011-02-22T23:00:33.55110Z,1298415633.5511 [transit_3km:SURFACECOMMS:1:2] Running Loop=1 2011-02-22T23:00:42.04030Z,1298415642.0403 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:00:50.91420Z,1298415650.9142 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:01:23.92890Z,1298415683.9289 [NAL9601](INFO): SBD MO Status=0, MOMSN=12761, MT Status=0, MTMSN=0 2011-02-22T23:01:24.10750Z,1298415684.1075 [transit_3km:SURFACECOMMS:1:2] Stopped 2011-02-22T23:01:24.10780Z,1298415684.1078 [transit_3km:SURFACECOMMS:1:3] Running Loop=1 2011-02-22T23:01:26.29870Z,1298415686.2987 [NAL9601](IMPORTANT): GPS fix at: 1298415710 2011-02-22T23:01:26.31450Z,1298415686.3145 [transit_3km:SURFACECOMMS:1:3] Stopped 2011-02-22T23:01:26.31520Z,1298415686.3152 [transit_3km:SURFACECOMMS:1](INFO): Completed transit_3km:SURFACECOMMS:1 2011-02-22T23:01:26.31530Z,1298415686.3153 [transit_3km:SURFACECOMMS:1] Stopped 2011-02-22T23:01:26.31540Z,1298415686.3154 [transit_3km:SURFACECOMMS:1](INFO): Aggregate::uninitialize transit_3km:SURFACECOMMS:1 2011-02-22T23:01:26.31550Z,1298415686.3155 [transit_3km:SURFACECOMMS:1:0.SetSpeed] Stopped 2011-02-22T23:01:26.31560Z,1298415686.3156 [transit_3km:SURFACECOMMS:1:0.SetSpeed](DEBUG): Uninitialize. 2011-02-22T23:01:26.31620Z,1298415686.3162 [transit_3km:SURFACECOMMS](INFO): Completed transit_3km:SURFACECOMMS 2011-02-22T23:01:26.31630Z,1298415686.3163 [transit_3km:SURFACECOMMS] Stopped 2011-02-22T23:01:26.31650Z,1298415686.3165 [transit_3km:SURFACECOMMS](INFO): Aggregate::uninitialize transit_3km:SURFACECOMMS 2011-02-22T23:01:26.31660Z,1298415686.3166 [transit_3km:SURFACECOMMS:0.GoToSurface] Stopped 2011-02-22T23:01:26.31670Z,1298415686.3167 [transit_3km:SURFACECOMMS:0.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2011-02-22T23:01:26.31690Z,1298415686.3169 [transit_3km:WaypointOne] Running Loop=1 2011-02-22T23:01:26.31710Z,1298415686.3171 [transit_3km:WaypointOne](INFO): Aggregate::initialize transit_3km:WaypointOne 2011-02-22T23:01:26.31740Z,1298415686.3174 [transit_3km:WaypointOne:0.Pitch] Running Loop=1 2011-02-22T23:01:26.31750Z,1298415686.3175 [transit_3km:WaypointOne:0.Pitch](DEBUG): Initialize. 2011-02-22T23:01:26.31800Z,1298415686.318 [transit_3km:WaypointOne:1.SetSpeed] Running Loop=1 2011-02-22T23:01:26.31810Z,1298415686.3181 [transit_3km:WaypointOne:1.SetSpeed](DEBUG): Initialize. 2011-02-22T23:01:26.31900Z,1298415686.319 [transit_3km:WaypointOne:WaypointW1.Waypoint] Running Loop=1 2011-02-22T23:01:26.31910Z,1298415686.3191 [transit_3km:WaypointOne:WaypointW1.Waypoint](DEBUG): Initialize WaypointComponent. 2011-02-22T23:01:26.70330Z,1298415686.7033 [transit_3km:WaypointOne:1.SetSpeed] Running Loop=1 2011-02-22T23:01:26.70890Z,1298415686.7089 [transit_3km:WaypointOne:0.Pitch] Running Loop=1 2011-02-22T23:01:26.71480Z,1298415686.7148 [transit_3km:5.Buoyancy] Running Loop=1 2011-02-22T23:01:32.69560Z,1298415692.6956 [NAL9601](INFO): Powering down 2011-02-22T23:01:45.14900Z,1298415705.149 [Radio_Freewave](INFO): Powering down 2011-02-22T23:01:45.94240Z,1298415705.9424 [Radio_Freewave](INFO): Powering up 2011-02-22T23:02:31.64880Z,1298415751.6488 [Radio_Freewave](INFO): Powering down 2011-02-22T23:02:39.22140Z,1298415759.2214 [Radio_Freewave](INFO): Powering up 2011-02-22T23:02:57.97110Z,1298415777.9711 [Radio_Freewave](INFO): Powering down 2011-02-22T23:02:59.56640Z,1298415779.5664 [Radio_Freewave](INFO): Powering up 2011-02-22T23:03:28.96960Z,1298415808.9696 [Radio_Freewave](INFO): Powering down 2011-02-22T23:03:40.11850Z,1298415820.1185 [Radio_Freewave](INFO): Powering up 2011-02-22T23:03:41.71880Z,1298415821.7188 [Radio_Freewave](INFO): Powering down 2011-02-22T23:21:04.81890Z,1298416864.8189 [Batt_Ocean_Server](DEBUG): Bus busy reported for battery bank#9 STATUS: 65535 2011-02-22T23:21:06.41630Z,1298416866.4163 [Batt_Ocean_Server](DEBUG): Bus busy reported for battery bank#9 STATUS: 65535 2011-02-22T23:21:08.01720Z,1298416868.0172 [Batt_Ocean_Server](DEBUG): Bus busy reported for battery bank#9 STATUS: 65535 2011-02-22T23:21:09.61640Z,1298416869.6164 [Batt_Ocean_Server](DEBUG): Bus busy reported for battery bank#9 STATUS: 65535 2011-02-22T23:21:11.21640Z,1298416871.2164 [Batt_Ocean_Server](DEBUG): Bus busy reported for battery bank#9 STATUS: 65535 2011-02-22T23:21:12.81940Z,1298416872.8194 [Batt_Ocean_Server](DEBUG): Bus busy reported for battery bank#9 STATUS: 65535 2011-02-22T23:21:14.41640Z,1298416874.4164 [Batt_Ocean_Server](DEBUG): Bus busy reported for battery bank#9 STATUS: 65535 2011-02-22T23:21:16.01680Z,1298416876.0168 [Batt_Ocean_Server](DEBUG): Bus busy reported for battery bank#9 STATUS: 65535 2011-02-22T23:21:17.61600Z,1298416877.616 [Batt_Ocean_Server](DEBUG): Bus busy reported for battery bank#9 STATUS: 65535 2011-02-22T23:21:19.21640Z,1298416879.2164 [Batt_Ocean_Server](DEBUG): Bus busy reported for battery bank#9 STATUS: 65535 2011-02-22T23:21:20.81860Z,1298416880.8186 [Batt_Ocean_Server](DEBUG): Bus busy reported for battery bank#9 STATUS: 65535 2011-02-22T23:21:22.01650Z,1298416882.0165 [Batt_Ocean_Server](DEBUG): Bus busy reported for battery bank#9 STATUS: 65535 2011-02-22T23:36:26.43270Z,1298417786.4327 [transit_3km:NeedComms] Running Loop=1 2011-02-22T23:36:26.43290Z,1298417786.4329 [transit_3km:NeedComms](INFO): Aggregate::initialize transit_3km:NeedComms 2011-02-22T23:36:26.43320Z,1298417786.4332 [transit_3km:NeedComms:NEEDCOMMS] Running Loop=1 2011-02-22T23:36:26.43340Z,1298417786.4334 [transit_3km:NeedComms:NEEDCOMMS](INFO): Aggregate::initialize transit_3km:NeedComms:NEEDCOMMS 2011-02-22T23:36:26.82090Z,1298417786.8209 [transit_3km:SURFACECOMMS] Running Loop=1 2011-02-22T23:36:26.82110Z,1298417786.8211 [transit_3km:SURFACECOMMS](INFO): Aggregate::initialize transit_3km:SURFACECOMMS 2011-02-22T23:36:26.82130Z,1298417786.8213 [transit_3km:SURFACECOMMS:0.GoToSurface] Running Loop=1 2011-02-22T23:36:26.82130Z,1298417786.8213 [transit_3km:SURFACECOMMS:0.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2011-02-22T23:37:55.62630Z,1298417875.6263 [Radio_Freewave](INFO): Powering up 2011-02-22T23:37:55.63940Z,1298417875.6394 [transit_3km:SURFACECOMMS:1] Running Loop=1 2011-02-22T23:37:55.63960Z,1298417875.6396 [transit_3km:SURFACECOMMS:1](INFO): Aggregate::initialize transit_3km:SURFACECOMMS:1 2011-02-22T23:37:55.63970Z,1298417875.6397 [transit_3km:SURFACECOMMS:1:0.SetSpeed] Running Loop=1 2011-02-22T23:37:55.63980Z,1298417875.6398 [transit_3km:SURFACECOMMS:1:0.SetSpeed](DEBUG): Initialize. 2011-02-22T23:37:55.64010Z,1298417875.6401 [transit_3km:SURFACECOMMS:1:1] Running Loop=1 2011-02-22T23:37:56.05650Z,1298417876.0565 [transit_3km:5.Buoyancy] Preempted 2011-02-22T23:37:56.42480Z,1298417876.4248 [NAL9601](INFO): Powering up 2011-02-22T23:39:02.13800Z,1298417942.138 [NAL9601](INFO): NAL9601 initialized 2011-02-22T23:39:45.22810Z,1298417985.2281 [NAL9601](IMPORTANT): GPS fix at: 1298418012 2011-02-22T23:39:45.24450Z,1298417985.2445 [transit_3km:SURFACECOMMS:1:1] Stopped 2011-02-22T23:39:45.24480Z,1298417985.2448 [transit_3km:SURFACECOMMS:1:2] Running Loop=1 2011-02-22T23:40:16.88240Z,1298418016.8824 [NAL9601](IMPORTANT): SBD MO Status=1, MOMSN=12762, MT Status=1, MTMSN=1584 2011-02-22T23:40:17.00730Z,1298418017.0073 [NAL9601](INFO): Sent 332 bytes from file Logs/20110222T222400/shore0004.lzma 2011-02-22T23:40:17.00750Z,1298418017.0075 [NAL9601](INFO): Packets left to send: 1 2011-02-22T23:40:17.00870Z,1298418017.0087 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000008 2011-02-22T23:40:17.42120Z,1298418017.4212 [NAL9601](INFO): Received command:stop 2011-02-22T23:40:17.42210Z,1298418017.4221 [CommandLine](IMPORTANT): got command stop 2011-02-22T23:40:17.44030Z,1298418017.4403 [transit_3km] Stopped 2011-02-22T23:40:17.44050Z,1298418017.4405 [transit_3km](INFO): Aggregate::uninitialize transit_3km 2011-02-22T23:40:17.44060Z,1298418017.4406 [transit_3km:0.AltitudeEnvelope] Stopped 2011-02-22T23:40:17.44070Z,1298418017.4407 [transit_3km:0.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent. 2011-02-22T23:40:17.44080Z,1298418017.4408 [transit_3km:1.DepthEnvelope] Stopped 2011-02-22T23:40:17.44090Z,1298418017.4409 [transit_3km:1.DepthEnvelope](DEBUG): Uninitialize. 2011-02-22T23:40:17.44090Z,1298418017.4409 [transit_3km:2.OffshoreEnvelope] Stopped 2011-02-22T23:40:17.44100Z,1298418017.441 [transit_3km:2.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent. 2011-02-22T23:40:17.44160Z,1298418017.4416 [transit_3km:SURFACECOMMS] Stopped 2011-02-22T23:40:17.44180Z,1298418017.4418 [transit_3km:SURFACECOMMS](INFO): Aggregate::uninitialize transit_3km:SURFACECOMMS 2011-02-22T23:40:17.44190Z,1298418017.4419 [transit_3km:SURFACECOMMS:0.GoToSurface] Stopped 2011-02-22T23:40:17.44200Z,1298418017.442 [transit_3km:SURFACECOMMS:0.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2011-02-22T23:40:17.44210Z,1298418017.4421 [transit_3km:SURFACECOMMS:1] Stopped 2011-02-22T23:40:17.44220Z,1298418017.4422 [transit_3km:SURFACECOMMS:1](INFO): Aggregate::uninitialize transit_3km:SURFACECOMMS:1 2011-02-22T23:40:17.44230Z,1298418017.4423 [transit_3km:SURFACECOMMS:1:0.SetSpeed] Stopped 2011-02-22T23:40:17.44240Z,1298418017.4424 [transit_3km:SURFACECOMMS:1:0.SetSpeed](DEBUG): Uninitialize. 2011-02-22T23:40:17.44250Z,1298418017.4425 [transit_3km:SURFACECOMMS:1:2] Stopped 2011-02-22T23:40:17.44260Z,1298418017.4426 [transit_3km:NeedComms] Stopped 2011-02-22T23:40:17.44280Z,1298418017.4428 [transit_3km:NeedComms](INFO): Aggregate::uninitialize transit_3km:NeedComms 2011-02-22T23:40:17.44290Z,1298418017.4429 [transit_3km:NeedComms:NEEDCOMMS] Stopped 2011-02-22T23:40:17.44310Z,1298418017.4431 [transit_3km:NeedComms:NEEDCOMMS](INFO): Aggregate::uninitialize transit_3km:NeedComms:NEEDCOMMS 2011-02-22T23:40:17.44320Z,1298418017.4432 [transit_3km:5.Buoyancy] Stopped 2011-02-22T23:40:17.44320Z,1298418017.4432 [transit_3km:5.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2011-02-22T23:40:17.44330Z,1298418017.4433 [transit_3km:WaypointOne] Stopped 2011-02-22T23:40:17.44350Z,1298418017.4435 [transit_3km:WaypointOne](INFO): Aggregate::uninitialize transit_3km:WaypointOne 2011-02-22T23:40:17.44360Z,1298418017.4436 [transit_3km:WaypointOne:0.Pitch] Stopped 2011-02-22T23:40:17.44360Z,1298418017.4436 [transit_3km:WaypointOne:1.SetSpeed] Stopped 2011-02-22T23:40:17.44370Z,1298418017.4437 [transit_3km:WaypointOne:1.SetSpeed](DEBUG): Uninitialize. 2011-02-22T23:40:17.44380Z,1298418017.4438 [transit_3km:WaypointOne:WaypointW1.Waypoint] Stopped 2011-02-22T23:40:17.44390Z,1298418017.4439 [transit_3km:WaypointOne:WaypointW1.Waypoint](DEBUG): Uninitialize WaypointComponent. 2011-02-22T23:40:17.77990Z,1298418017.7799 [MissionManager](IMPORTANT): Started mission Default 2011-02-22T23:40:17.78010Z,1298418017.7801 [Default] Running Loop=1 2011-02-22T23:40:17.78020Z,1298418017.7802 [Default](INFO): Aggregate::initialize Default 2011-02-22T23:40:17.78030Z,1298418017.7803 [Default:4.SetSpeed] Running Loop=1 2011-02-22T23:40:17.78040Z,1298418017.7804 [Default:4.SetSpeed](DEBUG): Initialize. 2011-02-22T23:40:17.78060Z,1298418017.7806 [Default:5.GoToSurface] Running Loop=1 2011-02-22T23:40:17.78070Z,1298418017.7807 [Default:5.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2011-02-22T23:40:17.78130Z,1298418017.7813 [Default:GPS] Running Loop=1 2011-02-22T23:40:17.78140Z,1298418017.7814 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2011-02-22T23:40:17.78150Z,1298418017.7815 [Default:GPS:0.SetSpeed] Running Loop=1 2011-02-22T23:40:17.78160Z,1298418017.7816 [Default:GPS:0.SetSpeed](DEBUG): Initialize. 2011-02-22T23:40:17.78190Z,1298418017.7819 [Default:GPS:1.GoToSurface] Running Loop=1 2011-02-22T23:40:17.78200Z,1298418017.782 [Default:GPS:1.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2011-02-22T23:40:17.78360Z,1298418017.7836 [Default:CallIridium] Running Loop=1 2011-02-22T23:40:17.78380Z,1298418017.7838 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2011-02-22T23:40:17.78400Z,1298418017.784 [Default:CallIridium:0] Running Loop=1 2011-02-22T23:40:17.78420Z,1298418017.7842 [Default:CallIridium:0](INFO): Aggregate::initialize Default:CallIridium:0 2011-02-22T23:40:17.78470Z,1298418017.7847 [Default:GPS:1.GoToSurface] Stopped 2011-02-22T23:40:17.78480Z,1298418017.7848 [Default:GPS:1.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2011-02-22T23:40:17.78500Z,1298418017.785 [Default:GPS:Read GPS] Running Loop=1 2011-02-22T23:40:18.12860Z,1298418018.1286 [Default:Iridium] Running Loop=1 2011-02-22T23:40:18.12880Z,1298418018.1288 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2011-02-22T23:40:18.12890Z,1298418018.1289 [Default:Iridium:0.SetSpeed] Running Loop=1 2011-02-22T23:40:18.12900Z,1298418018.129 [Default:Iridium:0.SetSpeed](DEBUG): Initialize. 2011-02-22T23:40:18.12930Z,1298418018.1293 [Default:Iridium:1.GoToSurface] Running Loop=1 2011-02-22T23:40:18.12940Z,1298418018.1294 [Default:Iridium:1.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2011-02-22T23:40:18.13020Z,1298418018.1302 [Default:Iridium:1.GoToSurface] Stopped 2011-02-22T23:40:18.13030Z,1298418018.1303 [Default:Iridium:1.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2011-02-22T23:40:18.13050Z,1298418018.1305 [Default:Iridium:Read Iridium] Running Loop=1 2011-02-22T23:40:19.68800Z,1298418019.688 [NAL9601](IMPORTANT): GPS fix at: 1298418047 2011-02-22T23:40:19.70500Z,1298418019.705 [Default:GPS:Read GPS] Stopped 2011-02-22T23:40:19.70560Z,1298418019.7056 [Default:GPS](INFO): Completed Default:GPS 2011-02-22T23:40:19.70570Z,1298418019.7057 [Default:GPS] Stopped 2011-02-22T23:40:19.70580Z,1298418019.7058 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2011-02-22T23:40:19.70590Z,1298418019.7059 [Default:GPS:0.SetSpeed] Stopped 2011-02-22T23:40:19.70600Z,1298418019.706 [Default:GPS:0.SetSpeed](DEBUG): Uninitialize. 2011-02-22T23:41:05.91010Z,1298418065.9101 [NAL9601](INFO): SBD MO Status=2, MOMSN=12763, MT Status=2, MTMSN=0 2011-02-22T23:41:05.91040Z,1298418065.9104 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2 2011-02-22T23:41:26.23010Z,1298418086.2301 [NAL9601](INFO): SBD MO Status=1, MOMSN=12763, MT Status=0, MTMSN=0 2011-02-22T23:41:26.40330Z,1298418086.4033 [NAL9601](INFO): Sent 112 bytes from file Logs/20110222T222400/shore0004.lzma 2011-02-22T23:41:26.40350Z,1298418086.4035 [NAL9601](INFO): Packets left to send: 0 2011-02-22T23:41:26.40540Z,1298418086.4054 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000009 2011-02-22T23:41:40.23000Z,1298418100.23 [NAL9601](INFO): SBD MO Status=2, MOMSN=12764, MT Status=2, MTMSN=0 2011-02-22T23:41:40.23020Z,1298418100.2302 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2 2011-02-22T23:41:59.65410Z,1298418119.6541 [NAL9601](INFO): SBD MO Status=2, MOMSN=12764, MT Status=2, MTMSN=0 2011-02-22T23:41:59.65440Z,1298418119.6544 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2 2011-02-22T23:42:04.27160Z,1298418124.2716 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:42:27.76610Z,1298418147.7661 [NAL9601](INFO): SBD MO Status=2, MOMSN=12764, MT Status=2, MTMSN=0 2011-02-22T23:42:27.76640Z,1298418147.7664 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2 2011-02-22T23:42:32.81120Z,1298418152.8112 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:42:35.04330Z,1298418155.0433 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:42:39.28520Z,1298418159.2852 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:42:41.46780Z,1298418161.4678 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:42:45.68350Z,1298418165.6835 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:42:55.09130Z,1298418175.0913 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:42:59.30790Z,1298418179.3079 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:43:07.94880Z,1298418187.9488 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:43:12.14070Z,1298418192.1407 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:43:16.34330Z,1298418196.3433 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:43:25.35130Z,1298418205.3513 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:43:29.59440Z,1298418209.5944 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:43:33.78740Z,1298418213.7874 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:43:35.99540Z,1298418215.9954 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:43:40.21240Z,1298418220.2124 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:43:42.42320Z,1298418222.4232 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:43:46.65940Z,1298418226.6594 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:43:48.89540Z,1298418228.8954 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:43:53.13980Z,1298418233.1398 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:43:55.40230Z,1298418235.4023 [Batt_Ocean_Server](DEBUG): Bus busy reported for battery bank#8 STATUS: 65535 2011-02-22T23:43:55.41330Z,1298418235.4133 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:43:59.62080Z,1298418239.6208 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:44:01.87580Z,1298418241.8758 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:44:06.09130Z,1298418246.0913 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:44:08.42450Z,1298418248.4245 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:44:12.78300Z,1298418252.783 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:44:14.82860Z,1298418254.8286 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:44:19.00100Z,1298418259.001 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:44:21.21740Z,1298418261.2174 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:44:25.82740Z,1298418265.8274 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:44:28.01200Z,1298418268.012 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:44:32.22330Z,1298418272.2233 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:44:34.44360Z,1298418274.4436 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:44:38.65930Z,1298418278.6593 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:44:40.90350Z,1298418280.9035 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:44:45.13960Z,1298418285.1396 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:44:47.34470Z,1298418287.3447 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:44:51.95680Z,1298418291.9568 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:44:54.15180Z,1298418294.1518 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:44:58.35660Z,1298418298.3566 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:45:00.57220Z,1298418300.5722 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:45:04.81380Z,1298418304.8138 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:45:07.04740Z,1298418307.0474 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:45:11.28890Z,1298418311.2889 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:45:20.07610Z,1298418320.0761 [Default:CallGPS] Running Loop=1 2011-02-22T23:45:20.07630Z,1298418320.0763 [Default:CallGPS](INFO): Aggregate::initialize Default:CallGPS 2011-02-22T23:45:20.07660Z,1298418320.0766 [Default:CallGPS:0] Running Loop=1 2011-02-22T23:45:20.07670Z,1298418320.0767 [Default:CallGPS:0](INFO): Aggregate::initialize Default:CallGPS:0 2011-02-22T23:45:20.97450Z,1298418320.9745 [Default:GPS] Running Loop=1 2011-02-22T23:45:20.97480Z,1298418320.9748 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2011-02-22T23:45:20.97490Z,1298418320.9749 [Default:GPS:0.SetSpeed] Running Loop=1 2011-02-22T23:45:20.97500Z,1298418320.975 [Default:GPS:0.SetSpeed](DEBUG): Initialize. 2011-02-22T23:45:20.97530Z,1298418320.9753 [Default:GPS:1.GoToSurface] Running Loop=1 2011-02-22T23:45:20.97540Z,1298418320.9754 [Default:GPS:1.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2011-02-22T23:45:20.97620Z,1298418320.9762 [Default:GPS:1.GoToSurface] Stopped 2011-02-22T23:45:20.97630Z,1298418320.9763 [Default:GPS:1.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2011-02-22T23:45:20.97650Z,1298418320.9765 [Default:GPS:Read GPS] Running Loop=1 2011-02-22T23:45:21.11710Z,1298418321.1171 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:45:22.28810Z,1298418322.2881 [NAL9601](IMPORTANT): GPS fix at: 1298418350 2011-02-22T23:45:22.30850Z,1298418322.3085 [Default:GPS:Read GPS] Stopped 2011-02-22T23:45:22.30910Z,1298418322.3091 [Default:GPS](INFO): Completed Default:GPS 2011-02-22T23:45:22.30920Z,1298418322.3092 [Default:GPS] Stopped 2011-02-22T23:45:22.30930Z,1298418322.3093 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2011-02-22T23:45:22.30940Z,1298418322.3094 [Default:GPS:0.SetSpeed] Stopped 2011-02-22T23:45:22.30950Z,1298418322.3095 [Default:GPS:0.SetSpeed](DEBUG): Uninitialize. 2011-02-22T23:45:22.76370Z,1298418322.7637 [Default:CallGPS:0](INFO): Completed Default:CallGPS:0 2011-02-22T23:45:22.76380Z,1298418322.7638 [Default:CallGPS:0] Stopped 2011-02-22T23:45:22.76400Z,1298418322.764 [Default:CallGPS:0](INFO): Aggregate::uninitialize Default:CallGPS:0 2011-02-22T23:45:22.76430Z,1298418322.7643 [Default:CallGPS](INFO): Completed Default:CallGPS 2011-02-22T23:45:22.76440Z,1298418322.7644 [Default:CallGPS] Stopped 2011-02-22T23:45:22.76450Z,1298418322.7645 [Default:CallGPS](INFO): Aggregate::uninitialize Default:CallGPS 2011-02-22T23:45:25.72100Z,1298418325.721 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:45:30.00380Z,1298418330.0038 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:45:32.12760Z,1298418332.1276 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:45:36.42260Z,1298418336.4226 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:45:38.56760Z,1298418338.5676 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:45:42.80000Z,1298418342.8 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:45:45.03700Z,1298418345.037 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:45:49.22410Z,1298418349.2241 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:45:51.43960Z,1298418351.4396 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:45:55.65140Z,1298418355.6514 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:45:57.86330Z,1298418357.8633 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:46:02.10350Z,1298418362.1035 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:46:11.20900Z,1298418371.209 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:46:15.38770Z,1298418375.3877 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:46:19.99950Z,1298418379.9995 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:46:22.20740Z,1298418382.2074 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:46:26.42370Z,1298418386.4237 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:46:28.63940Z,1298418388.6394 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:46:32.87550Z,1298418392.8755 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:46:35.11580Z,1298418395.1158 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:46:39.74890Z,1298418399.7489 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:46:41.96100Z,1298418401.961 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:46:46.15020Z,1298418406.1502 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:46:49.96090Z,1298418409.9609 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:47:00.60100Z,1298418420.601 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:47:04.85150Z,1298418424.8515 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:47:09.05940Z,1298418429.0594 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:47:11.34180Z,1298418431.3418 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:47:15.51560Z,1298418435.5156 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:47:17.81820Z,1298418437.8182 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:47:21.94380Z,1298418441.9438 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:47:24.16370Z,1298418444.1637 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:47:28.37090Z,1298418448.3709 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:47:30.58380Z,1298418450.5838 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:47:34.82340Z,1298418454.8234 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:47:37.05840Z,1298418457.0584 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:47:41.67820Z,1298418461.6782 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:47:43.88880Z,1298418463.8888 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:47:48.07570Z,1298418468.0757 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:47:50.28730Z,1298418470.2873 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:48:10.09830Z,1298418490.0983 [NAL9601](INFO): SBD MO Status=2, MOMSN=12764, MT Status=2, MTMSN=0 2011-02-22T23:48:10.09850Z,1298418490.0985 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2 2011-02-22T23:48:15.13840Z,1298418495.1384 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:48:17.37290Z,1298418497.3729 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:48:33.15830Z,1298418513.1583 [NAL9601](INFO): SBD MO Status=2, MOMSN=12764, MT Status=2, MTMSN=0 2011-02-22T23:48:33.15860Z,1298418513.1586 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2 2011-02-22T23:48:38.17570Z,1298418518.1757 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:48:41.98330Z,1298418521.9833 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:48:44.28950Z,1298418524.2895 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:48:48.43560Z,1298418528.4356 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:48:50.67700Z,1298418530.677 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:48:55.29490Z,1298418535.2949 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:48:57.50940Z,1298418537.5094 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-22T23:49:11.68200Z,1298418551.682 [NAL9601](INFO): SBD MO Status=2, MOMSN=12764, MT Status=2, MTMSN=0 2011-02-22T23:49:11.68230Z,1298418551.6823 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2 2011-02-22T23:49:23.49400Z,1298418563.494 [NAL9601](INFO): SBD MO Status=0, MOMSN=12764, MT Status=0, MTMSN=0 2011-02-22T23:49:23.67510Z,1298418563.6751 [Default:Iridium:Read Iridium] Stopped 2011-02-22T23:49:23.67570Z,1298418563.6757 [Default:Iridium](INFO): Completed Default:Iridium 2011-02-22T23:49:23.67590Z,1298418563.6759 [Default:Iridium] Stopped 2011-02-22T23:49:23.67600Z,1298418563.676 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2011-02-22T23:49:23.67610Z,1298418563.6761 [Default:Iridium:0.SetSpeed] Stopped 2011-02-22T23:49:23.67620Z,1298418563.6762 [Default:Iridium:0.SetSpeed](DEBUG): Uninitialize. 2011-02-22T23:49:23.67640Z,1298418563.6764 [Default:6.Wait] Running Loop=1 2011-02-22T23:49:23.67650Z,1298418563.6765 [Default:6.Wait](DEBUG): Initialize Wait Component. 2011-02-22T23:49:23.91240Z,1298418563.9124 [Default:CallIridium:0](INFO): Completed Default:CallIridium:0 2011-02-22T23:49:23.91250Z,1298418563.9125 [Default:CallIridium:0] Stopped 2011-02-22T23:49:23.91270Z,1298418563.9127 [Default:CallIridium:0](INFO): Aggregate::uninitialize Default:CallIridium:0 2011-02-22T23:49:23.91290Z,1298418563.9129 [Default:CallIridium](INFO): Completed Default:CallIridium 2011-02-22T23:49:23.91300Z,1298418563.913 [Default:CallIridium] Stopped 2011-02-22T23:49:23.91320Z,1298418563.9132 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2011-02-22T23:49:34.04590Z,1298418574.0459 [NAL9601](INFO): Powering down 2011-02-22T23:50:24.06050Z,1298418624.0605 [Default:CallGPS] Running Loop=1 2011-02-22T23:50:24.06070Z,1298418624.0607 [Default:CallGPS](INFO): Aggregate::initialize Default:CallGPS 2011-02-22T23:50:24.06090Z,1298418624.0609 [Default:CallGPS:0] Running Loop=1 2011-02-22T23:50:24.06110Z,1298418624.0611 [Default:CallGPS:0](INFO): Aggregate::initialize Default:CallGPS:0 2011-02-22T23:50:29.05100Z,1298418629.051 [Default:GPS] Running Loop=1 2011-02-22T23:50:29.05120Z,1298418629.0512 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2011-02-22T23:50:29.05130Z,1298418629.0513 [Default:GPS:0.SetSpeed] Running Loop=1 2011-02-22T23:50:29.05140Z,1298418629.0514 [Default:GPS:0.SetSpeed](DEBUG): Initialize. 2011-02-22T23:50:29.05170Z,1298418629.0517 [Default:GPS:1.GoToSurface] Running Loop=1 2011-02-22T23:50:29.05180Z,1298418629.0518 [Default:GPS:1.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2011-02-22T23:50:29.05270Z,1298418629.0527 [Default:GPS:1.GoToSurface] Stopped 2011-02-22T23:50:29.05280Z,1298418629.0528 [Default:GPS:1.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2011-02-22T23:50:29.05300Z,1298418629.053 [Default:GPS:Read GPS] Running Loop=1 2011-02-22T23:50:29.69260Z,1298418629.6926 [NAL9601](INFO): Powering up 2011-02-22T23:51:35.40340Z,1298418695.4034 [NAL9601](INFO): NAL9601 initialized 2011-02-22T23:51:36.55210Z,1298418696.5521 [NAL9601](IMPORTANT): GPS fix at: 1298418725 2011-02-22T23:51:36.56870Z,1298418696.5687 [Default:GPS:Read GPS] Stopped 2011-02-22T23:51:36.56920Z,1298418696.5692 [Default:GPS](INFO): Completed Default:GPS 2011-02-22T23:51:36.56940Z,1298418696.5694 [Default:GPS] Stopped 2011-02-22T23:51:36.56950Z,1298418696.5695 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2011-02-22T23:51:36.56960Z,1298418696.5696 [Default:GPS:0.SetSpeed] Stopped 2011-02-22T23:51:36.56970Z,1298418696.5697 [Default:GPS:0.SetSpeed](DEBUG): Uninitialize. 2011-02-22T23:51:36.96440Z,1298418696.9644 [Default:CallGPS:0](INFO): Completed Default:CallGPS:0 2011-02-22T23:51:36.96450Z,1298418696.9645 [Default:CallGPS:0] Stopped 2011-02-22T23:51:36.96470Z,1298418696.9647 [Default:CallGPS:0](INFO): Aggregate::uninitialize Default:CallGPS:0 2011-02-22T23:51:36.96490Z,1298418696.9649 [Default:CallGPS](INFO): Completed Default:CallGPS 2011-02-22T23:51:36.96500Z,1298418696.965 [Default:CallGPS] Stopped 2011-02-22T23:51:36.96520Z,1298418696.9652 [Default:CallGPS](INFO): Aggregate::uninitialize Default:CallGPS 2011-02-22T23:51:57.11780Z,1298418717.1178 [NAL9601](INFO): Powering down 2011-02-22T23:54:27.15020Z,1298418867.1502 [Default:CallIridium] Running Loop=1 2011-02-22T23:54:27.15040Z,1298418867.1504 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2011-02-22T23:54:27.15060Z,1298418867.1506 [Default:CallIridium:0] Running Loop=1 2011-02-22T23:54:27.15080Z,1298418867.1508 [Default:CallIridium:0](INFO): Aggregate::initialize Default:CallIridium:0 2011-02-22T23:54:32.09840Z,1298418872.0984 [Default:Iridium] Running Loop=1 2011-02-22T23:54:32.09860Z,1298418872.0986 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2011-02-22T23:54:32.09880Z,1298418872.0988 [Default:Iridium:0.SetSpeed] Running Loop=1 2011-02-22T23:54:32.09890Z,1298418872.0989 [Default:Iridium:0.SetSpeed](DEBUG): Initialize. 2011-02-22T23:54:32.09920Z,1298418872.0992 [Default:Iridium:1.GoToSurface] Running Loop=1 2011-02-22T23:54:32.09930Z,1298418872.0993 [Default:Iridium:1.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2011-02-22T23:54:32.10010Z,1298418872.1001 [Default:Iridium:1.GoToSurface] Stopped 2011-02-22T23:54:32.10020Z,1298418872.1002 [Default:Iridium:1.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2011-02-22T23:54:32.10040Z,1298418872.1004 [Default:Iridium:Read Iridium] Running Loop=1 2011-02-22T23:54:32.74860Z,1298418872.7486 [NAL9601](INFO): Powering up 2011-02-22T23:55:38.55940Z,1298418938.5594 [NAL9601](INFO): NAL9601 initialized 2011-02-22T23:56:00.30790Z,1298418960.3079 [NAL9601](INFO): SBD MO Status=2, MOMSN=12765, MT Status=2, MTMSN=0 2011-02-22T23:56:00.30820Z,1298418960.3082 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2 2011-02-22T23:56:33.27940Z,1298418993.2794 [NAL9601](INFO): SBD MO Status=1, MOMSN=12765, MT Status=0, MTMSN=0 2011-02-22T23:56:33.46330Z,1298418993.4633 [NAL9601](INFO): Sent 241 bytes from file Logs/20110222T222400/shore0005.lzma 2011-02-22T23:56:33.46350Z,1298418993.4635 [NAL9601](INFO): Packets left to send: 0 2011-02-22T23:56:33.46470Z,1298418993.4647 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000010 2011-02-22T23:56:36.86790Z,1298418996.8679 [Default:CallGPS] Running Loop=1 2011-02-22T23:56:36.86810Z,1298418996.8681 [Default:CallGPS](INFO): Aggregate::initialize Default:CallGPS 2011-02-22T23:56:36.86830Z,1298418996.8683 [Default:CallGPS:0] Running Loop=1 2011-02-22T23:56:36.86850Z,1298418996.8685 [Default:CallGPS:0](INFO): Aggregate::initialize Default:CallGPS:0 2011-02-22T23:56:37.26810Z,1298418997.2681 [Default:GPS] Running Loop=1 2011-02-22T23:56:37.26830Z,1298418997.2683 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2011-02-22T23:56:37.26840Z,1298418997.2684 [Default:GPS:0.SetSpeed] Running Loop=1 2011-02-22T23:56:37.26850Z,1298418997.2685 [Default:GPS:0.SetSpeed](DEBUG): Initialize. 2011-02-22T23:56:37.26880Z,1298418997.2688 [Default:GPS:1.GoToSurface] Running Loop=1 2011-02-22T23:56:37.26890Z,1298418997.2689 [Default:GPS:1.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2011-02-22T23:56:37.26980Z,1298418997.2698 [Default:GPS:1.GoToSurface] Stopped 2011-02-22T23:56:37.26990Z,1298418997.2699 [Default:GPS:1.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2011-02-22T23:56:37.27010Z,1298418997.2701 [Default:GPS:Read GPS] Running Loop=1 2011-02-22T23:56:42.45810Z,1298419002.4581 [NAL9601](INFO): SBD MO Status=0, MOMSN=12766, MT Status=0, MTMSN=0 2011-02-22T23:56:42.66290Z,1298419002.6629 [Default:Iridium:Read Iridium] Stopped 2011-02-22T23:56:42.66350Z,1298419002.6635 [Default:Iridium](INFO): Completed Default:Iridium 2011-02-22T23:56:42.66360Z,1298419002.6636 [Default:Iridium] Stopped 2011-02-22T23:56:42.66380Z,1298419002.6638 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2011-02-22T23:56:42.66390Z,1298419002.6639 [Default:Iridium:0.SetSpeed] Stopped 2011-02-22T23:56:42.66400Z,1298419002.664 [Default:Iridium:0.SetSpeed](DEBUG): Uninitialize. 2011-02-22T23:56:42.89380Z,1298419002.8938 [Default:CallIridium:0](INFO): Completed Default:CallIridium:0 2011-02-22T23:56:42.89390Z,1298419002.8939 [Default:CallIridium:0] Stopped 2011-02-22T23:56:42.89410Z,1298419002.8941 [Default:CallIridium:0](INFO): Aggregate::uninitialize Default:CallIridium:0 2011-02-22T23:56:42.89430Z,1298419002.8943 [Default:CallIridium](INFO): Completed Default:CallIridium 2011-02-22T23:56:42.89440Z,1298419002.8944 [Default:CallIridium] Stopped 2011-02-22T23:56:42.89460Z,1298419002.8946 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2011-02-22T23:56:43.65590Z,1298419003.6559 [NAL9601](IMPORTANT): GPS fix at: 1298419032 2011-02-22T23:56:43.67240Z,1298419003.6724 [Default:GPS:Read GPS] Stopped 2011-02-22T23:56:43.67300Z,1298419003.673 [Default:GPS](INFO): Completed Default:GPS 2011-02-22T23:56:43.67310Z,1298419003.6731 [Default:GPS] Stopped 2011-02-22T23:56:43.67330Z,1298419003.6733 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2011-02-22T23:56:43.67340Z,1298419003.6734 [Default:GPS:0.SetSpeed] Stopped 2011-02-22T23:56:43.67340Z,1298419003.6734 [Default:GPS:0.SetSpeed](DEBUG): Uninitialize. 2011-02-22T23:56:44.06840Z,1298419004.0684 [Default:CallGPS:0](INFO): Completed Default:CallGPS:0 2011-02-22T23:56:44.06850Z,1298419004.0685 [Default:CallGPS:0] Stopped 2011-02-22T23:56:44.06860Z,1298419004.0686 [Default:CallGPS:0](INFO): Aggregate::uninitialize Default:CallGPS:0 2011-02-22T23:56:44.06890Z,1298419004.0689 [Default:CallGPS](INFO): Completed Default:CallGPS 2011-02-22T23:56:44.06900Z,1298419004.069 [Default:CallGPS] Stopped 2011-02-22T23:56:44.06910Z,1298419004.0691 [Default:CallGPS](INFO): Aggregate::uninitialize Default:CallGPS 2011-02-22T23:57:04.17340Z,1298419024.1734 [NAL9601](INFO): Powering down 2011-02-23T00:01:44.20470Z,1298419304.2047 [Default:CallIridium] Running Loop=1 2011-02-23T00:01:44.20490Z,1298419304.2049 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2011-02-23T00:01:44.20520Z,1298419304.2052 [Default:CallIridium:0] Running Loop=1 2011-02-23T00:01:44.20530Z,1298419304.2053 [Default:CallIridium:0](INFO): Aggregate::initialize Default:CallIridium:0 2011-02-23T00:01:44.20550Z,1298419304.2055 [Default:CallGPS] Running Loop=1 2011-02-23T00:01:44.20570Z,1298419304.2057 [Default:CallGPS](INFO): Aggregate::initialize Default:CallGPS 2011-02-23T00:01:44.20580Z,1298419304.2058 [Default:CallGPS:0] Running Loop=1 2011-02-23T00:01:44.20600Z,1298419304.206 [Default:CallGPS:0](INFO): Aggregate::initialize Default:CallGPS:0 2011-02-23T00:01:49.20410Z,1298419309.2041 [Default:Iridium] Running Loop=1 2011-02-23T00:01:49.20430Z,1298419309.2043 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2011-02-23T00:01:49.20440Z,1298419309.2044 [Default:Iridium:0.SetSpeed] Running Loop=1 2011-02-23T00:01:49.20450Z,1298419309.2045 [Default:Iridium:0.SetSpeed](DEBUG): Initialize. 2011-02-23T00:01:49.20470Z,1298419309.2047 [Default:Iridium:1.GoToSurface] Running Loop=1 2011-02-23T00:01:49.20480Z,1298419309.2048 [Default:Iridium:1.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2011-02-23T00:01:49.20560Z,1298419309.2056 [Default:Iridium:1.GoToSurface] Stopped 2011-02-23T00:01:49.20570Z,1298419309.2057 [Default:Iridium:1.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2011-02-23T00:01:49.20590Z,1298419309.2059 [Default:Iridium:Read Iridium] Running Loop=1 2011-02-23T00:01:49.20630Z,1298419309.2063 [Default:GPS] Running Loop=1 2011-02-23T00:01:49.20650Z,1298419309.2065 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2011-02-23T00:01:49.20660Z,1298419309.2066 [Default:GPS:0.SetSpeed] Running Loop=1 2011-02-23T00:01:49.20680Z,1298419309.2068 [Default:GPS:0.SetSpeed](DEBUG): Initialize. 2011-02-23T00:01:49.20710Z,1298419309.2071 [Default:GPS:1.GoToSurface] Running Loop=1 2011-02-23T00:01:49.20720Z,1298419309.2072 [Default:GPS:1.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2011-02-23T00:01:49.20790Z,1298419309.2079 [Default:GPS:1.GoToSurface] Stopped 2011-02-23T00:01:49.20810Z,1298419309.2081 [Default:GPS:1.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2011-02-23T00:01:49.20830Z,1298419309.2083 [Default:GPS:Read GPS] Running Loop=1 2011-02-23T00:01:49.85270Z,1298419309.8527 [NAL9601](INFO): Powering up 2011-02-23T00:02:55.56340Z,1298419375.5634 [NAL9601](INFO): NAL9601 initialized 2011-02-23T00:03:12.98200Z,1298419392.982 [NAL9601](INFO): SBD MO Status=1, MOMSN=12767, MT Status=0, MTMSN=0 2011-02-23T00:03:13.12730Z,1298419393.1273 [NAL9601](INFO): Sent 122 bytes from file Logs/20110222T222400/shore0006.lzma 2011-02-23T00:03:13.12750Z,1298419393.1275 [NAL9601](INFO): Packets left to send: 0 2011-02-23T00:03:13.12860Z,1298419393.1286 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000011 2011-02-23T00:03:19.78200Z,1298419399.782 [NAL9601](INFO): SBD MO Status=2, MOMSN=12768, MT Status=2, MTMSN=0 2011-02-23T00:03:19.78220Z,1298419399.7822 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2 2011-02-23T00:03:30.01980Z,1298419410.0198 [NAL9601](INFO): SBD MO Status=0, MOMSN=12768, MT Status=0, MTMSN=0 2011-02-23T00:03:30.21500Z,1298419410.215 [Default:Iridium:Read Iridium] Stopped 2011-02-23T00:03:30.21560Z,1298419410.2156 [Default:Iridium](INFO): Completed Default:Iridium 2011-02-23T00:03:30.21570Z,1298419410.2157 [Default:Iridium] Stopped 2011-02-23T00:03:30.21590Z,1298419410.2159 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2011-02-23T00:03:30.21590Z,1298419410.2159 [Default:Iridium:0.SetSpeed] Stopped 2011-02-23T00:03:30.21600Z,1298419410.216 [Default:Iridium:0.SetSpeed](DEBUG): Uninitialize. 2011-02-23T00:03:30.40850Z,1298419410.4085 [Default:CallIridium:0](INFO): Completed Default:CallIridium:0 2011-02-23T00:03:30.40860Z,1298419410.4086 [Default:CallIridium:0] Stopped 2011-02-23T00:03:30.40870Z,1298419410.4087 [Default:CallIridium:0](INFO): Aggregate::uninitialize Default:CallIridium:0 2011-02-23T00:03:30.40900Z,1298419410.409 [Default:CallIridium](INFO): Completed Default:CallIridium 2011-02-23T00:03:30.40910Z,1298419410.4091 [Default:CallIridium] Stopped 2011-02-23T00:03:30.40920Z,1298419410.4092 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2011-02-23T00:05:59.20410Z,1298419559.2041 [NAL9601](IMPORTANT): GPS fix at: 1298419589 2011-02-23T00:05:59.22870Z,1298419559.2287 [Default:GPS:Read GPS] Stopped 2011-02-23T00:05:59.22920Z,1298419559.2292 [Default:GPS](INFO): Completed Default:GPS 2011-02-23T00:05:59.22930Z,1298419559.2293 [Default:GPS] Stopped 2011-02-23T00:05:59.22950Z,1298419559.2295 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2011-02-23T00:05:59.22960Z,1298419559.2296 [Default:GPS:0.SetSpeed] Stopped 2011-02-23T00:05:59.22960Z,1298419559.2296 [Default:GPS:0.SetSpeed](DEBUG): Uninitialize. 2011-02-23T00:05:59.60890Z,1298419559.6089 [Default:CallGPS:0](INFO): Completed Default:CallGPS:0 2011-02-23T00:05:59.60900Z,1298419559.609 [Default:CallGPS:0] Stopped 2011-02-23T00:05:59.60920Z,1298419559.6092 [Default:CallGPS:0](INFO): Aggregate::uninitialize Default:CallGPS:0 2011-02-23T00:05:59.60940Z,1298419559.6094 [Default:CallGPS](INFO): Completed Default:CallGPS 2011-02-23T00:05:59.60950Z,1298419559.6095 [Default:CallGPS] Stopped 2011-02-23T00:05:59.60970Z,1298419559.6097 [Default:CallGPS](INFO): Aggregate::uninitialize Default:CallGPS 2011-02-23T00:06:19.72620Z,1298419579.7262 [NAL9601](INFO): Powering down 2011-02-23T00:08:34.72820Z,1298419714.7282 [Default:CallIridium] Running Loop=1 2011-02-23T00:08:34.72840Z,1298419714.7284 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2011-02-23T00:08:34.72860Z,1298419714.7286 [Default:CallIridium:0] Running Loop=1 2011-02-23T00:08:34.72880Z,1298419714.7288 [Default:CallIridium:0](INFO): Aggregate::initialize Default:CallIridium:0 2011-02-23T00:08:39.76550Z,1298419719.7655 [Default:Iridium] Running Loop=1 2011-02-23T00:08:39.76570Z,1298419719.7657 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2011-02-23T00:08:39.76590Z,1298419719.7659 [Default:Iridium:0.SetSpeed] Running Loop=1 2011-02-23T00:08:39.76600Z,1298419719.766 [Default:Iridium:0.SetSpeed](DEBUG): Initialize. 2011-02-23T00:08:39.76620Z,1298419719.7662 [Default:Iridium:1.GoToSurface] Running Loop=1 2011-02-23T00:08:39.76630Z,1298419719.7663 [Default:Iridium:1.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2011-02-23T00:08:39.76840Z,1298419719.7684 [Default:Iridium:1.GoToSurface] Stopped 2011-02-23T00:08:39.76850Z,1298419719.7685 [Default:Iridium:1.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2011-02-23T00:08:39.76870Z,1298419719.7687 [Default:Iridium:Read Iridium] Running Loop=1 2011-02-23T00:08:40.39260Z,1298419720.3926 [NAL9601](INFO): Powering up 2011-02-23T00:09:46.10350Z,1298419786.1035 [NAL9601](INFO): NAL9601 initialized 2011-02-23T00:10:03.97180Z,1298419803.9718 [NAL9601](INFO): SBD MO Status=1, MOMSN=12769, MT Status=0, MTMSN=0 2011-02-23T00:10:04.16330Z,1298419804.1633 [NAL9601](INFO): Sent 121 bytes from file Logs/20110222T222400/shore0007.lzma 2011-02-23T00:10:04.16360Z,1298419804.1636 [NAL9601](INFO): Packets left to send: 0 2011-02-23T00:10:04.16470Z,1298419804.1647 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000012 2011-02-23T00:10:12.32220Z,1298419812.3222 [NAL9601](INFO): SBD MO Status=0, MOMSN=12770, MT Status=0, MTMSN=0 2011-02-23T00:10:12.46960Z,1298419812.4696 [Default:Iridium:Read Iridium] Stopped 2011-02-23T00:10:12.47020Z,1298419812.4702 [Default:Iridium](INFO): Completed Default:Iridium 2011-02-23T00:10:12.47030Z,1298419812.4703 [Default:Iridium] Stopped 2011-02-23T00:10:12.47050Z,1298419812.4705 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2011-02-23T00:10:12.47060Z,1298419812.4706 [Default:Iridium:0.SetSpeed] Stopped 2011-02-23T00:10:12.47060Z,1298419812.4706 [Default:Iridium:0.SetSpeed](DEBUG): Uninitialize. 2011-02-23T00:10:12.75900Z,1298419812.759 [Default:CallIridium:0](INFO): Completed Default:CallIridium:0 2011-02-23T00:10:12.75910Z,1298419812.7591 [Default:CallIridium:0] Stopped 2011-02-23T00:10:12.75930Z,1298419812.7593 [Default:CallIridium:0](INFO): Aggregate::uninitialize Default:CallIridium:0 2011-02-23T00:10:12.75950Z,1298419812.7595 [Default:CallIridium](INFO): Completed Default:CallIridium 2011-02-23T00:10:12.75960Z,1298419812.7596 [Default:CallIridium] Stopped 2011-02-23T00:10:12.75980Z,1298419812.7598 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2011-02-23T00:10:22.79700Z,1298419822.797 [NAL9601](INFO): Powering down 2011-02-23T00:11:02.81680Z,1298419862.8168 [Default:CallGPS] Running Loop=1 2011-02-23T00:11:02.81700Z,1298419862.817 [Default:CallGPS](INFO): Aggregate::initialize Default:CallGPS 2011-02-23T00:11:02.81720Z,1298419862.8172 [Default:CallGPS:0] Running Loop=1 2011-02-23T00:11:02.81730Z,1298419862.8173 [Default:CallGPS:0](INFO): Aggregate::initialize Default:CallGPS:0 2011-02-23T00:11:07.86880Z,1298419867.8688 [Default:GPS] Running Loop=1 2011-02-23T00:11:07.86900Z,1298419867.869 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2011-02-23T00:11:07.86910Z,1298419867.8691 [Default:GPS:0.SetSpeed] Running Loop=1 2011-02-23T00:11:07.86920Z,1298419867.8692 [Default:GPS:0.SetSpeed](DEBUG): Initialize. 2011-02-23T00:11:07.86950Z,1298419867.8695 [Default:GPS:1.GoToSurface] Running Loop=1 2011-02-23T00:11:07.86960Z,1298419867.8696 [Default:GPS:1.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2011-02-23T00:11:07.87030Z,1298419867.8703 [Default:GPS:1.GoToSurface] Stopped 2011-02-23T00:11:07.87050Z,1298419867.8705 [Default:GPS:1.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2011-02-23T00:11:07.87070Z,1298419867.8707 [Default:GPS:Read GPS] Running Loop=1 2011-02-23T00:11:08.51650Z,1298419868.5165 [NAL9601](INFO): Powering up 2011-02-23T00:12:14.22740Z,1298419934.2274 [NAL9601](INFO): NAL9601 initialized 2011-02-23T00:12:15.31980Z,1298419935.3198 [NAL9601](IMPORTANT): GPS fix at: 1298419965 2011-02-23T00:12:15.33630Z,1298419935.3363 [Default:GPS:Read GPS] Stopped 2011-02-23T00:12:15.33700Z,1298419935.337 [Default:GPS](INFO): Completed Default:GPS 2011-02-23T00:12:15.33710Z,1298419935.3371 [Default:GPS] Stopped 2011-02-23T00:12:15.33720Z,1298419935.3372 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2011-02-23T00:12:15.33730Z,1298419935.3373 [Default:GPS:0.SetSpeed] Stopped 2011-02-23T00:12:15.33740Z,1298419935.3374 [Default:GPS:0.SetSpeed](DEBUG): Uninitialize. 2011-02-23T00:12:15.73270Z,1298419935.7327 [Default:CallGPS:0](INFO): Completed Default:CallGPS:0 2011-02-23T00:12:15.73280Z,1298419935.7328 [Default:CallGPS:0] Stopped 2011-02-23T00:12:15.73300Z,1298419935.733 [Default:CallGPS:0](INFO): Aggregate::uninitialize Default:CallGPS:0 2011-02-23T00:12:15.73320Z,1298419935.7332 [Default:CallGPS](INFO): Completed Default:CallGPS 2011-02-23T00:12:15.73330Z,1298419935.7333 [Default:CallGPS] Stopped 2011-02-23T00:12:15.73350Z,1298419935.7335 [Default:CallGPS](INFO): Aggregate::uninitialize Default:CallGPS 2011-02-23T00:12:35.85360Z,1298419955.8536 [NAL9601](INFO): Powering down 2011-02-23T00:15:15.86890Z,1298420115.8689 [Default:CallIridium] Running Loop=1 2011-02-23T00:15:15.86910Z,1298420115.8691 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2011-02-23T00:15:15.86940Z,1298420115.8694 [Default:CallIridium:0] Running Loop=1 2011-02-23T00:15:15.86950Z,1298420115.8695 [Default:CallIridium:0](INFO): Aggregate::initialize Default:CallIridium:0 2011-02-23T00:15:20.86860Z,1298420120.8686 [Default:Iridium] Running Loop=1 2011-02-23T00:15:20.86880Z,1298420120.8688 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2011-02-23T00:15:20.86900Z,1298420120.869 [Default:Iridium:0.SetSpeed] Running Loop=1 2011-02-23T00:15:20.86910Z,1298420120.8691 [Default:Iridium:0.SetSpeed](DEBUG): Initialize. 2011-02-23T00:15:20.86930Z,1298420120.8693 [Default:Iridium:1.GoToSurface] Running Loop=1 2011-02-23T00:15:20.86940Z,1298420120.8694 [Default:Iridium:1.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2011-02-23T00:15:20.87030Z,1298420120.8703 [Default:Iridium:1.GoToSurface] Stopped 2011-02-23T00:15:20.87040Z,1298420120.8704 [Default:Iridium:1.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2011-02-23T00:15:20.87060Z,1298420120.8706 [Default:Iridium:Read Iridium] Running Loop=1 2011-02-23T00:15:21.52060Z,1298420121.5206 [NAL9601](INFO): Powering up 2011-02-23T00:16:27.33140Z,1298420187.3314 [NAL9601](INFO): NAL9601 initialized 2011-02-23T00:16:57.57040Z,1298420217.5704 [NAL9601](IMPORTANT): SBD MO Status=1, MOMSN=12771, MT Status=1, MTMSN=1585 2011-02-23T00:16:57.77530Z,1298420217.7753 [NAL9601](INFO): Sent 122 bytes from file Logs/20110222T222400/shore0008.lzma 2011-02-23T00:16:57.77560Z,1298420217.7756 [NAL9601](INFO): Packets left to send: 0 2011-02-23T00:16:57.77670Z,1298420217.7767 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000013 2011-02-23T00:16:58.32040Z,1298420218.3204 [NAL9601](IMPORTANT): Initialized file: Config/lrauv-tethys/Sensor.cfg 2011-02-23T00:17:00.47360Z,1298420220.4736 [NAL9601](IMPORTANT): Success executing cat Logs/latest/4D64502E.part | gunzip -f -d | cat `cp Config/lrauv-tethys/.svn/text-base/Sensor.cfg.svn-base Config/lrauv-tethys/Sensor.cfg` | vim -e Config/lrauv-tethys/Sensor.cfg 2011-02-23T00:17:00.53650Z,1298420220.5365 [CommandLine](IMPORTANT): f246eab858122c8cb8a59793975829c9 Config/lrauv-tethys/Sensor.cfg 2011-02-23T00:17:14.18260Z,1298420234.1826 [NAL9601](INFO): SBD MO Status=2, MOMSN=12772, MT Status=2, MTMSN=0 2011-02-23T00:17:14.18290Z,1298420234.1829 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2 2011-02-23T00:17:15.34050Z,1298420235.3405 [Default:CallGPS] Running Loop=1 2011-02-23T00:17:15.34070Z,1298420235.3407 [Default:CallGPS](INFO): Aggregate::initialize Default:CallGPS 2011-02-23T00:17:15.34090Z,1298420235.3409 [Default:CallGPS:0] Running Loop=1 2011-02-23T00:17:15.34110Z,1298420235.3411 [Default:CallGPS:0](INFO): Aggregate::initialize Default:CallGPS:0 2011-02-23T00:17:15.74040Z,1298420235.7404 [Default:GPS] Running Loop=1 2011-02-23T00:17:15.74060Z,1298420235.7406 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2011-02-23T00:17:15.74080Z,1298420235.7408 [Default:GPS:0.SetSpeed] Running Loop=1 2011-02-23T00:17:15.74080Z,1298420235.7408 [Default:GPS:0.SetSpeed](DEBUG): Initialize. 2011-02-23T00:17:15.74110Z,1298420235.7411 [Default:GPS:1.GoToSurface] Running Loop=1 2011-02-23T00:17:15.74120Z,1298420235.7412 [Default:GPS:1.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2011-02-23T00:17:15.74210Z,1298420235.7421 [Default:GPS:1.GoToSurface] Stopped 2011-02-23T00:17:15.74220Z,1298420235.7422 [Default:GPS:1.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2011-02-23T00:17:15.74240Z,1298420235.7424 [Default:GPS:Read GPS] Running Loop=1 2011-02-23T00:17:28.36210Z,1298420248.3621 [NAL9601](INFO): SBD MO Status=0, MOMSN=12772, MT Status=0, MTMSN=0 2011-02-23T00:17:28.54320Z,1298420248.5432 [Default:Iridium:Read Iridium] Stopped 2011-02-23T00:17:28.54380Z,1298420248.5438 [Default:Iridium](INFO): Completed Default:Iridium 2011-02-23T00:17:28.54390Z,1298420248.5439 [Default:Iridium] Stopped 2011-02-23T00:17:28.54410Z,1298420248.5441 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2011-02-23T00:17:28.54420Z,1298420248.5442 [Default:Iridium:0.SetSpeed] Stopped 2011-02-23T00:17:28.54430Z,1298420248.5443 [Default:Iridium:0.SetSpeed](DEBUG): Uninitialize. 2011-02-23T00:17:28.77600Z,1298420248.776 [Default:CallIridium:0](INFO): Completed Default:CallIridium:0 2011-02-23T00:17:28.77610Z,1298420248.7761 [Default:CallIridium:0] Stopped 2011-02-23T00:17:28.77620Z,1298420248.7762 [Default:CallIridium:0](INFO): Aggregate::uninitialize Default:CallIridium:0 2011-02-23T00:17:28.77650Z,1298420248.7765 [Default:CallIridium](INFO): Completed Default:CallIridium 2011-02-23T00:17:28.77660Z,1298420248.7766 [Default:CallIridium] Stopped 2011-02-23T00:17:28.77670Z,1298420248.7767 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2011-02-23T00:17:29.56830Z,1298420249.5683 [NAL9601](IMPORTANT): GPS fix at: 1298420280 2011-02-23T00:17:29.58500Z,1298420249.585 [Default:GPS:Read GPS] Stopped 2011-02-23T00:17:29.58570Z,1298420249.5857 [Default:GPS](INFO): Completed Default:GPS 2011-02-23T00:17:29.58580Z,1298420249.5858 [Default:GPS] Stopped 2011-02-23T00:17:29.58590Z,1298420249.5859 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2011-02-23T00:17:29.58600Z,1298420249.586 [Default:GPS:0.SetSpeed] Stopped 2011-02-23T00:17:29.58610Z,1298420249.5861 [Default:GPS:0.SetSpeed](DEBUG): Uninitialize. 2011-02-23T00:17:29.98130Z,1298420249.9813 [Default:CallGPS:0](INFO): Completed Default:CallGPS:0 2011-02-23T00:17:29.98140Z,1298420249.9814 [Default:CallGPS:0] Stopped 2011-02-23T00:17:29.98160Z,1298420249.9816 [Default:CallGPS:0](INFO): Aggregate::uninitialize Default:CallGPS:0 2011-02-23T00:17:29.98180Z,1298420249.9818 [Default:CallGPS](INFO): Completed Default:CallGPS 2011-02-23T00:17:29.98190Z,1298420249.9819 [Default:CallGPS] Stopped 2011-02-23T00:17:29.98210Z,1298420249.9821 [Default:CallGPS](INFO): Aggregate::uninitialize Default:CallGPS 2011-02-23T00:17:50.09390Z,1298420270.0939 [NAL9601](INFO): Powering down 2011-02-23T00:18:45.11670Z,1298420325.1167 [Batt_Ocean_Server](DEBUG): Bus busy reported for battery bank#8 STATUS: 65535 2011-02-23T00:18:50.09390Z,1298420330.0939 [Batt_Ocean_Server](DEBUG): Bus busy reported for battery bank#8 STATUS: 65535 2011-02-23T00:18:55.09410Z,1298420335.0941 [Batt_Ocean_Server](DEBUG): Bus busy reported for battery bank#8 STATUS: 65535 2011-02-23T00:19:00.04030Z,1298420340.0403 [Batt_Ocean_Server](DEBUG): Bus busy reported for battery bank#8 STATUS: 65535 2011-02-23T00:19:05.11870Z,1298420345.1187 [Batt_Ocean_Server](DEBUG): Bus busy reported for battery bank#8 STATUS: 65535 2011-02-23T00:19:10.09360Z,1298420350.0936 [Batt_Ocean_Server](DEBUG): Bus busy reported for battery bank#8 STATUS: 65535 2011-02-23T00:19:15.04090Z,1298420355.0409 [Batt_Ocean_Server](DEBUG): Bus busy reported for battery bank#8 STATUS: 65535 2011-02-23T00:19:20.09370Z,1298420360.0937 [Batt_Ocean_Server](DEBUG): Bus busy reported for battery bank#8 STATUS: 65535 2011-02-23T00:19:25.09400Z,1298420365.094 [Batt_Ocean_Server](DEBUG): Bus busy reported for battery bank#8 STATUS: 65535 2011-02-23T00:22:30.05650Z,1298420550.0565 [Default:CallIridium] Running Loop=1 2011-02-23T00:22:30.05670Z,1298420550.0567 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2011-02-23T00:22:30.05690Z,1298420550.0569 [Default:CallIridium:0] Running Loop=1 2011-02-23T00:22:30.05710Z,1298420550.0571 [Default:CallIridium:0](INFO): Aggregate::initialize Default:CallIridium:0 2011-02-23T00:22:30.05730Z,1298420550.0573 [Default:CallGPS] Running Loop=1 2011-02-23T00:22:30.05740Z,1298420550.0574 [Default:CallGPS](INFO): Aggregate::initialize Default:CallGPS 2011-02-23T00:22:30.05760Z,1298420550.0576 [Default:CallGPS:0] Running Loop=1 2011-02-23T00:22:30.05780Z,1298420550.0578 [Default:CallGPS:0](INFO): Aggregate::initialize Default:CallGPS:0 2011-02-23T00:22:35.10900Z,1298420555.109 [Default:Iridium] Running Loop=1 2011-02-23T00:22:35.10920Z,1298420555.1092 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2011-02-23T00:22:35.10930Z,1298420555.1093 [Default:Iridium:0.SetSpeed] Running Loop=1 2011-02-23T00:22:35.10940Z,1298420555.1094 [Default:Iridium:0.SetSpeed](DEBUG): Initialize. 2011-02-23T00:22:35.10970Z,1298420555.1097 [Default:Iridium:1.GoToSurface] Running Loop=1 2011-02-23T00:22:35.10980Z,1298420555.1098 [Default:Iridium:1.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2011-02-23T00:22:35.11060Z,1298420555.1106 [Default:Iridium:1.GoToSurface] Stopped 2011-02-23T00:22:35.11090Z,1298420555.1109 [Default:Iridium:1.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2011-02-23T00:22:35.11120Z,1298420555.1112 [Default:Iridium:Read Iridium] Running Loop=1 2011-02-23T00:22:35.11160Z,1298420555.1116 [Default:GPS] Running Loop=1 2011-02-23T00:22:35.11180Z,1298420555.1118 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2011-02-23T00:22:35.11190Z,1298420555.1119 [Default:GPS:0.SetSpeed] Running Loop=1 2011-02-23T00:22:35.11200Z,1298420555.112 [Default:GPS:0.SetSpeed](DEBUG): Initialize. 2011-02-23T00:22:35.11230Z,1298420555.1123 [Default:GPS:1.GoToSurface] Running Loop=1 2011-02-23T00:22:35.11240Z,1298420555.1124 [Default:GPS:1.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2011-02-23T00:22:35.11320Z,1298420555.1132 [Default:GPS:1.GoToSurface] Stopped 2011-02-23T00:22:35.11330Z,1298420555.1133 [Default:GPS:1.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2011-02-23T00:22:35.11350Z,1298420555.1135 [Default:GPS:Read GPS] Running Loop=1 2011-02-23T00:22:35.76050Z,1298420555.7605 [NAL9601](INFO): Powering up 2011-02-23T00:23:41.47140Z,1298420621.4714 [NAL9601](INFO): NAL9601 initialized 2011-02-23T00:24:12.78170Z,1298420652.7817 [NAL9601](INFO): SBD MO Status=1, MOMSN=12773, MT Status=0, MTMSN=0 2011-02-23T00:24:12.91140Z,1298420652.9114 [NAL9601](INFO): Sent 332 bytes from file Logs/20110222T222400/shore0009.lzma 2011-02-23T00:24:12.91170Z,1298420652.9117 [NAL9601](INFO): Packets left to send: 1 2011-02-23T00:24:12.91280Z,1298420652.9128 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000014 2011-02-23T00:24:29.29410Z,1298420669.2941 [NAL9601](INFO): SBD MO Status=2, MOMSN=12774, MT Status=2, MTMSN=0 2011-02-23T00:24:29.29440Z,1298420669.2944 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2 2011-02-23T00:24:47.24200Z,1298420687.242 [NAL9601](INFO): SBD MO Status=2, MOMSN=12774, MT Status=2, MTMSN=0 2011-02-23T00:24:47.24230Z,1298420687.2423 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2 2011-02-23T00:25:04.79420Z,1298420704.7942 [NAL9601](INFO): SBD MO Status=2, MOMSN=12774, MT Status=2, MTMSN=0 2011-02-23T00:25:04.79440Z,1298420704.7944 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2 2011-02-23T00:25:21.93800Z,1298420721.938 [NAL9601](INFO): SBD MO Status=2, MOMSN=12774, MT Status=2, MTMSN=0 2011-02-23T00:25:21.93820Z,1298420721.9382 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2 2011-02-23T00:25:47.49790Z,1298420747.4979 [NAL9601](INFO): SBD MO Status=2, MOMSN=12774, MT Status=2, MTMSN=0 2011-02-23T00:25:47.49820Z,1298420747.4982 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2 2011-02-23T00:26:12.49410Z,1298420772.4941 [NAL9601](INFO): SBD MO Status=1, MOMSN=12774, MT Status=0, MTMSN=0 2011-02-23T00:26:12.62730Z,1298420772.6273 [NAL9601](INFO): Sent 26 bytes from file Logs/20110222T222400/shore0009.lzma 2011-02-23T00:26:12.62760Z,1298420772.6276 [NAL9601](INFO): Packets left to send: 0 2011-02-23T00:26:12.62870Z,1298420772.6287 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000015 2011-02-23T00:26:30.09420Z,1298420790.0942 [NAL9601](INFO): SBD MO Status=2, MOMSN=12775, MT Status=2, MTMSN=0 2011-02-23T00:26:30.09450Z,1298420790.0945 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2 2011-02-23T00:26:31.29630Z,1298420791.2963 [NAL9601](IMPORTANT): GPS fix at: 1298420823 2011-02-23T00:26:31.31390Z,1298420791.3139 [Default:GPS:Read GPS] Stopped 2011-02-23T00:26:31.31440Z,1298420791.3144 [Default:GPS](INFO): Completed Default:GPS 2011-02-23T00:26:31.31450Z,1298420791.3145 [Default:GPS] Stopped 2011-02-23T00:26:31.31460Z,1298420791.3146 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2011-02-23T00:26:31.31490Z,1298420791.3149 [Default:GPS:0.SetSpeed] Stopped 2011-02-23T00:26:31.31500Z,1298420791.315 [Default:GPS:0.SetSpeed](DEBUG): Uninitialize. 2011-02-23T00:26:31.76260Z,1298420791.7626 [Default:CallGPS:0](INFO): Completed Default:CallGPS:0 2011-02-23T00:26:31.76280Z,1298420791.7628 [Default:CallGPS:0] Stopped 2011-02-23T00:26:31.76290Z,1298420791.7629 [Default:CallGPS:0](INFO): Aggregate::uninitialize Default:CallGPS:0 2011-02-23T00:26:31.76320Z,1298420791.7632 [Default:CallGPS](INFO): Completed Default:CallGPS 2011-02-23T00:26:31.76330Z,1298420791.7633 [Default:CallGPS] Stopped 2011-02-23T00:26:31.76340Z,1298420791.7634 [Default:CallGPS](INFO): Aggregate::uninitialize Default:CallGPS 2011-02-23T00:26:35.13320Z,1298420795.1332 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-23T00:26:39.54710Z,1298420799.5471 [NAL9601](ERROR): Inadequate Iridium signal strength reported: 0 2011-02-23T00:26:56.79410Z,1298420816.7941 [NAL9601](INFO): SBD MO Status=2, MOMSN=12775, MT Status=2, MTMSN=0 2011-02-23T00:26:56.79440Z,1298420816.7944 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2 2011-02-23T00:27:14.23020Z,1298420834.2302 [NAL9601](INFO): SBD MO Status=2, MOMSN=12775, MT Status=2, MTMSN=0 2011-02-23T00:27:14.23050Z,1298420834.2305 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2 2011-02-23T00:27:31.24620Z,1298420851.2462 [NAL9601](INFO): SBD MO Status=2, MOMSN=12775, MT Status=2, MTMSN=0 2011-02-23T00:27:31.24650Z,1298420851.2465 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2 2011-02-23T00:27:54.25800Z,1298420874.258 [NAL9601](INFO): SBD MO Status=2, MOMSN=12775, MT Status=2, MTMSN=0 2011-02-23T00:27:54.25830Z,1298420874.2583 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2 2011-02-23T00:28:12.20380Z,1298420892.2038 [NAL9601](INFO): SBD MO Status=0, MOMSN=12775, MT Status=0, MTMSN=0 2011-02-23T00:28:12.35540Z,1298420892.3554 [Default:Iridium:Read Iridium] Stopped 2011-02-23T00:28:12.35590Z,1298420892.3559 [Default:Iridium](INFO): Completed Default:Iridium 2011-02-23T00:28:12.35600Z,1298420892.356 [Default:Iridium] Stopped 2011-02-23T00:28:12.35620Z,1298420892.3562 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2011-02-23T00:28:12.35630Z,1298420892.3563 [Default:Iridium:0.SetSpeed] Stopped 2011-02-23T00:28:12.35640Z,1298420892.3564 [Default:Iridium:0.SetSpeed](DEBUG): Uninitialize. 2011-02-23T00:28:12.58970Z,1298420892.5897 [Default:CallIridium:0](INFO): Completed Default:CallIridium:0 2011-02-23T00:28:12.58980Z,1298420892.5898 [Default:CallIridium:0] Stopped 2011-02-23T00:28:12.58990Z,1298420892.5899 [Default:CallIridium:0](INFO): Aggregate::uninitialize Default:CallIridium:0 2011-02-23T00:28:12.59020Z,1298420892.5902 [Default:CallIridium](INFO): Completed Default:CallIridium 2011-02-23T00:28:12.59030Z,1298420892.5903 [Default:CallIridium] Stopped 2011-02-23T00:28:12.59040Z,1298420892.5904 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2011-02-23T00:28:22.68220Z,1298420902.6822 [NAL9601](INFO): Powering down 2011-02-23T00:31:32.64460Z,1298421092.6446 [Default:CallGPS] Running Loop=1 2011-02-23T00:31:32.64480Z,1298421092.6448 [Default:CallGPS](INFO): Aggregate::initialize Default:CallGPS 2011-02-23T00:31:32.64500Z,1298421092.645 [Default:CallGPS:0] Running Loop=1 2011-02-23T00:31:32.64520Z,1298421092.6452 [Default:CallGPS:0](INFO): Aggregate::initialize Default:CallGPS:0 2011-02-23T00:31:37.69790Z,1298421097.6979 [Default:GPS] Running Loop=1 2011-02-23T00:31:37.69810Z,1298421097.6981 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2011-02-23T00:31:37.69820Z,1298421097.6982 [Default:GPS:0.SetSpeed] Running Loop=1 2011-02-23T00:31:37.69830Z,1298421097.6983 [Default:GPS:0.SetSpeed](DEBUG): Initialize. 2011-02-23T00:31:37.69860Z,1298421097.6986 [Default:GPS:1.GoToSurface] Running Loop=1 2011-02-23T00:31:37.69870Z,1298421097.6987 [Default:GPS:1.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2011-02-23T00:31:37.69960Z,1298421097.6996 [Default:GPS:1.GoToSurface] Stopped 2011-02-23T00:31:37.69970Z,1298421097.6997 [Default:GPS:1.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2011-02-23T00:31:37.69990Z,1298421097.6999 [Default:GPS:Read GPS] Running Loop=1 2011-02-23T00:31:38.34850Z,1298421098.3485 [NAL9601](INFO): Powering up 2011-02-23T00:32:44.05940Z,1298421164.0594 [NAL9601](INFO): NAL9601 initialized 2011-02-23T00:33:12.36430Z,1298421192.3643 [Default:CallIridium] Running Loop=1 2011-02-23T00:33:12.36450Z,1298421192.3645 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2011-02-23T00:33:12.36470Z,1298421192.3647 [Default:CallIridium:0] Running Loop=1 2011-02-23T00:33:12.36490Z,1298421192.3649 [Default:CallIridium:0](INFO): Aggregate::initialize Default:CallIridium:0 2011-02-23T00:33:12.79010Z,1298421192.7901 [Default:Iridium] Running Loop=1 2011-02-23T00:33:12.79030Z,1298421192.7903 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2011-02-23T00:33:12.79040Z,1298421192.7904 [Default:Iridium:0.SetSpeed] Running Loop=1 2011-02-23T00:33:12.79050Z,1298421192.7905 [Default:Iridium:0.SetSpeed](DEBUG): Initialize. 2011-02-23T00:33:12.79080Z,1298421192.7908 [Default:Iridium:1.GoToSurface] Running Loop=1 2011-02-23T00:33:12.79090Z,1298421192.7909 [Default:Iridium:1.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2011-02-23T00:33:12.79170Z,1298421192.7917 [Default:Iridium:1.GoToSurface] Stopped 2011-02-23T00:33:12.79180Z,1298421192.7918 [Default:Iridium:1.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2011-02-23T00:33:12.79200Z,1298421192.792 [Default:Iridium:Read Iridium] Running Loop=1 2011-02-23T00:33:37.09810Z,1298421217.0981 [NAL9601](IMPORTANT): SBD MO Status=1, MOMSN=12776, MT Status=1, MTMSN=1586 2011-02-23T00:33:37.26730Z,1298421217.2673 [NAL9601](INFO): Sent 138 bytes from file Logs/20110222T222400/shore0010.lzma 2011-02-23T00:33:37.26760Z,1298421217.2676 [NAL9601](INFO): Packets left to send: 0 2011-02-23T00:33:37.26880Z,1298421217.2688 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000016 2011-02-23T00:33:37.67720Z,1298421217.6772 [NAL9601](INFO): Received command:restart 2011-02-23T00:33:37.67840Z,1298421217.6784 [CommandLine](IMPORTANT): got command restart 2011-02-23T00:33:37.81480Z,1298421217.8148 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2011-02-23T00:33:38.13720Z,1298421218.1372 [AsyncPiEstimator](DEBUG): Uninitialize AsyncPiEstimator. 2011-02-23T00:33:38.35690Z,1298421218.3569 [controlThread](DEBUG): Uninitializing ControlThread 2011-02-23T00:33:38.35760Z,1298421218.3576 [AHRS_sp3003D](INFO): Powering down 2011-02-23T00:33:38.44340Z,1298421218.4434 [AHRS_3DMGX3](INFO): Powering down 2011-02-23T00:33:38.44470Z,1298421218.4447 [DVL_micro](INFO): Powering down 2011-02-23T00:33:38.44510Z,1298421218.4451 [NAL9601](INFO): Powering down 2011-02-23T00:33:38.44610Z,1298421218.4461 [CTD_NeilBrown](INFO): Powering down 2011-02-23T00:33:38.44650Z,1298421218.4465 [WetLabsBB2FL](INFO): Powering down 2011-02-23T00:33:38.44710Z,1298421218.4471 [Aanderaa_O2](INFO): Powering down 2011-02-23T00:33:38.44800Z,1298421218.448 [Bathymetry](DEBUG): Uninitialize Bathymetry Derivation. 2011-02-23T00:33:38.45000Z,1298421218.45 [Default] Stopped 2011-02-23T00:33:38.45020Z,1298421218.4502 [Default](INFO): Aggregate::uninitialize Default 2011-02-23T00:33:38.45030Z,1298421218.4503 [Default:GPS] Stopped 2011-02-23T00:33:38.45040Z,1298421218.4504 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2011-02-23T00:33:38.45050Z,1298421218.4505 [Default:GPS:0.SetSpeed] Stopped 2011-02-23T00:33:38.45060Z,1298421218.4506 [Default:GPS:0.SetSpeed](DEBUG): Uninitialize. 2011-02-23T00:33:38.45080Z,1298421218.4508 [Default:GPS:Read GPS] Stopped 2011-02-23T00:33:38.45080Z,1298421218.4508 [Default:Iridium] Stopped 2011-02-23T00:33:38.45100Z,1298421218.451 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2011-02-23T00:33:38.45110Z,1298421218.4511 [Default:Iridium:0.SetSpeed] Stopped 2011-02-23T00:33:38.45120Z,1298421218.4512 [Default:Iridium:0.SetSpeed](DEBUG): Uninitialize. 2011-02-23T00:33:38.45130Z,1298421218.4513 [Default:Iridium:Read Iridium] Stopped 2011-02-23T00:33:38.45140Z,1298421218.4514 [Default:CallGPS] Stopped 2011-02-23T00:33:38.45150Z,1298421218.4515 [Default:CallGPS](INFO): Aggregate::uninitialize Default:CallGPS 2011-02-23T00:33:38.45160Z,1298421218.4516 [Default:CallGPS:0] Stopped 2011-02-23T00:33:38.45170Z,1298421218.4517 [Default:CallGPS:0](INFO): Aggregate::uninitialize Default:CallGPS:0 2011-02-23T00:33:38.45180Z,1298421218.4518 [Default:CallIridium] Stopped 2011-02-23T00:33:38.45200Z,1298421218.452 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2011-02-23T00:33:38.45210Z,1298421218.4521 [Default:CallIridium:0] Stopped 2011-02-23T00:33:38.45220Z,1298421218.4522 [Default:CallIridium:0](INFO): Aggregate::uninitialize Default:CallIridium:0 2011-02-23T00:33:38.45230Z,1298421218.4523 [Default:4.SetSpeed] Stopped 2011-02-23T00:33:38.45240Z,1298421218.4524 [Default:4.SetSpeed](DEBUG): Uninitialize. 2011-02-23T00:33:38.45250Z,1298421218.4525 [Default:5.GoToSurface] Stopped 2011-02-23T00:33:38.45260Z,1298421218.4526 [Default:5.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2011-02-23T00:33:38.45270Z,1298421218.4527 [Default:6.Wait] Stopped 2011-02-23T00:33:38.45270Z,1298421218.4527 [Default:6.Wait](DEBUG): Uninitialize Wait Component. 2011-02-23T00:33:38.45810Z,1298421218.4581 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2011-02-23T00:33:38.45840Z,1298421218.4584 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2011-02-23T00:33:38.45890Z,1298421218.4589 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2011-02-23T00:33:38.45920Z,1298421218.4592 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2011-02-23T00:33:38.45970Z,1298421218.4597 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2011-02-23T00:33:38.45980Z,1298421218.4598 [BuoyancyServo](INFO): Powering down 2011-02-23T00:33:38.46030Z,1298421218.4603 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2011-02-23T00:33:38.46040Z,1298421218.4604 [ElevatorServo](INFO): Powering down 2011-02-23T00:33:38.46080Z,1298421218.4608 [MassServo](DEBUG): Uninitialize Mass Servo. 2011-02-23T00:33:38.46100Z,1298421218.461 [MassServo](INFO): Powering down 2011-02-23T00:33:38.46140Z,1298421218.4614 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2011-02-23T00:33:38.46150Z,1298421218.4615 [RudderServo](INFO): Powering down 2011-02-23T00:33:38.46190Z,1298421218.4619 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2011-02-23T00:33:38.46200Z,1298421218.462 [ThrusterServo](INFO): Powering down 2011-02-23T00:33:38.46240Z,1298421218.4624 [SBIT](DEBUG): Uninitialize SBIT Component. 2011-02-23T00:33:38.46280Z,1298421218.4628 [IBIT](DEBUG): Uninitialize IBIT Component. 2011-02-23T00:33:38.46320Z,1298421218.4632 [CBIT](DEBUG): Uninitialize CBIT Component.