2012-05-10T02:18:25.023Z,1336616305.023 [Supervisor](DEBUG): Initializing supervisor. 2012-05-10T02:18:25.026Z,1336616305.026 [SyncHandler](DEBUG): Created PCaller Thread at 1077138656 2012-05-10T02:18:25.026Z,1336616305.026 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2012-05-10T02:18:25.027Z,1336616305.027 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 1077335264 2012-05-10T02:18:25.028Z,1336616305.028 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2012-05-10T02:18:25.038Z,1336616305.038 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2012-05-10T02:18:25.039Z,1336616305.039 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 1077531872 2012-05-10T02:18:25.040Z,1336616305.040 [ComponentRegistry](DEBUG): SyncComponent "logger" handled in the control thread. 2012-05-10T02:18:25.041Z,1336616305.041 [Supervisor](INFO): Looking for Config files in directory: Config/ 2012-05-10T02:18:25.043Z,1336616305.043 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2012-05-10T02:18:25.331Z,1336616305.331 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2012-05-10T02:18:25.332Z,1336616305.332 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2012-05-10T02:18:25.513Z,1336616305.513 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2012-05-10T02:18:25.514Z,1336616305.514 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2012-05-10T02:18:25.600Z,1336616305.600 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2012-05-10T02:18:25.601Z,1336616305.601 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2012-05-10T02:18:25.786Z,1336616305.786 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2012-05-10T02:18:25.787Z,1336616305.787 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2012-05-10T02:18:25.912Z,1336616305.912 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2012-05-10T02:18:25.913Z,1336616305.913 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2012-05-10T02:18:26.129Z,1336616306.129 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2012-05-10T02:18:26.130Z,1336616306.130 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2012-05-10T02:18:26.277Z,1336616306.277 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2012-05-10T02:18:26.277Z,1336616306.277 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2012-05-10T02:18:26.489Z,1336616306.489 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2012-05-10T02:18:26.489Z,1336616306.489 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2012-05-10T02:18:26.588Z,1336616306.588 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2012-05-10T02:18:26.589Z,1336616306.589 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2012-05-10T02:18:26.974Z,1336616306.974 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2012-05-10T02:18:26.975Z,1336616306.974 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2012-05-10T02:18:28.818Z,1336616308.818 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2012-05-10T02:18:28.818Z,1336616308.818 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2012-05-10T02:18:32.019Z,1336616312.019 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2012-05-10T02:18:32.020Z,1336616312.020 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2012-05-10T02:18:32.125Z,1336616312.125 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2012-05-10T02:18:32.252Z,1336616312.252 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2012-05-10T02:18:32.882Z,1336616312.882 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2012-05-10T02:18:33.156Z,1336616313.157 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2012-05-10T02:18:33.266Z,1336616313.266 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2012-05-10T02:18:33.360Z,1336616313.360 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2012-05-10T02:18:33.448Z,1336616313.448 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2012-05-10T02:18:33.563Z,1336616313.563 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2012-05-10T02:18:33.689Z,1336616313.689 [InternalSim] Loaded 2012-05-10T02:18:33.689Z,1336616313.689 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread. 2012-05-10T02:18:33.690Z,1336616313.690 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2012-05-10T02:18:33.690Z,1336616313.690 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2012-05-10T02:18:33.731Z,1336616313.731 [SBIT](DEBUG): Construct Startup Built In Test. 2012-05-10T02:18:33.742Z,1336616313.742 [SBIT] Loaded 2012-05-10T02:18:33.742Z,1336616313.742 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2012-05-10T02:18:33.743Z,1336616313.743 [IBIT](DEBUG): Construct Initiated Built In Test. 2012-05-10T02:18:33.766Z,1336616313.766 [IBIT] Loaded 2012-05-10T02:18:33.767Z,1336616313.767 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2012-05-10T02:18:33.774Z,1336616313.774 [CBIT](DEBUG): Construct CBIT Built In Test. 2012-05-10T02:18:33.880Z,1336616313.880 [CBIT] Loaded 2012-05-10T02:18:33.881Z,1336616313.881 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2012-05-10T02:18:33.881Z,1336616313.881 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2012-05-10T02:18:33.882Z,1336616313.882 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2012-05-10T02:18:34.009Z,1336616314.009 [BuoyancyServo] Loaded 2012-05-10T02:18:34.009Z,1336616314.009 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2012-05-10T02:18:34.016Z,1336616314.016 [ElevatorServo] Loaded 2012-05-10T02:18:34.016Z,1336616314.016 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2012-05-10T02:18:34.023Z,1336616314.023 [MassServo] Loaded 2012-05-10T02:18:34.023Z,1336616314.023 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2012-05-10T02:18:34.029Z,1336616314.029 [RudderServo] Loaded 2012-05-10T02:18:34.030Z,1336616314.030 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2012-05-10T02:18:34.036Z,1336616314.036 [ThrusterServo] Loaded 2012-05-10T02:18:34.036Z,1336616314.036 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2012-05-10T02:18:34.037Z,1336616314.037 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2012-05-10T02:18:34.037Z,1336616314.037 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2012-05-10T02:18:34.052Z,1336616314.052 [DepthRateCalculator] Loaded 2012-05-10T02:18:34.052Z,1336616314.052 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2012-05-10T02:18:34.067Z,1336616314.067 [NavChart] Loaded 2012-05-10T02:18:34.068Z,1336616314.068 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2012-05-10T02:18:34.073Z,1336616314.073 [PitchRateCalculator] Loaded 2012-05-10T02:18:34.073Z,1336616314.073 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2012-05-10T02:18:34.079Z,1336616314.079 [SpeedCalculator] Loaded 2012-05-10T02:18:34.079Z,1336616314.079 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2012-05-10T02:18:34.093Z,1336616314.093 [TempGradientCalculator] Loaded 2012-05-10T02:18:34.094Z,1336616314.093 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2012-05-10T02:18:34.099Z,1336616314.099 [YawRateCalculator] Loaded 2012-05-10T02:18:34.100Z,1336616314.100 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2012-05-10T02:18:34.129Z,1336616314.129 [Navigation] Loaded 2012-05-10T02:18:34.129Z,1336616314.129 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread. 2012-05-10T02:18:34.130Z,1336616314.130 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2012-05-10T02:18:34.130Z,1336616314.130 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2012-05-10T02:18:34.335Z,1336616314.335 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2012-05-10T02:18:34.335Z,1336616314.335 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2012-05-10T02:18:34.355Z,1336616314.355 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2012-05-10T02:18:34.355Z,1336616314.355 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2012-05-10T02:18:34.392Z,1336616314.392 [VerticalControl](DEBUG): Construct VerticalControl. 2012-05-10T02:18:34.434Z,1336616314.434 [VerticalControl] Loaded 2012-05-10T02:18:34.435Z,1336616314.435 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2012-05-10T02:18:34.435Z,1336616314.435 [HorizontalControl](DEBUG): Construct HorizontalControl. 2012-05-10T02:18:34.455Z,1336616314.455 [HorizontalControl] Loaded 2012-05-10T02:18:34.455Z,1336616314.455 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2012-05-10T02:18:34.456Z,1336616314.456 [SpeedControl](DEBUG): Construct SpeedControl. 2012-05-10T02:18:34.458Z,1336616314.458 [SpeedControl] Loaded 2012-05-10T02:18:34.458Z,1336616314.458 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2012-05-10T02:18:34.459Z,1336616314.459 [LoopControl](DEBUG): Construct LoopControl. 2012-05-10T02:18:34.459Z,1336616314.459 [LoopControl] Loaded 2012-05-10T02:18:34.460Z,1336616314.460 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2012-05-10T02:18:34.460Z,1336616314.460 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2012-05-10T02:18:34.461Z,1336616314.461 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2012-05-10T02:18:34.466Z,1336616314.466 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator. 2012-05-10T02:18:34.471Z,1336616314.471 [AsyncPiEstimator] Loaded 2012-05-10T02:18:34.471Z,1336616314.471 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread. 2012-05-10T02:18:34.472Z,1336616314.472 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 1078994144 2012-05-10T02:18:34.473Z,1336616314.473 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2012-05-10T02:18:34.473Z,1336616314.473 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2012-05-10T02:18:34.563Z,1336616314.563 [AHRS_sp3003D] Loaded 2012-05-10T02:18:34.563Z,1336616314.563 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread. 2012-05-10T02:18:34.803Z,1336616314.803 [Batt_Ocean_Server] Loaded 2012-05-10T02:18:34.803Z,1336616314.803 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread. 2012-05-10T02:18:34.809Z,1336616314.809 [DropWeight] Loaded 2012-05-10T02:18:34.809Z,1336616314.809 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2012-05-10T02:18:34.897Z,1336616314.897 [DVL_micro] Loaded 2012-05-10T02:18:34.898Z,1336616314.898 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2012-05-10T02:18:34.974Z,1336616314.974 [NAL9601] Loaded 2012-05-10T02:18:34.974Z,1336616314.974 [ComponentRegistry](DEBUG): SyncComponent "NAL9601" handled in the control thread. 2012-05-10T02:18:35.022Z,1336616315.022 [Onboard] Loaded 2012-05-10T02:18:35.022Z,1336616315.022 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2012-05-10T02:18:35.029Z,1336616315.029 [Radio_Freewave] Loaded 2012-05-10T02:18:35.029Z,1336616315.029 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread. 2012-05-10T02:18:35.030Z,1336616315.030 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2012-05-10T02:18:35.030Z,1336616315.030 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2012-05-10T02:18:35.074Z,1336616315.074 [CTD_NeilBrown] Loaded 2012-05-10T02:18:35.074Z,1336616315.074 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2012-05-10T02:18:35.075Z,1336616315.075 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 1079645408 2012-05-10T02:18:35.105Z,1336616315.105 [WetLabsBB2FL] Loaded 2012-05-10T02:18:35.105Z,1336616315.105 [ComponentRegistry](DEBUG): SyncComponent "WetLabsBB2FL" handled in the control thread. 2012-05-10T02:18:35.105Z,1336616315.105 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2012-05-10T02:18:35.107Z,1336616315.107 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2012-05-10T02:18:35.108Z,1336616315.108 [ComponentRegistry](DEBUG): SyncComponent "Maintainer" handled in the control thread. 2012-05-10T02:18:35.109Z,1336616315.109 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2012-05-10T02:18:35.114Z,1336616315.114 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2012-05-10T02:18:35.115Z,1336616315.115 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 1079842016 2012-05-10T02:18:35.116Z,1336616315.116 [Supervisor](DEBUG): Running supervisor. 2012-05-10T02:18:35.119Z,1336616315.119 [controlThread](DEBUG): Initializing ControlThread 2012-05-10T02:18:35.120Z,1336616315.120 [InternalSim](DEBUG): InternalSim initializing... 2012-05-10T02:18:35.155Z,1336616315.155 [SBIT](INFO): Initialize SBIT Component. 2012-05-10T02:18:35.156Z,1336616315.156 [SBIT](IMPORTANT): Tethys CM Info: $Rev: 9636 $ 2012-05-10T02:18:35.157Z,1336616315.157 [IBIT](INFO): Initialize IBIT Component. 2012-05-10T02:18:35.160Z,1336616315.160 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator. 2012-05-10T02:18:35.168Z,1336616315.168 [CBIT](DEBUG): Initialize CBIT Component. 2012-05-10T02:18:35.168Z,1336616315.168 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2012-05-10T02:18:35.169Z,1336616315.169 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown. 2012-05-10T02:18:35.192Z,1336616315.192 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2012-05-10T02:18:35.192Z,1336616315.192 [NavChart](DEBUG): Initialize NavChart Derivation. 2012-05-10T02:18:35.192Z,1336616315.193 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2012-05-10T02:18:35.193Z,1336616315.193 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2012-05-10T02:18:35.193Z,1336616315.194 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2012-05-10T02:18:35.195Z,1336616315.195 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2012-05-10T02:18:35.195Z,1336616315.195 [Navigation](DEBUG): Initializing Navigation. 2012-05-10T02:18:35.196Z,1336616315.196 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2012-05-10T02:18:35.198Z,1336616315.198 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2012-05-10T02:18:35.199Z,1336616315.198 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2012-05-10T02:18:35.199Z,1336616315.199 [LoopControl](DEBUG): Initialize LoopControlComponent. 2012-05-10T02:18:35.280Z,1336616315.280 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources 2012-05-10T02:18:35.284Z,1336616315.284 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2012-05-10T02:18:35.289Z,1336616315.289 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2012-05-10T02:18:35.293Z,1336616315.293 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2012-05-10T02:18:35.297Z,1336616315.297 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2012-05-10T02:18:35.298Z,1336616315.297 [NavChartDb](INFO): Creating index for Soundings 2012-05-10T02:18:35.301Z,1336616315.301 [NavChartDb](INFO): Creating index for Contour 0p0 2012-05-10T02:18:35.303Z,1336616315.303 [NavChartDb](INFO): Creating index for Contour 1p8 2012-05-10T02:18:35.305Z,1336616315.305 [NavChartDb](INFO): Creating index for Contour 3p6 2012-05-10T02:18:35.307Z,1336616315.307 [NavChartDb](INFO): Creating index for Contour 5p4 2012-05-10T02:18:35.309Z,1336616315.309 [NavChartDb](INFO): Creating index for Contour 9p1 2012-05-10T02:18:35.311Z,1336616315.311 [NavChartDb](INFO): Creating index for Contour 10p9 2012-05-10T02:18:35.313Z,1336616315.313 [NavChartDb](INFO): Creating index for Contour 18p2 2012-05-10T02:18:35.315Z,1336616315.315 [NavChartDb](INFO): Creating index for Contour 36p5 2012-05-10T02:18:35.317Z,1336616315.317 [NavChartDb](INFO): Creating index for Contour 54p8 2012-05-10T02:18:35.319Z,1336616315.319 [NavChartDb](INFO): Creating index for Contour 73p1 2012-05-10T02:18:35.321Z,1336616315.321 [NavChartDb](INFO): Creating index for Contour 91p4 2012-05-10T02:18:35.323Z,1336616315.323 [NavChartDb](INFO): Creating index for Contour 182p8 2012-05-10T02:18:35.325Z,1336616315.325 [NavChartDb](INFO): Creating index for Contour 365p7 2012-05-10T02:18:35.327Z,1336616315.327 [NavChartDb](INFO): Creating index for Contour 548p6 2012-05-10T02:18:35.329Z,1336616315.329 [NavChartDb](INFO): Creating index for Contour 731p5 2012-05-10T02:18:35.331Z,1336616315.330 [NavChartDb](INFO): Creating index for Contour 914p4 2012-05-10T02:18:35.332Z,1336616315.332 [NavChartDb](INFO): Creating index for Contour 1097p2 2012-05-10T02:18:35.334Z,1336616315.334 [NavChartDb](INFO): Creating index for Contour 1280p1 2012-05-10T02:18:35.336Z,1336616315.336 [NavChartDb](INFO): Creating index for Contour 1463p0 2012-05-10T02:18:35.338Z,1336616315.338 [NavChartDb](INFO): Creating index for Contour 1645p9 2012-05-10T02:18:35.340Z,1336616315.340 [NavChartDb](INFO): Creating index for Contour 1828p8 2012-05-10T02:18:35.342Z,1336616315.342 [NavChartDb](INFO): Creating index for Contour 2011p6 2012-05-10T02:18:35.344Z,1336616315.344 [NavChartDb](INFO): Creating index for Contour 2194p5 2012-05-10T02:18:35.346Z,1336616315.346 [NavChartDb](INFO): Creating index for Contour 2377p4 2012-05-10T02:18:35.348Z,1336616315.348 [NavChartDb](INFO): Creating index for Contour 2560p3 2012-05-10T02:18:35.350Z,1336616315.350 [NavChartDb](INFO): Creating index for Contour 2743p2 2012-05-10T02:18:35.352Z,1336616315.352 [NavChartDb](INFO): Creating index for Contour 2926p0 2012-05-10T02:18:35.354Z,1336616315.354 [NavChartDb](INFO): Creating index for Contour 3108p9 2012-05-10T02:18:35.356Z,1336616315.356 [NavChartDb](INFO): Creating index for Contour 3291p8 2012-05-10T02:18:35.358Z,1336616315.358 [NavChartDb](INFO): Creating index for Contour 3474p7 2012-05-10T02:18:35.360Z,1336616315.360 [NavChartDb](INFO): Creating index for Contour 3657p6 2012-05-10T02:18:37.035Z,1336616317.035 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized 2012-05-10T02:18:37.038Z,1336616317.038 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2012-05-10T02:18:37.049Z,1336616317.049 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2012-05-10T02:18:37.059Z,1336616317.059 [MissionManager](DEBUG): 2012-05-10T02:18:37.060Z,1336616317.060 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2012-05-10T02:18:37.088Z,1336616317.088 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool 2012-05-10T02:18:37.090Z,1336616317.090 [Default:GPS:A.SetSpeed](DEBUG): Construct. 2012-05-10T02:18:37.093Z,1336616317.093 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface. 2012-05-10T02:18:37.102Z,1336616317.102 [Default:Iridium:A.SetSpeed](DEBUG): Construct. 2012-05-10T02:18:37.106Z,1336616317.106 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface. 2012-05-10T02:18:37.112Z,1336616317.112 [Default:Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2012-05-10T02:18:37.120Z,1336616317.120 [Default:D.SetSpeed](DEBUG): Construct. 2012-05-10T02:18:37.124Z,1336616317.124 [Default:E.GoToSurface](DEBUG): Construct GoToSurface. 2012-05-10T02:18:37.128Z,1336616317.128 [Default:F.Wait](DEBUG): Construct Wait. 2012-05-10T02:18:37.132Z,1336616317.132 [MissionManager](DEBUG): 400 400 Burn on Dropped drop weight due to communications timeout 5.0 1.0 5 2012-05-10T02:18:37.137Z,1336616317.137 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,DropWeight,DVL_micro,NAL9601,Onboard,Radio_Freewave,WetLabsBB2FL,DepthRateCalculator,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintainer,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,logger, 2012-05-10T02:18:37.156Z,1336616317.156 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2012-05-10T02:18:37.183Z,1336616317.183 [DVL_micro](DEBUG): Initializing DVL_micro. 2012-05-10T02:18:37.205Z,1336616317.205 [Radio_Freewave](INFO): Powering up 2012-05-10T02:18:37.210Z,1336616317.210 [WetLabsBB2FL](INFO): Powering down 2012-05-10T02:18:37.278Z,1336616317.278 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2012-05-10T02:18:37.279Z,1336616317.279 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2012-05-10T02:18:37.288Z,1336616317.288 [ElevatorServo](DEBUG): Initializing EZServoServo. 2012-05-10T02:18:37.289Z,1336616317.289 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2012-05-10T02:18:37.297Z,1336616317.297 [MassServo](DEBUG): Initializing EZServoServo. 2012-05-10T02:18:37.298Z,1336616317.298 [MassServo](DEBUG): Initializing MassServo. 2012-05-10T02:18:37.306Z,1336616317.306 [RudderServo](DEBUG): Initializing EZServoServo. 2012-05-10T02:18:37.307Z,1336616317.307 [RudderServo](DEBUG): Initializing RudderServo. 2012-05-10T02:18:37.315Z,1336616317.315 [ThrusterServo](DEBUG): Initializing EZServoServo. 2012-05-10T02:18:37.316Z,1336616317.316 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2012-05-10T02:18:40.182Z,1336616320.182 [NAL9601](INFO): Powering up NAL9601 2012-05-10T02:18:50.575Z,1336616330.575 [SBIT](IMPORTANT): Beginning Startup BIT 2012-05-10T02:18:50.577Z,1336616330.577 [CBIT](IMPORTANT): Beginning GF scan 2012-05-10T02:19:16.743Z,1336616356.743 [CBIT](IMPORTANT): No ground fault detected 2012-05-10T02:19:32.674Z,1336616372.674 [SBIT](IMPORTANT): SBIT PASSED 2012-05-10T02:19:33.084Z,1336616373.084 [MissionManager](IMPORTANT): Started mission Startup 2012-05-10T02:19:33.084Z,1336616373.084 [Startup] Running Loop=1 2012-05-10T02:19:33.084Z,1336616373.084 [Startup](INFO): Aggregate::initialize Startup 2012-05-10T02:19:33.084Z,1336616373.084 [Startup:A.GoToSurface] Running Loop=1 2012-05-10T02:19:33.084Z,1336616373.084 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-05-10T02:19:34.955Z,1336616374.955 [Startup:StartupSatComms] Running Loop=1 2012-05-10T02:19:34.955Z,1336616374.955 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms 2012-05-10T02:19:34.955Z,1336616374.955 [Startup:StartupSatComms:A] Running Loop=1 2012-05-10T02:19:35.352Z,1336616375.352 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2012-05-10T02:19:40.291Z,1336616380.291 [CTD_NeilBrown](ERROR): Bad response: -1.26 2012-05-10T02:19:40.423Z,1336616380.423 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.037410 psu 2012-05-10T02:19:45.959Z,1336616385.959 [NAL9601](INFO): NAL9601 initialized 2012-05-10T02:20:35.352Z,1336616435.352 [Startup:StartupSatComms:A](INFO): Timed out from 2012-05-10T02:19:34.0Z 2012-05-10T02:20:35.352Z,1336616435.352 [Startup:StartupSatComms:A_Timeout] Running Loop=1 2012-05-10T02:20:35.352Z,1336616435.352 [Startup:StartupSatComms:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:A_Timeout 2012-05-10T02:20:35.352Z,1336616435.352 [Startup:StartupSatComms:A_Timeout](INFO): Completed Startup:StartupSatComms:A_Timeout 2012-05-10T02:20:35.352Z,1336616435.352 [Startup:StartupSatComms:A] Stopped 2012-05-10T02:20:35.352Z,1336616435.352 [Startup:StartupSatComms:B] Running Loop=1 2012-05-10T02:20:35.747Z,1336616435.747 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2012-05-10T02:21:01.760Z,1336616461.760 [NAL9601](INFO): SBD MO Status=1, MOMSN=6342, MT Status=0, MTMSN=0 2012-05-10T02:21:01.927Z,1336616461.927 [NAL9601](INFO): Sent 240 bytes from file Logs/20120509T202435/shore0035.lzma 2012-05-10T02:21:01.927Z,1336616461.927 [NAL9601](INFO): Packets left to send: 0 2012-05-10T02:21:01.928Z,1336616461.928 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000000 2012-05-10T02:21:09.883Z,1336616469.883 [NAL9601](INFO): SBD MO Status=1, MOMSN=6343, MT Status=0, MTMSN=0 2012-05-10T02:21:10.015Z,1336616470.015 [NAL9601](INFO): Sent 332 bytes from file Logs/20120510T021825/shore0000.lzma 2012-05-10T02:21:10.015Z,1336616470.015 [NAL9601](INFO): Packets left to send: 1 2012-05-10T02:21:10.016Z,1336616470.016 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000001 2012-05-10T02:21:18.780Z,1336616478.780 [NAL9601](INFO): SBD MO Status=1, MOMSN=6344, MT Status=0, MTMSN=0 2012-05-10T02:21:18.903Z,1336616478.903 [NAL9601](INFO): Sent 182 bytes from file Logs/20120510T021825/shore0000.lzma 2012-05-10T02:21:18.903Z,1336616478.903 [NAL9601](INFO): Packets left to send: 0 2012-05-10T02:21:18.904Z,1336616478.904 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000002 2012-05-10T02:21:29.199Z,1336616489.199 [NAL9601](INFO): SBD MO Status=0, MOMSN=6345, MT Status=0, MTMSN=0 2012-05-10T02:21:29.401Z,1336616489.401 [Startup:StartupSatComms:B] Stopped 2012-05-10T02:21:29.401Z,1336616489.401 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2012-05-10T02:21:29.401Z,1336616489.401 [Startup:StartupSatComms] Stopped 2012-05-10T02:21:29.401Z,1336616489.401 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms 2012-05-10T02:21:29.403Z,1336616489.403 [Startup](INFO): Completed Startup 2012-05-10T02:21:29.403Z,1336616489.403 [Startup] Stopped 2012-05-10T02:21:29.403Z,1336616489.403 [Startup](INFO): Aggregate::uninitialize Startup 2012-05-10T02:21:29.403Z,1336616489.403 [Startup:A.GoToSurface] Stopped 2012-05-10T02:21:29.403Z,1336616489.403 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-05-10T02:21:29.590Z,1336616489.591 [MissionManager](IMPORTANT): Started mission Default 2012-05-10T02:21:29.591Z,1336616489.591 [Default] Running Loop=1 2012-05-10T02:21:29.591Z,1336616489.591 [Default](INFO): Aggregate::initialize Default 2012-05-10T02:21:29.591Z,1336616489.591 [Default:D.SetSpeed] Running Loop=1 2012-05-10T02:21:29.591Z,1336616489.591 [Default:D.SetSpeed](DEBUG): Initialize. 2012-05-10T02:21:29.591Z,1336616489.591 [Default:E.GoToSurface] Running Loop=1 2012-05-10T02:21:29.591Z,1336616489.591 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-05-10T02:21:29.592Z,1336616489.592 [Default:Iridium] Running Loop=1 2012-05-10T02:21:29.592Z,1336616489.592 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2012-05-10T02:21:29.592Z,1336616489.592 [Default:Iridium:A.SetSpeed] Running Loop=1 2012-05-10T02:21:29.592Z,1336616489.592 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2012-05-10T02:21:29.592Z,1336616489.592 [Default:Iridium:B.GoToSurface] Running Loop=1 2012-05-10T02:21:29.592Z,1336616489.592 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-05-10T02:21:29.593Z,1336616489.593 [Default:E.GoToSurface] Running Loop=1 2012-05-10T02:21:29.600Z,1336616489.600 [Default:D.SetSpeed] Running Loop=1 2012-05-10T02:21:29.610Z,1336616489.610 [Default:Iridium:B.GoToSurface] Stopped 2012-05-10T02:21:29.610Z,1336616489.610 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-05-10T02:21:29.610Z,1336616489.610 [Default:Iridium:Read_Iridium] Running Loop=1 2012-05-10T02:21:29.610Z,1336616489.610 [Default:Iridium:A.SetSpeed] Running Loop=1 2012-05-10T02:21:29.615Z,1336616489.615 [Default:GPS] Running Loop=1 2012-05-10T02:21:29.615Z,1336616489.615 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2012-05-10T02:21:29.615Z,1336616489.615 [Default:GPS:A.SetSpeed] Running Loop=1 2012-05-10T02:21:29.615Z,1336616489.615 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2012-05-10T02:21:29.615Z,1336616489.615 [Default:GPS:B.GoToSurface] Running Loop=1 2012-05-10T02:21:29.615Z,1336616489.615 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-05-10T02:21:29.621Z,1336616489.621 [Default:GPS:B.GoToSurface] Stopped 2012-05-10T02:21:29.621Z,1336616489.621 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-05-10T02:21:29.621Z,1336616489.621 [Default:GPS:Read_GPS] Running Loop=1 2012-05-10T02:21:29.621Z,1336616489.621 [Default:GPS:A.SetSpeed] Running Loop=1 2012-05-10T02:21:30.028Z,1336616490.028 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2012-05-10T02:21:30.031Z,1336616490.031 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2012-05-10T02:21:31.623Z,1336616491.624 [CTD_NeilBrown](ERROR): Pressure reading out of range: -243.610001 decibar 2012-05-10T02:21:31.867Z,1336616491.867 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.037410 psu 2012-05-10T02:21:31.976Z,1336616491.976 [Radio_Freewave](INFO): Powering down 2012-05-10T02:21:32.381Z,1336616492.381 [Radio_Freewave](INFO): Powering up 2012-05-10T02:21:41.604Z,1336616501.604 [NAL9601](INFO): SBD MO Status=1, MOMSN=6346, MT Status=0, MTMSN=0 2012-05-10T02:21:41.767Z,1336616501.767 [NAL9601](INFO): Sent 103 bytes from file Logs/20120510T021825/shore0001.lzma 2012-05-10T02:21:41.767Z,1336616501.767 [NAL9601](INFO): Packets left to send: 0 2012-05-10T02:21:41.768Z,1336616501.768 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000003 2012-05-10T02:21:49.203Z,1336616509.203 [NAL9601](INFO): SBD MO Status=0, MOMSN=6347, MT Status=0, MTMSN=0 2012-05-10T02:21:49.367Z,1336616509.367 [Default:Iridium:Read_Iridium] Stopped 2012-05-10T02:21:49.368Z,1336616509.368 [Default:Iridium](INFO): Completed Default:Iridium 2012-05-10T02:21:49.368Z,1336616509.368 [Default:Iridium] Stopped 2012-05-10T02:21:49.368Z,1336616509.368 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2012-05-10T02:21:49.368Z,1336616509.368 [Default:Iridium:A.SetSpeed] Stopped 2012-05-10T02:21:49.368Z,1336616509.368 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2012-05-10T02:21:49.368Z,1336616509.368 [Default:F.Wait] Running Loop=1 2012-05-10T02:21:49.368Z,1336616509.368 [Default:F.Wait](DEBUG): Initialize Wait Component. 2012-05-10T02:23:50.402Z,1336616630.402 [NAL9601](IMPORTANT): GPS fix at: 1336616668.00 2012-05-10T02:23:50.416Z,1336616630.416 [Default:GPS:Read_GPS] Stopped 2012-05-10T02:23:50.416Z,1336616630.416 [Default:GPS:D] Running Loop=1 2012-05-10T02:23:50.822Z,1336616630.822 [Default:GPS:D] Stopped 2012-05-10T02:23:50.822Z,1336616630.822 [Default:GPS](INFO): Completed Default:GPS 2012-05-10T02:23:50.822Z,1336616630.822 [Default:GPS] Stopped 2012-05-10T02:23:50.822Z,1336616630.822 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2012-05-10T02:23:50.823Z,1336616630.823 [Default:GPS:A.SetSpeed] Stopped 2012-05-10T02:23:50.823Z,1336616630.823 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2012-05-10T02:24:06.423Z,1336616646.422 [NAL9601](INFO): Powering down 2012-05-10T02:26:51.387Z,1336616811.387 [Default:CallIridium] Running Loop=1 2012-05-10T02:26:51.387Z,1336616811.387 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2012-05-10T02:26:51.387Z,1336616811.387 [Default:CallIridium:A] Running Loop=1 2012-05-10T02:26:51.389Z,1336616811.389 [Default:CallIridium:A] Stopped 2012-05-10T02:26:51.389Z,1336616811.389 [Default:CallIridium:B] Running Loop=1 2012-05-10T02:26:51.389Z,1336616811.389 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2012-05-10T02:26:56.397Z,1336616816.397 [Default:Iridium] Running Loop=1 2012-05-10T02:26:56.397Z,1336616816.397 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2012-05-10T02:26:56.397Z,1336616816.397 [Default:Iridium:A.SetSpeed] Running Loop=1 2012-05-10T02:26:56.397Z,1336616816.397 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2012-05-10T02:26:56.398Z,1336616816.398 [Default:Iridium:B.GoToSurface] Running Loop=1 2012-05-10T02:26:56.398Z,1336616816.398 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-05-10T02:26:56.399Z,1336616816.399 [Default:Iridium:B.GoToSurface] Stopped 2012-05-10T02:26:56.399Z,1336616816.399 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-05-10T02:26:56.400Z,1336616816.399 [Default:Iridium:Read_Iridium] Running Loop=1 2012-05-10T02:26:56.400Z,1336616816.400 [Default:GPS] Running Loop=1 2012-05-10T02:26:56.400Z,1336616816.400 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2012-05-10T02:26:56.400Z,1336616816.400 [Default:GPS:A.SetSpeed] Running Loop=1 2012-05-10T02:26:56.400Z,1336616816.400 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2012-05-10T02:26:56.400Z,1336616816.401 [Default:GPS:B.GoToSurface] Running Loop=1 2012-05-10T02:26:56.400Z,1336616816.401 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-05-10T02:26:56.402Z,1336616816.402 [Default:GPS:B.GoToSurface] Stopped 2012-05-10T02:26:56.402Z,1336616816.402 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-05-10T02:26:56.402Z,1336616816.402 [Default:GPS:Read_GPS] Running Loop=1 2012-05-10T02:26:57.007Z,1336616817.007 [NAL9601](INFO): Powering up 2012-05-10T02:28:02.731Z,1336616882.731 [NAL9601](INFO): NAL9601 initialized 2012-05-10T02:28:26.715Z,1336616906.716 [NAL9601](INFO): SBD MO Status=1, MOMSN=6348, MT Status=0, MTMSN=0 2012-05-10T02:28:26.883Z,1336616906.883 [NAL9601](INFO): Sent 332 bytes from file Logs/20120510T021825/shore0002.lzma 2012-05-10T02:28:26.883Z,1336616906.883 [NAL9601](INFO): Packets left to send: 1 2012-05-10T02:28:26.884Z,1336616906.884 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000004 2012-05-10T02:28:29.562Z,1336616909.562 [InternalSim](ERROR): Simulator run error: error=UNSTABLE SIMULATION -- ABORTED, rate=[1685968706148614.500000,15335063874624.396484,-34585832579311360.000000,-4369703947 2012-05-10T02:28:29.562Z,1336616909.562 [InternalSim] Software Fault, FailCount= 1 2012-05-10T02:28:29.562Z,1336616909.562 [InternalSim](ERROR): Software Fault 2012-05-10T02:28:29.637Z,1336616909.637 [CBIT](ERROR): Software Fault in component: InternalSim 2012-05-10T02:28:30.029Z,1336616910.029 [CBIT](INFO): Clearing failed state for component InternalSim 2012-05-10T02:28:30.029Z,1336616910.029 [InternalSim] No Fault, FailCount= 1 2012-05-10T02:28:30.319Z,1336616910.319 [InternalSim](DEBUG): InternalSim initializing... 2012-05-10T02:28:37.166Z,1336616917.166 [NAL9601](INFO): SBD MO Status=1, MOMSN=6349, MT Status=0, MTMSN=0 2012-05-10T02:28:37.367Z,1336616917.367 [NAL9601](INFO): Sent 65 bytes from file Logs/20120510T021825/shore0002.lzma 2012-05-10T02:28:37.367Z,1336616917.367 [NAL9601](INFO): Packets left to send: 0 2012-05-10T02:28:37.368Z,1336616917.368 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000005 2012-05-10T02:28:47.176Z,1336616927.176 [NAL9601](INFO): SBD MO Status=0, MOMSN=6350, MT Status=0, MTMSN=0 2012-05-10T02:28:47.365Z,1336616927.365 [Default:Iridium:Read_Iridium] Stopped 2012-05-10T02:28:47.365Z,1336616927.365 [Default:Iridium](INFO): Completed Default:Iridium 2012-05-10T02:28:47.365Z,1336616927.365 [Default:Iridium] Stopped 2012-05-10T02:28:47.365Z,1336616927.365 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2012-05-10T02:28:47.365Z,1336616927.365 [Default:Iridium:A.SetSpeed] Stopped 2012-05-10T02:28:47.365Z,1336616927.365 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2012-05-10T02:28:47.595Z,1336616927.595 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2012-05-10T02:28:47.595Z,1336616927.595 [Default:CallIridium:B] Stopped 2012-05-10T02:28:47.595Z,1336616927.595 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2012-05-10T02:28:47.595Z,1336616927.595 [Default:CallIridium](INFO): Completed Default:CallIridium 2012-05-10T02:28:47.595Z,1336616927.595 [Default:CallIridium] Stopped 2012-05-10T02:28:47.596Z,1336616927.596 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2012-05-10T02:28:56.361Z,1336616936.361 [NAL9601](IMPORTANT): GPS fix at: 1336616974.00 2012-05-10T02:28:56.400Z,1336616936.400 [Default:GPS:Read_GPS] Stopped 2012-05-10T02:28:56.400Z,1336616936.401 [Default:GPS:D] Running Loop=1 2012-05-10T02:28:56.783Z,1336616936.783 [Default:GPS:D] Stopped 2012-05-10T02:28:56.784Z,1336616936.784 [Default:GPS](INFO): Completed Default:GPS 2012-05-10T02:28:56.784Z,1336616936.784 [Default:GPS] Stopped 2012-05-10T02:28:56.784Z,1336616936.784 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2012-05-10T02:28:56.784Z,1336616936.784 [Default:GPS:A.SetSpeed] Stopped 2012-05-10T02:28:56.784Z,1336616936.784 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2012-05-10T02:29:12.336Z,1336616952.336 [NAL9601](INFO): Powering down 2012-05-10T02:33:47.357Z,1336617227.357 [Default:CallIridium] Running Loop=1 2012-05-10T02:33:47.357Z,1336617227.358 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2012-05-10T02:33:47.358Z,1336617227.358 [Default:CallIridium:A] Running Loop=1 2012-05-10T02:33:47.358Z,1336617227.358 [Default:CallIridium:A] Stopped 2012-05-10T02:33:47.358Z,1336617227.358 [Default:CallIridium:B] Running Loop=1 2012-05-10T02:33:47.359Z,1336617227.359 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2012-05-10T02:33:52.345Z,1336617232.345 [Default:Iridium] Running Loop=1 2012-05-10T02:33:52.345Z,1336617232.345 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2012-05-10T02:33:52.345Z,1336617232.345 [Default:Iridium:A.SetSpeed] Running Loop=1 2012-05-10T02:33:52.345Z,1336617232.345 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2012-05-10T02:33:52.346Z,1336617232.346 [Default:Iridium:B.GoToSurface] Running Loop=1 2012-05-10T02:33:52.346Z,1336617232.346 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-05-10T02:33:52.347Z,1336617232.347 [Default:Iridium:B.GoToSurface] Stopped 2012-05-10T02:33:52.347Z,1336617232.347 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-05-10T02:33:52.347Z,1336617232.347 [Default:Iridium:Read_Iridium] Running Loop=1 2012-05-10T02:33:52.347Z,1336617232.348 [Default:GPS] Running Loop=1 2012-05-10T02:33:52.348Z,1336617232.348 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2012-05-10T02:33:52.348Z,1336617232.348 [Default:GPS:A.SetSpeed] Running Loop=1 2012-05-10T02:33:52.348Z,1336617232.348 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2012-05-10T02:33:52.348Z,1336617232.348 [Default:GPS:B.GoToSurface] Running Loop=1 2012-05-10T02:33:52.348Z,1336617232.348 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-05-10T02:33:52.349Z,1336617232.349 [Default:GPS:B.GoToSurface] Stopped 2012-05-10T02:33:52.349Z,1336617232.349 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-05-10T02:33:52.349Z,1336617232.349 [Default:GPS:Read_GPS] Running Loop=1 2012-05-10T02:33:52.966Z,1336617232.966 [NAL9601](INFO): Powering up 2012-05-10T02:34:58.591Z,1336617298.591 [NAL9601](INFO): NAL9601 initialized 2012-05-10T02:35:14.088Z,1336617314.088 [NAL9601](IMPORTANT): SBD MO Status=1, MOMSN=6351, MT Status=1, MTMSN=2610 2012-05-10T02:35:14.255Z,1336617314.255 [NAL9601](INFO): Sent 175 bytes from file Logs/20120510T021825/shore0003.lzma 2012-05-10T02:35:14.255Z,1336617314.255 [NAL9601](INFO): Packets left to send: 0 2012-05-10T02:35:14.257Z,1336617314.257 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000006 2012-05-10T02:35:14.668Z,1336617314.668 [NAL9601](INFO): Received command:show best depth 2012-05-10T02:35:14.751Z,1336617314.751 [CommandLine](IMPORTANT): got command show best depth 2012-05-10T02:35:14.751Z,1336617314.751 [CommandLine](IMPORTANT): depth best is CTD_NeilBrown.depth 2012-05-10T02:35:31.537Z,1336617331.537 [NAL9601](INFO): SBD MO Status=0, MOMSN=6352, MT Status=0, MTMSN=0 2012-05-10T02:35:44.680Z,1336617344.680 [NAL9601](INFO): SBD MO Status=1, MOMSN=6353, MT Status=0, MTMSN=0 2012-05-10T02:35:44.807Z,1336617344.807 [NAL9601](INFO): Sent 246 bytes from file Logs/20120510T021825/shore0004.lzma 2012-05-10T02:35:44.807Z,1336617344.807 [NAL9601](INFO): Packets left to send: 0 2012-05-10T02:35:44.808Z,1336617344.808 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000007 2012-05-10T02:35:53.480Z,1336617353.480 [NAL9601](INFO): SBD MO Status=0, MOMSN=6354, MT Status=0, MTMSN=0 2012-05-10T02:35:53.713Z,1336617353.713 [Default:Iridium:Read_Iridium] Stopped 2012-05-10T02:35:53.713Z,1336617353.713 [Default:Iridium](INFO): Completed Default:Iridium 2012-05-10T02:35:53.713Z,1336617353.713 [Default:Iridium] Stopped 2012-05-10T02:35:53.713Z,1336617353.713 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2012-05-10T02:35:53.714Z,1336617353.714 [Default:Iridium:A.SetSpeed] Stopped 2012-05-10T02:35:53.714Z,1336617353.714 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2012-05-10T02:35:53.933Z,1336617353.933 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2012-05-10T02:35:53.933Z,1336617353.933 [Default:CallIridium:B] Stopped 2012-05-10T02:35:53.933Z,1336617353.933 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2012-05-10T02:35:53.933Z,1336617353.933 [Default:CallIridium](INFO): Completed Default:CallIridium 2012-05-10T02:35:53.933Z,1336617353.934 [Default:CallIridium] Stopped 2012-05-10T02:35:53.934Z,1336617353.934 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2012-05-10T02:40:53.935Z,1336617653.935 [Default:CallIridium] Running Loop=1 2012-05-10T02:40:53.935Z,1336617653.935 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2012-05-10T02:40:53.935Z,1336617653.935 [Default:CallIridium:A] Running Loop=1 2012-05-10T02:40:53.935Z,1336617653.935 [Default:CallIridium:A] Stopped 2012-05-10T02:40:53.936Z,1336617653.935 [Default:CallIridium:B] Running Loop=1 2012-05-10T02:40:53.936Z,1336617653.936 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2012-05-10T02:40:54.289Z,1336617654.289 [Default:Iridium] Running Loop=1 2012-05-10T02:40:54.289Z,1336617654.289 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2012-05-10T02:40:54.289Z,1336617654.289 [Default:Iridium:A.SetSpeed] Running Loop=1 2012-05-10T02:40:54.290Z,1336617654.290 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2012-05-10T02:40:54.290Z,1336617654.290 [Default:Iridium:B.GoToSurface] Running Loop=1 2012-05-10T02:40:54.290Z,1336617654.290 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-05-10T02:40:54.291Z,1336617654.291 [Default:Iridium:B.GoToSurface] Stopped 2012-05-10T02:40:54.291Z,1336617654.291 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-05-10T02:40:54.291Z,1336617654.291 [Default:Iridium:Read_Iridium] Running Loop=1 2012-05-10T02:41:16.668Z,1336617676.668 [NAL9601](INFO): SBD MO Status=1, MOMSN=6355, MT Status=0, MTMSN=0 2012-05-10T02:41:16.791Z,1336617676.791 [NAL9601](INFO): Sent 115 bytes from file Logs/20120510T021825/shore0005.lzma 2012-05-10T02:41:16.791Z,1336617676.791 [NAL9601](INFO): Packets left to send: 0 2012-05-10T02:41:16.793Z,1336617676.793 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000008 2012-05-10T02:41:25.868Z,1336617685.868 [NAL9601](INFO): SBD MO Status=0, MOMSN=6356, MT Status=0, MTMSN=0 2012-05-10T02:41:26.093Z,1336617686.093 [Default:Iridium:Read_Iridium] Stopped 2012-05-10T02:41:26.093Z,1336617686.093 [Default:Iridium](INFO): Completed Default:Iridium 2012-05-10T02:41:26.093Z,1336617686.093 [Default:Iridium] Stopped 2012-05-10T02:41:26.093Z,1336617686.093 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2012-05-10T02:41:26.093Z,1336617686.093 [Default:Iridium:A.SetSpeed] Stopped 2012-05-10T02:41:26.093Z,1336617686.093 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2012-05-10T02:41:26.547Z,1336617686.547 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2012-05-10T02:41:26.547Z,1336617686.547 [Default:CallIridium:B] Stopped 2012-05-10T02:41:26.547Z,1336617686.547 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2012-05-10T02:41:26.547Z,1336617686.547 [Default:CallIridium](INFO): Completed Default:CallIridium 2012-05-10T02:41:26.547Z,1336617686.547 [Default:CallIridium] Stopped 2012-05-10T02:41:26.547Z,1336617686.547 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2012-05-10T02:41:34.151Z,1336617694.151 [CTD_NeilBrown](ERROR): Bad response: 39.61536 2012-05-10T02:42:16.461Z,1336617736.461 [InternalSim](ERROR): Simulator run error: error=UNSTABLE SIMULATION -- ABORTED, rate=[15101.497823,1677.831076,-240789.620852,-2498.856485,-2626392.825219,-7842.176033] 2012-05-10T02:42:16.461Z,1336617736.461 [InternalSim] Software Fault, FailCount= 2 2012-05-10T02:42:16.461Z,1336617736.461 [InternalSim](ERROR): Software Fault 2012-05-10T02:42:16.524Z,1336617736.524 [CBIT](ERROR): Software Fault in component: InternalSim 2012-05-10T02:42:16.912Z,1336617736.912 [CBIT](INFO): Clearing failed state for component InternalSim 2012-05-10T02:42:16.912Z,1336617736.912 [InternalSim] No Fault, FailCount= 2 2012-05-10T02:42:17.255Z,1336617737.255 [InternalSim](DEBUG): InternalSim initializing... 2012-05-10T02:45:00.910Z,1336617900.910 [NAL9601](FAULT): GPS failed to acquire within timeout. 2012-05-10T02:45:00.910Z,1336617900.910 [NAL9601] Data Fault, FailCount= 1 2012-05-10T02:45:00.910Z,1336617900.910 [NAL9601](ERROR): Data Fault 2012-05-10T02:45:00.925Z,1336617900.925 [Default:CallIridium] Running Loop=1 2012-05-10T02:45:00.925Z,1336617900.925 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2012-05-10T02:45:00.925Z,1336617900.925 [Default:CallIridium:A] Running Loop=1 2012-05-10T02:45:00.925Z,1336617900.925 [Default:CallIridium:A] Stopped 2012-05-10T02:45:00.925Z,1336617900.925 [Default:CallIridium:B] Running Loop=1 2012-05-10T02:45:00.926Z,1336617900.926 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2012-05-10T02:45:00.935Z,1336617900.935 [CBIT](ERROR): Data Fault in component: NAL9601 2012-05-10T02:45:01.310Z,1336617901.310 [NAL9601](INFO): Powering down 2012-05-10T02:45:01.325Z,1336617901.325 [Default:Iridium] Running Loop=1 2012-05-10T02:45:01.326Z,1336617901.326 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2012-05-10T02:45:01.326Z,1336617901.326 [Default:Iridium:A.SetSpeed] Running Loop=1 2012-05-10T02:45:01.326Z,1336617901.326 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2012-05-10T02:45:01.326Z,1336617901.326 [Default:Iridium:B.GoToSurface] Running Loop=1 2012-05-10T02:45:01.326Z,1336617901.326 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-05-10T02:45:01.327Z,1336617901.327 [Default:Iridium:B.GoToSurface] Stopped 2012-05-10T02:45:01.327Z,1336617901.327 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-05-10T02:45:01.327Z,1336617901.328 [Default:Iridium:Read_Iridium] Running Loop=1 2012-05-10T02:45:01.337Z,1336617901.337 [CBIT](INFO): Clearing failed state for component NAL9601 2012-05-10T02:45:01.337Z,1336617901.337 [NAL9601] No Fault, FailCount= 1 2012-05-10T02:45:06.512Z,1336617906.512 [NAL9601](INFO): Powering up NAL9601 2012-05-10T02:46:12.203Z,1336617972.203 [NAL9601](INFO): NAL9601 initialized 2012-05-10T02:46:33.616Z,1336617993.616 [NAL9601](INFO): SBD MO Status=1, MOMSN=6357, MT Status=0, MTMSN=0 2012-05-10T02:46:33.759Z,1336617993.759 [NAL9601](INFO): Sent 160 bytes from file Logs/20120510T021825/shore0006.lzma 2012-05-10T02:46:33.759Z,1336617993.759 [NAL9601](INFO): Packets left to send: 0 2012-05-10T02:46:33.760Z,1336617993.760 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000009 2012-05-10T02:46:44.419Z,1336618004.420 [NAL9601](INFO): SBD MO Status=0, MOMSN=6358, MT Status=0, MTMSN=0 2012-05-10T02:46:44.557Z,1336618004.557 [Default:Iridium:Read_Iridium] Stopped 2012-05-10T02:46:44.558Z,1336618004.558 [Default:Iridium](INFO): Completed Default:Iridium 2012-05-10T02:46:44.558Z,1336618004.558 [Default:Iridium] Stopped 2012-05-10T02:46:44.558Z,1336618004.558 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2012-05-10T02:46:44.558Z,1336618004.558 [Default:Iridium:A.SetSpeed] Stopped 2012-05-10T02:46:44.558Z,1336618004.558 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2012-05-10T02:46:44.853Z,1336618004.853 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2012-05-10T02:46:44.853Z,1336618004.853 [Default:CallIridium:B] Stopped 2012-05-10T02:46:44.853Z,1336618004.853 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2012-05-10T02:46:44.853Z,1336618004.853 [Default:CallIridium](INFO): Completed Default:CallIridium 2012-05-10T02:46:44.853Z,1336618004.853 [Default:CallIridium] Stopped 2012-05-10T02:46:44.853Z,1336618004.853 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2012-05-10T02:51:44.835Z,1336618304.835 [Default:CallIridium] Running Loop=1 2012-05-10T02:51:44.835Z,1336618304.835 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2012-05-10T02:51:44.835Z,1336618304.835 [Default:CallIridium:A] Running Loop=1 2012-05-10T02:51:44.835Z,1336618304.835 [Default:CallIridium:A] Stopped 2012-05-10T02:51:44.836Z,1336618304.836 [Default:CallIridium:B] Running Loop=1 2012-05-10T02:51:44.836Z,1336618304.836 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2012-05-10T02:51:45.273Z,1336618305.273 [Default:Iridium] Running Loop=1 2012-05-10T02:51:45.273Z,1336618305.273 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2012-05-10T02:51:45.273Z,1336618305.273 [Default:Iridium:A.SetSpeed] Running Loop=1 2012-05-10T02:51:45.273Z,1336618305.273 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2012-05-10T02:51:45.273Z,1336618305.273 [Default:Iridium:B.GoToSurface] Running Loop=1 2012-05-10T02:51:45.273Z,1336618305.273 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-05-10T02:51:45.275Z,1336618305.275 [Default:Iridium:B.GoToSurface] Stopped 2012-05-10T02:51:45.275Z,1336618305.275 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-05-10T02:51:45.275Z,1336618305.275 [Default:Iridium:Read_Iridium] Running Loop=1 2012-05-10T02:52:02.328Z,1336618322.328 [NAL9601](INFO): SBD MO Status=1, MOMSN=6359, MT Status=0, MTMSN=0 2012-05-10T02:52:02.451Z,1336618322.451 [NAL9601](INFO): Sent 116 bytes from file Logs/20120510T021825/shore0007.lzma 2012-05-10T02:52:02.451Z,1336618322.451 [NAL9601](INFO): Packets left to send: 0 2012-05-10T02:52:02.452Z,1336618322.452 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000010 2012-05-10T02:52:17.545Z,1336618337.545 [NAL9601](INFO): SBD MO Status=0, MOMSN=6360, MT Status=0, MTMSN=0 2012-05-10T02:52:17.741Z,1336618337.741 [Default:Iridium:Read_Iridium] Stopped 2012-05-10T02:52:17.742Z,1336618337.742 [Default:Iridium](INFO): Completed Default:Iridium 2012-05-10T02:52:17.742Z,1336618337.742 [Default:Iridium] Stopped 2012-05-10T02:52:17.742Z,1336618337.742 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2012-05-10T02:52:17.742Z,1336618337.742 [Default:Iridium:A.SetSpeed] Stopped 2012-05-10T02:52:17.743Z,1336618337.743 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2012-05-10T02:52:17.967Z,1336618337.967 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2012-05-10T02:52:17.967Z,1336618337.967 [Default:CallIridium:B] Stopped 2012-05-10T02:52:17.967Z,1336618337.967 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2012-05-10T02:52:17.968Z,1336618337.968 [Default:CallIridium](INFO): Completed Default:CallIridium 2012-05-10T02:52:17.968Z,1336618337.968 [Default:CallIridium] Stopped 2012-05-10T02:52:17.968Z,1336618337.968 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2012-05-10T02:52:18.753Z,1336618338.753 [NAL9601](IMPORTANT): GPS fix at: 1336618379.00 2012-05-10T02:52:18.769Z,1336618338.769 [Default:GPS:Read_GPS] Stopped 2012-05-10T02:52:18.769Z,1336618338.769 [Default:GPS:D] Running Loop=1 2012-05-10T02:52:19.208Z,1336618339.208 [Default:GPS:D] Stopped 2012-05-10T02:52:19.208Z,1336618339.208 [Default:GPS](INFO): Completed Default:GPS 2012-05-10T02:52:19.208Z,1336618339.208 [Default:GPS] Stopped 2012-05-10T02:52:19.209Z,1336618339.209 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2012-05-10T02:52:19.209Z,1336618339.209 [Default:GPS:A.SetSpeed] Stopped 2012-05-10T02:52:19.209Z,1336618339.209 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2012-05-10T02:52:34.671Z,1336618354.671 [NAL9601](INFO): Powering down 2012-05-10T02:57:19.691Z,1336618639.691 [Default:CallIridium] Running Loop=1 2012-05-10T02:57:19.691Z,1336618639.691 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2012-05-10T02:57:19.691Z,1336618639.691 [Default:CallIridium:A] Running Loop=1 2012-05-10T02:57:19.692Z,1336618639.691 [Default:CallIridium:A] Stopped 2012-05-10T02:57:19.692Z,1336618639.692 [Default:CallIridium:B] Running Loop=1 2012-05-10T02:57:19.692Z,1336618639.692 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2012-05-10T02:57:24.646Z,1336618644.645 [Default:Iridium] Running Loop=1 2012-05-10T02:57:24.646Z,1336618644.646 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2012-05-10T02:57:24.646Z,1336618644.646 [Default:Iridium:A.SetSpeed] Running Loop=1 2012-05-10T02:57:24.646Z,1336618644.646 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2012-05-10T02:57:24.646Z,1336618644.646 [Default:Iridium:B.GoToSurface] Running Loop=1 2012-05-10T02:57:24.646Z,1336618644.646 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-05-10T02:57:24.647Z,1336618644.647 [Default:Iridium:B.GoToSurface] Stopped 2012-05-10T02:57:24.647Z,1336618644.648 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-05-10T02:57:24.648Z,1336618644.648 [Default:Iridium:Read_Iridium] Running Loop=1 2012-05-10T02:57:24.648Z,1336618644.648 [Default:GPS] Running Loop=1 2012-05-10T02:57:24.648Z,1336618644.648 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2012-05-10T02:57:24.648Z,1336618644.648 [Default:GPS:A.SetSpeed] Running Loop=1 2012-05-10T02:57:24.648Z,1336618644.648 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2012-05-10T02:57:24.648Z,1336618644.648 [Default:GPS:B.GoToSurface] Running Loop=1 2012-05-10T02:57:24.649Z,1336618644.648 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-05-10T02:57:24.649Z,1336618644.649 [Default:GPS:B.GoToSurface] Stopped 2012-05-10T02:57:24.650Z,1336618644.649 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-05-10T02:57:24.650Z,1336618644.650 [Default:GPS:Read_GPS] Running Loop=1 2012-05-10T02:57:25.346Z,1336618645.346 [NAL9601](INFO): Powering up 2012-05-10T02:58:31.071Z,1336618711.071 [NAL9601](INFO): NAL9601 initialized 2012-05-10T02:58:55.385Z,1336618735.385 [NAL9601](INFO): SBD MO Status=1, MOMSN=6361, MT Status=0, MTMSN=0 2012-05-10T02:58:55.527Z,1336618735.527 [NAL9601](INFO): Sent 235 bytes from file Logs/20120510T021825/shore0008.lzma 2012-05-10T02:58:55.527Z,1336618735.527 [NAL9601](INFO): Packets left to send: 0 2012-05-10T02:58:55.528Z,1336618735.528 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000011 2012-05-10T02:59:00.984Z,1336618740.984 [NAL9601](INFO): SBD MO Status=0, MOMSN=6362, MT Status=0, MTMSN=0 2012-05-10T02:59:01.138Z,1336618741.138 [Default:Iridium:Read_Iridium] Stopped 2012-05-10T02:59:01.143Z,1336618741.143 [Default:Iridium](INFO): Completed Default:Iridium 2012-05-10T02:59:01.143Z,1336618741.143 [Default:Iridium] Stopped 2012-05-10T02:59:01.143Z,1336618741.143 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2012-05-10T02:59:01.143Z,1336618741.143 [Default:Iridium:A.SetSpeed] Stopped 2012-05-10T02:59:01.143Z,1336618741.143 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2012-05-10T02:59:01.423Z,1336618741.422 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2012-05-10T02:59:01.423Z,1336618741.423 [Default:CallIridium:B] Stopped 2012-05-10T02:59:01.423Z,1336618741.423 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2012-05-10T02:59:01.423Z,1336618741.423 [Default:CallIridium](INFO): Completed Default:CallIridium 2012-05-10T02:59:01.423Z,1336618741.423 [Default:CallIridium] Stopped 2012-05-10T02:59:01.423Z,1336618741.423 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2012-05-10T03:03:58.078Z,1336619038.078 [AHRS_sp3003D](FAULT): Read Heading/Pitch/Roll Failure. 2012-05-10T03:03:58.079Z,1336619038.079 [AHRS_sp3003D] Communications Fault, FailCount= 1 2012-05-10T03:03:58.079Z,1336619038.079 [AHRS_sp3003D](ERROR): Communications Fault 2012-05-10T03:03:58.153Z,1336619038.153 [CBIT](ERROR): Communications Fault in component: AHRS_sp3003D 2012-05-10T03:03:58.217Z,1336619038.217 [AHRS_sp3003D](INFO): Powering down 2012-05-10T03:03:58.333Z,1336619038.332 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D 2012-05-10T03:03:58.333Z,1336619038.333 [AHRS_sp3003D] No Fault, FailCount= 1 2012-05-10T03:03:59.421Z,1336619039.421 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2012-05-10T03:04:01.470Z,1336619041.470 [Default:CallIridium] Running Loop=1 2012-05-10T03:04:01.475Z,1336619041.474 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2012-05-10T03:04:01.475Z,1336619041.475 [Default:CallIridium:A] Running Loop=1 2012-05-10T03:04:01.475Z,1336619041.475 [Default:CallIridium:A] Stopped 2012-05-10T03:04:01.475Z,1336619041.475 [Default:CallIridium:B] Running Loop=1 2012-05-10T03:04:01.475Z,1336619041.475 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2012-05-10T03:04:01.883Z,1336619041.883 [Default:Iridium] Running Loop=1 2012-05-10T03:04:01.883Z,1336619041.883 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2012-05-10T03:04:01.883Z,1336619041.883 [Default:Iridium:A.SetSpeed] Running Loop=1 2012-05-10T03:04:01.883Z,1336619041.883 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2012-05-10T03:04:01.883Z,1336619041.883 [Default:Iridium:B.GoToSurface] Running Loop=1 2012-05-10T03:04:01.883Z,1336619041.883 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-05-10T03:04:01.884Z,1336619041.884 [Default:Iridium:B.GoToSurface] Stopped 2012-05-10T03:04:01.884Z,1336619041.884 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-05-10T03:04:01.884Z,1336619041.884 [Default:Iridium:Read_Iridium] Running Loop=1 2012-05-10T03:04:20.684Z,1336619060.684 [NAL9601](INFO): SBD MO Status=1, MOMSN=6363, MT Status=0, MTMSN=0 2012-05-10T03:04:20.819Z,1336619060.819 [NAL9601](INFO): Sent 203 bytes from file Logs/20120510T021825/shore0009.lzma 2012-05-10T03:04:20.819Z,1336619060.819 [NAL9601](INFO): Packets left to send: 0 2012-05-10T03:04:20.820Z,1336619060.820 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000012 2012-05-10T03:04:27.485Z,1336619067.485 [NAL9601](INFO): SBD MO Status=0, MOMSN=6364, MT Status=0, MTMSN=0 2012-05-10T03:04:27.637Z,1336619067.637 [Default:Iridium:Read_Iridium] Stopped 2012-05-10T03:04:27.638Z,1336619067.638 [Default:Iridium](INFO): Completed Default:Iridium 2012-05-10T03:04:27.638Z,1336619067.638 [Default:Iridium] Stopped 2012-05-10T03:04:27.638Z,1336619067.638 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2012-05-10T03:04:27.638Z,1336619067.638 [Default:Iridium:A.SetSpeed] Stopped 2012-05-10T03:04:27.638Z,1336619067.638 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2012-05-10T03:04:27.904Z,1336619067.904 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2012-05-10T03:04:27.904Z,1336619067.904 [Default:CallIridium:B] Stopped 2012-05-10T03:04:27.904Z,1336619067.904 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2012-05-10T03:04:27.904Z,1336619067.904 [Default:CallIridium](INFO): Completed Default:CallIridium 2012-05-10T03:04:27.904Z,1336619067.904 [Default:CallIridium] Stopped 2012-05-10T03:04:27.905Z,1336619067.905 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2012-05-10T03:04:28.728Z,1336619068.728 [NAL9601](IMPORTANT): GPS fix at: 1336619110.00 2012-05-10T03:04:28.745Z,1336619068.745 [Default:GPS:Read_GPS] Stopped 2012-05-10T03:04:28.745Z,1336619068.745 [Default:GPS:D] Running Loop=1 2012-05-10T03:04:29.099Z,1336619069.099 [Default:GPS:D] Stopped 2012-05-10T03:04:29.100Z,1336619069.100 [Default:GPS](INFO): Completed Default:GPS 2012-05-10T03:04:29.100Z,1336619069.100 [Default:GPS] Stopped 2012-05-10T03:04:29.100Z,1336619069.100 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2012-05-10T03:04:29.100Z,1336619069.100 [Default:GPS:A.SetSpeed] Stopped 2012-05-10T03:04:29.100Z,1336619069.100 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2012-05-10T03:04:44.589Z,1336619084.589 [NAL9601](INFO): Powering down 2012-05-10T03:09:29.679Z,1336619369.679 [Default:CallIridium] Running Loop=1 2012-05-10T03:09:29.679Z,1336619369.679 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2012-05-10T03:09:29.679Z,1336619369.679 [Default:CallIridium:A] Running Loop=1 2012-05-10T03:09:29.680Z,1336619369.680 [Default:CallIridium:A] Stopped 2012-05-10T03:09:29.680Z,1336619369.680 [Default:CallIridium:B] Running Loop=1 2012-05-10T03:09:29.680Z,1336619369.680 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2012-05-10T03:09:34.635Z,1336619374.635 [Default:Iridium] Running Loop=1 2012-05-10T03:09:34.635Z,1336619374.635 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2012-05-10T03:09:34.636Z,1336619374.636 [Default:Iridium:A.SetSpeed] Running Loop=1 2012-05-10T03:09:34.636Z,1336619374.636 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2012-05-10T03:09:34.636Z,1336619374.636 [Default:Iridium:B.GoToSurface] Running Loop=1 2012-05-10T03:09:34.636Z,1336619374.636 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-05-10T03:09:34.637Z,1336619374.637 [Default:Iridium:B.GoToSurface] Stopped 2012-05-10T03:09:34.637Z,1336619374.637 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-05-10T03:09:34.637Z,1336619374.637 [Default:Iridium:Read_Iridium] Running Loop=1 2012-05-10T03:09:34.638Z,1336619374.638 [Default:GPS] Running Loop=1 2012-05-10T03:09:34.638Z,1336619374.638 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2012-05-10T03:09:34.638Z,1336619374.638 [Default:GPS:A.SetSpeed] Running Loop=1 2012-05-10T03:09:34.638Z,1336619374.638 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2012-05-10T03:09:34.639Z,1336619374.639 [Default:GPS:B.GoToSurface] Running Loop=1 2012-05-10T03:09:34.639Z,1336619374.639 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-05-10T03:09:34.640Z,1336619374.640 [Default:GPS:B.GoToSurface] Stopped 2012-05-10T03:09:34.640Z,1336619374.640 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-05-10T03:09:34.640Z,1336619374.640 [Default:GPS:Read_GPS] Running Loop=1 2012-05-10T03:09:35.378Z,1336619375.378 [NAL9601](INFO): Powering up 2012-05-10T03:10:41.063Z,1336619441.063 [NAL9601](INFO): NAL9601 initialized 2012-05-10T03:11:00.576Z,1336619460.576 [NAL9601](IMPORTANT): SBD MO Status=1, MOMSN=6365, MT Status=1, MTMSN=2611 2012-05-10T03:11:00.723Z,1336619460.723 [NAL9601](INFO): Sent 200 bytes from file Logs/20120510T021825/shore0010.lzma 2012-05-10T03:11:00.723Z,1336619460.723 [NAL9601](INFO): Packets left to send: 0 2012-05-10T03:11:00.724Z,1336619460.724 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000013 2012-05-10T03:11:01.246Z,1336619461.246 [NAL9601](IMPORTANT): Initialized file: Config/lrauv-daphne/Science.cfg 2012-05-10T03:11:03.619Z,1336619463.619 [NAL9601](IMPORTANT): Success executing cat Logs/latest/4FAB2C67.part | gunzip -f -d | cat `cp Config/lrauv-daphne/.svn/text-base/Science.cfg.svn-base Config/lrauv-daphne/Science.cfg` | vim -e Config/lrauv-daphne/Science.cfg 2012-05-10T03:11:03.669Z,1336619463.669 [CTD_NeilBrown](ERROR): Bad response: 79 2012-05-10T03:11:03.692Z,1336619463.693 [CommandLine](IMPORTANT): e59bb011fbb322c78bb246504f3dfa7c Config/lrauv-daphne/Science.cfg 2012-05-10T03:11:16.567Z,1336619476.568 [NAL9601](INFO): SBD MO Status=0, MOMSN=6366, MT Status=0, MTMSN=0 2012-05-10T03:11:28.873Z,1336619488.872 [NAL9601](INFO): SBD MO Status=1, MOMSN=6367, MT Status=0, MTMSN=0 2012-05-10T03:11:29.079Z,1336619489.079 [NAL9601](INFO): Sent 332 bytes from file Logs/20120510T021825/shore0011.lzma 2012-05-10T03:11:29.079Z,1336619489.079 [NAL9601](INFO): Packets left to send: 1 2012-05-10T03:11:29.080Z,1336619489.080 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000014 2012-05-10T03:11:37.015Z,1336619497.016 [NAL9601](INFO): SBD MO Status=1, MOMSN=6368, MT Status=0, MTMSN=0 2012-05-10T03:11:37.167Z,1336619497.167 [NAL9601](INFO): Sent 28 bytes from file Logs/20120510T021825/shore0011.lzma 2012-05-10T03:11:37.167Z,1336619497.167 [NAL9601](INFO): Packets left to send: 0 2012-05-10T03:11:37.264Z,1336619497.264 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000015 2012-05-10T03:11:41.411Z,1336619501.411 [NAL9601](INFO): SBD MO Status=0, MOMSN=6369, MT Status=0, MTMSN=0 2012-05-10T03:11:41.585Z,1336619501.585 [Default:Iridium:Read_Iridium] Stopped 2012-05-10T03:11:41.586Z,1336619501.586 [Default:Iridium](INFO): Completed Default:Iridium 2012-05-10T03:11:41.586Z,1336619501.586 [Default:Iridium] Stopped 2012-05-10T03:11:41.586Z,1336619501.586 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2012-05-10T03:11:41.586Z,1336619501.586 [Default:Iridium:A.SetSpeed] Stopped 2012-05-10T03:11:41.586Z,1336619501.586 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2012-05-10T03:11:41.839Z,1336619501.839 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2012-05-10T03:11:41.839Z,1336619501.839 [Default:CallIridium:B] Stopped 2012-05-10T03:11:41.839Z,1336619501.839 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2012-05-10T03:11:41.839Z,1336619501.839 [Default:CallIridium](INFO): Completed Default:CallIridium 2012-05-10T03:11:41.839Z,1336619501.839 [Default:CallIridium] Stopped 2012-05-10T03:11:41.839Z,1336619501.839 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2012-05-10T03:14:46.713Z,1336619686.713 [NAL9601](IMPORTANT): GPS fix at: 1336619729.00 2012-05-10T03:14:46.728Z,1336619686.727 [Default:GPS:Read_GPS] Stopped 2012-05-10T03:14:46.728Z,1336619686.728 [Default:GPS:D] Running Loop=1 2012-05-10T03:14:47.125Z,1336619687.125 [Default:GPS:D] Stopped 2012-05-10T03:14:47.126Z,1336619687.126 [Default:GPS](INFO): Completed Default:GPS 2012-05-10T03:14:47.126Z,1336619687.126 [Default:GPS] Stopped 2012-05-10T03:14:47.126Z,1336619687.126 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2012-05-10T03:14:47.127Z,1336619687.127 [Default:GPS:A.SetSpeed] Stopped 2012-05-10T03:14:47.127Z,1336619687.127 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2012-05-10T03:15:02.629Z,1336619702.629 [NAL9601](INFO): Powering down 2012-05-10T03:16:42.731Z,1336619802.731 [Default:CallIridium] Running Loop=1 2012-05-10T03:16:42.731Z,1336619802.731 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2012-05-10T03:16:42.732Z,1336619802.731 [Default:CallIridium:A] Running Loop=1 2012-05-10T03:16:42.732Z,1336619802.732 [Default:CallIridium:A] Stopped 2012-05-10T03:16:42.732Z,1336619802.732 [Default:CallIridium:B] Running Loop=1 2012-05-10T03:16:42.732Z,1336619802.732 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2012-05-10T03:16:47.685Z,1336619807.685 [Default:Iridium] Running Loop=1 2012-05-10T03:16:47.686Z,1336619807.686 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2012-05-10T03:16:47.686Z,1336619807.686 [Default:Iridium:A.SetSpeed] Running Loop=1 2012-05-10T03:16:47.686Z,1336619807.686 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2012-05-10T03:16:47.686Z,1336619807.686 [Default:Iridium:B.GoToSurface] Running Loop=1 2012-05-10T03:16:47.686Z,1336619807.686 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-05-10T03:16:47.687Z,1336619807.687 [Default:Iridium:B.GoToSurface] Stopped 2012-05-10T03:16:47.687Z,1336619807.687 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-05-10T03:16:47.687Z,1336619807.687 [Default:Iridium:Read_Iridium] Running Loop=1 2012-05-10T03:16:47.688Z,1336619807.688 [Default:GPS] Running Loop=1 2012-05-10T03:16:47.688Z,1336619807.688 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2012-05-10T03:16:47.688Z,1336619807.688 [Default:GPS:A.SetSpeed] Running Loop=1 2012-05-10T03:16:47.688Z,1336619807.688 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2012-05-10T03:16:47.688Z,1336619807.688 [Default:GPS:B.GoToSurface] Running Loop=1 2012-05-10T03:16:47.688Z,1336619807.688 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-05-10T03:16:47.689Z,1336619807.689 [Default:GPS:B.GoToSurface] Stopped 2012-05-10T03:16:47.689Z,1336619807.689 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-05-10T03:16:47.689Z,1336619807.689 [Default:GPS:Read_GPS] Running Loop=1 2012-05-10T03:16:48.314Z,1336619808.314 [NAL9601](INFO): Powering up 2012-05-10T03:17:54.039Z,1336619874.039 [NAL9601](INFO): NAL9601 initialized 2012-05-10T03:18:09.840Z,1336619889.840 [NAL9601](IMPORTANT): SBD MO Status=1, MOMSN=6370, MT Status=1, MTMSN=2612 2012-05-10T03:18:10.003Z,1336619890.003 [NAL9601](INFO): Sent 218 bytes from file Logs/20120510T021825/shore0012.lzma 2012-05-10T03:18:10.003Z,1336619890.003 [NAL9601](INFO): Packets left to send: 0 2012-05-10T03:18:10.021Z,1336619890.021 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000016 2012-05-10T03:18:10.416Z,1336619890.416 [NAL9601](INFO): Received command:restart app 2012-05-10T03:18:10.435Z,1336619890.435 [CommandLine](IMPORTANT): got command restart application 2012-05-10T03:18:10.554Z,1336619890.554 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2012-05-10T03:18:10.555Z,1336619890.555 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2012-05-10T03:18:10.710Z,1336619890.710 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler 2012-05-10T03:18:10.923Z,1336619890.922 [CTD_NeilBrown](INFO): Powering down 2012-05-10T03:18:10.923Z,1336619890.923 [ComponentRegistry](INFO): Shutting down AsyncPiEstimator ThreadHandler 2012-05-10T03:18:11.161Z,1336619891.161 [AsyncPiEstimator](DEBUG): Uninitialize AsyncPiEstimator. 2012-05-10T03:18:11.161Z,1336619891.161 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2012-05-10T03:18:11.161Z,1336619891.161 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2012-05-10T03:18:11.488Z,1336619891.488 [controlThread](DEBUG): Uninitializing ControlThread 2012-05-10T03:18:11.488Z,1336619891.488 [AHRS_sp3003D](INFO): Powering down 2012-05-10T03:18:11.576Z,1336619891.576 [DVL_micro](INFO): Powering down 2012-05-10T03:18:11.576Z,1336619891.576 [NAL9601](INFO): Powering down 2012-05-10T03:18:11.577Z,1336619891.577 [WetLabsBB2FL](INFO): Powering down 2012-05-10T03:18:11.577Z,1336619891.577 [NavChart](DEBUG): Uninitialize NavChart Derivation. 2012-05-10T03:18:11.579Z,1336619891.579 [Default] Stopped 2012-05-10T03:18:11.579Z,1336619891.579 [Default](INFO): Aggregate::uninitialize Default 2012-05-10T03:18:11.579Z,1336619891.579 [Default:GPS] Stopped 2012-05-10T03:18:11.579Z,1336619891.579 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2012-05-10T03:18:11.579Z,1336619891.579 [Default:GPS:A.SetSpeed] Stopped 2012-05-10T03:18:11.579Z,1336619891.579 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2012-05-10T03:18:11.579Z,1336619891.579 [Default:GPS:Read_GPS] Stopped 2012-05-10T03:18:11.579Z,1336619891.579 [Default:Iridium] Stopped 2012-05-10T03:18:11.579Z,1336619891.579 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2012-05-10T03:18:11.579Z,1336619891.579 [Default:Iridium:A.SetSpeed] Stopped 2012-05-10T03:18:11.580Z,1336619891.579 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2012-05-10T03:18:11.580Z,1336619891.580 [Default:Iridium:Read_Iridium] Stopped 2012-05-10T03:18:11.580Z,1336619891.580 [Default:CallIridium] Stopped 2012-05-10T03:18:11.580Z,1336619891.580 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2012-05-10T03:18:11.580Z,1336619891.580 [Default:CallIridium:B] Stopped 2012-05-10T03:18:11.580Z,1336619891.580 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2012-05-10T03:18:11.580Z,1336619891.580 [Default:D.SetSpeed] Stopped 2012-05-10T03:18:11.580Z,1336619891.580 [Default:D.SetSpeed](DEBUG): Uninitialize. 2012-05-10T03:18:11.580Z,1336619891.580 [Default:E.GoToSurface] Stopped 2012-05-10T03:18:11.580Z,1336619891.580 [Default:E.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-05-10T03:18:11.580Z,1336619891.580 [Default:F.Wait] Stopped 2012-05-10T03:18:11.580Z,1336619891.580 [Default:F.Wait](DEBUG): Uninitialize Wait Component. 2012-05-10T03:18:11.585Z,1336619891.585 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2012-05-10T03:18:11.585Z,1336619891.585 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2012-05-10T03:18:11.586Z,1336619891.586 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2012-05-10T03:18:11.586Z,1336619891.586 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2012-05-10T03:18:11.587Z,1336619891.587 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2012-05-10T03:18:11.587Z,1336619891.587 [BuoyancyServo](INFO): Powering down 2012-05-10T03:18:11.587Z,1336619891.588 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2012-05-10T03:18:11.588Z,1336619891.588 [ElevatorServo](INFO): Powering down 2012-05-10T03:18:11.588Z,1336619891.588 [MassServo](DEBUG): Uninitialize Mass Servo. 2012-05-10T03:18:11.588Z,1336619891.588 [MassServo](INFO): Powering down 2012-05-10T03:18:11.588Z,1336619891.588 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2012-05-10T03:18:11.589Z,1336619891.589 [RudderServo](INFO): Powering down 2012-05-10T03:18:11.589Z,1336619891.589 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2012-05-10T03:18:11.589Z,1336619891.589 [ThrusterServo](INFO): Powering down 2012-05-10T03:18:11.589Z,1336619891.589 [SBIT](DEBUG): Uninitialize SBIT Component. 2012-05-10T03:18:11.590Z,1336619891.590 [IBIT](DEBUG): Uninitialize IBIT Component. 2012-05-10T03:18:11.590Z,1336619891.590 [CBIT](DEBUG): Uninitialize CBIT Component.