2014-04-13T13:23:23.578Z,1397395403.578 [Supervisor](DEBUG): Initializing supervisor. 2014-04-13T13:23:23.588Z,1397395403.588 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0 2014-04-13T13:23:23.602Z,1397395403.602 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2014-04-13T13:23:23.603Z,1397395403.603 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0 2014-04-13T13:23:23.606Z,1397395403.606 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2014-04-13T13:23:23.620Z,1397395403.620 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2014-04-13T13:23:23.623Z,1397395403.623 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0 2014-04-13T13:23:23.626Z,1397395403.626 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2014-04-13T13:23:23.634Z,1397395403.634 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0 2014-04-13T13:23:23.649Z,1397395403.649 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2014-04-13T13:23:23.651Z,1397395403.651 [Supervisor](INFO): Looking for Config files in directory: Config/ 2014-04-13T13:23:23.671Z,1397395403.671 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2014-04-13T13:23:24.434Z,1397395404.434 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2014-04-13T13:23:24.435Z,1397395404.435 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2014-04-13T13:23:25.730Z,1397395405.730 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2014-04-13T13:23:25.731Z,1397395405.731 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2014-04-13T13:23:25.888Z,1397395405.888 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2014-04-13T13:23:25.891Z,1397395405.891 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2014-04-13T13:23:26.144Z,1397395406.144 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2014-04-13T13:23:26.144Z,1397395406.144 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2014-04-13T13:23:26.304Z,1397395406.304 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2014-04-13T13:23:26.306Z,1397395406.306 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2014-04-13T13:23:26.610Z,1397395406.610 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2014-04-13T13:23:26.610Z,1397395406.610 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2014-04-13T13:23:26.793Z,1397395406.793 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2014-04-13T13:23:26.796Z,1397395406.796 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2014-04-13T13:23:27.132Z,1397395407.132 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2014-04-13T13:23:27.134Z,1397395407.134 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2014-04-13T13:23:27.247Z,1397395407.247 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2014-04-13T13:23:27.248Z,1397395407.248 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2014-04-13T13:23:27.751Z,1397395407.751 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2014-04-13T13:23:27.752Z,1397395407.752 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2014-04-13T13:23:27.863Z,1397395407.863 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2014-04-13T13:23:27.864Z,1397395407.864 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2014-04-13T13:23:27.951Z,1397395407.951 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2014-04-13T13:23:28.058Z,1397395408.058 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2014-04-13T13:23:28.060Z,1397395408.060 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2014-04-13T13:23:28.165Z,1397395408.165 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2014-04-13T13:23:28.166Z,1397395408.166 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2014-04-13T13:23:28.289Z,1397395408.289 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2014-04-13T13:23:28.291Z,1397395408.291 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2014-04-13T13:23:28.295Z,1397395408.295 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2014-04-13T13:23:28.402Z,1397395408.402 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2014-04-13T13:23:28.531Z,1397395408.531 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2014-04-13T13:23:28.628Z,1397395408.628 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2014-04-13T13:23:28.722Z,1397395408.722 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2014-04-13T13:23:28.874Z,1397395408.874 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2014-04-13T13:23:28.991Z,1397395408.991 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2014-04-13T13:23:29.144Z,1397395409.144 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2014-04-13T13:23:29.257Z,1397395409.257 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2014-04-13T13:23:29.358Z,1397395409.358 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2014-04-13T13:23:29.362Z,1397395409.362 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2014-04-13T13:23:30.048Z,1397395410.048 [AHRS_sp3003D] Loaded 2014-04-13T13:23:30.049Z,1397395410.049 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread. 2014-04-13T13:23:30.339Z,1397395410.339 [Batt_Ocean_Server] Loaded 2014-04-13T13:23:30.339Z,1397395410.339 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread. 2014-04-13T13:23:30.353Z,1397395410.353 [Depth_Keller] Loaded 2014-04-13T13:23:30.353Z,1397395410.353 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2014-04-13T13:23:30.358Z,1397395410.358 [DropWeight] Loaded 2014-04-13T13:23:30.358Z,1397395410.358 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2014-04-13T13:23:30.496Z,1397395410.496 [DVL_micro] Loaded 2014-04-13T13:23:30.496Z,1397395410.496 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2014-04-13T13:23:30.595Z,1397395410.595 [NAL9602] Loaded 2014-04-13T13:23:30.596Z,1397395410.596 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2014-04-13T13:23:30.647Z,1397395410.647 [Onboard] Loaded 2014-04-13T13:23:30.647Z,1397395410.647 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2014-04-13T13:23:30.654Z,1397395410.654 [Radio_Freewave] Loaded 2014-04-13T13:23:30.655Z,1397395410.655 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread. 2014-04-13T13:23:30.661Z,1397395410.661 [SCPI] Loaded 2014-04-13T13:23:30.662Z,1397395410.662 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread. 2014-04-13T13:23:30.662Z,1397395410.662 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2014-04-13T13:23:30.663Z,1397395410.663 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2014-04-13T13:23:30.856Z,1397395410.856 [InternalSim] Loaded 2014-04-13T13:23:30.856Z,1397395410.856 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread. 2014-04-13T13:23:30.857Z,1397395410.857 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2014-04-13T13:23:30.857Z,1397395410.857 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2014-04-13T13:23:31.132Z,1397395411.132 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2014-04-13T13:23:31.133Z,1397395411.133 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2014-04-13T13:23:31.141Z,1397395411.141 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator. 2014-04-13T13:23:31.146Z,1397395411.146 [AsyncPiEstimator] Loaded 2014-04-13T13:23:31.147Z,1397395411.147 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread. 2014-04-13T13:23:31.148Z,1397395411.148 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 4069E4E0 2014-04-13T13:23:31.149Z,1397395411.149 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2014-04-13T13:23:31.149Z,1397395411.149 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2014-04-13T13:23:31.242Z,1397395411.242 [DeadReckonUsingMultipleVelocitySources] Loaded 2014-04-13T13:23:31.243Z,1397395411.243 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2014-04-13T13:23:31.259Z,1397395411.259 [NavChart] Loaded 2014-04-13T13:23:31.259Z,1397395411.259 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2014-04-13T13:23:31.260Z,1397395411.260 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2014-04-13T13:23:31.261Z,1397395411.261 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2014-04-13T13:23:31.328Z,1397395411.328 [VerticalControl](DEBUG): Construct VerticalControl. 2014-04-13T13:23:31.438Z,1397395411.438 [VerticalControl] Loaded 2014-04-13T13:23:31.438Z,1397395411.438 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2014-04-13T13:23:31.439Z,1397395411.439 [HorizontalControl](DEBUG): Construct HorizontalControl. 2014-04-13T13:23:31.505Z,1397395411.505 [HorizontalControl] Loaded 2014-04-13T13:23:31.505Z,1397395411.505 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2014-04-13T13:23:31.506Z,1397395411.506 [SpeedControl](DEBUG): Construct SpeedControl. 2014-04-13T13:23:31.508Z,1397395411.508 [SpeedControl] Loaded 2014-04-13T13:23:31.508Z,1397395411.508 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2014-04-13T13:23:31.509Z,1397395411.509 [LoopControl](DEBUG): Construct LoopControl. 2014-04-13T13:23:31.509Z,1397395411.509 [LoopControl] Loaded 2014-04-13T13:23:31.510Z,1397395411.510 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2014-04-13T13:23:31.510Z,1397395411.510 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2014-04-13T13:23:31.511Z,1397395411.511 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2014-04-13T13:23:31.540Z,1397395411.540 [DepthRateCalculator] Loaded 2014-04-13T13:23:31.540Z,1397395411.540 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2014-04-13T13:23:31.546Z,1397395411.546 [PitchRateCalculator] Loaded 2014-04-13T13:23:31.546Z,1397395411.546 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2014-04-13T13:23:31.553Z,1397395411.553 [SpeedCalculator] Loaded 2014-04-13T13:23:31.553Z,1397395411.553 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2014-04-13T13:23:31.559Z,1397395411.559 [YawRateCalculator] Loaded 2014-04-13T13:23:31.559Z,1397395411.559 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2014-04-13T13:23:31.559Z,1397395411.559 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2014-04-13T13:23:31.560Z,1397395411.560 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2014-04-13T13:23:31.690Z,1397395411.690 [CTD_NeilBrown] Loaded 2014-04-13T13:23:31.691Z,1397395411.691 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2014-04-13T13:23:31.692Z,1397395411.692 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 407404E0 2014-04-13T13:23:31.707Z,1397395411.707 [PAR_Licor] Loaded 2014-04-13T13:23:31.708Z,1397395411.708 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2014-04-13T13:23:31.742Z,1397395411.742 [WetLabsBB2FL] Loaded 2014-04-13T13:23:31.743Z,1397395411.743 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2014-04-13T13:23:31.744Z,1397395411.744 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407704E0 2014-04-13T13:23:31.744Z,1397395411.744 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2014-04-13T13:23:31.747Z,1397395411.747 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2014-04-13T13:23:31.862Z,1397395411.862 [SBIT](DEBUG): Construct Startup Built In Test. 2014-04-13T13:23:31.874Z,1397395411.874 [SBIT] Loaded 2014-04-13T13:23:31.874Z,1397395411.874 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2014-04-13T13:23:31.875Z,1397395411.875 [IBIT](DEBUG): Construct Initiated Built In Test. 2014-04-13T13:23:31.887Z,1397395411.887 [IBIT] Loaded 2014-04-13T13:23:31.888Z,1397395411.888 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2014-04-13T13:23:31.890Z,1397395411.890 [CBIT](DEBUG): Construct CBIT Built In Test. 2014-04-13T13:23:31.958Z,1397395411.958 [CBIT] Loaded 2014-04-13T13:23:31.958Z,1397395411.958 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2014-04-13T13:23:31.959Z,1397395411.959 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2014-04-13T13:23:31.961Z,1397395411.961 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2014-04-13T13:23:32.030Z,1397395412.030 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2014-04-13T13:23:32.030Z,1397395412.030 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2014-04-13T13:23:32.149Z,1397395412.149 [BuoyancyServo] Loaded 2014-04-13T13:23:32.149Z,1397395412.149 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2014-04-13T13:23:32.161Z,1397395412.161 [ElevatorServo] Loaded 2014-04-13T13:23:32.162Z,1397395412.162 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2014-04-13T13:23:32.173Z,1397395412.173 [MassServo] Loaded 2014-04-13T13:23:32.173Z,1397395412.173 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2014-04-13T13:23:32.185Z,1397395412.185 [RudderServo] Loaded 2014-04-13T13:23:32.185Z,1397395412.185 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2014-04-13T13:23:32.197Z,1397395412.197 [ThrusterServo] Loaded 2014-04-13T13:23:32.197Z,1397395412.197 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2014-04-13T13:23:32.198Z,1397395412.198 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2014-04-13T13:23:32.198Z,1397395412.198 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2014-04-13T13:23:32.238Z,1397395412.238 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2014-04-13T13:23:32.240Z,1397395412.240 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2014-04-13T13:23:32.241Z,1397395412.241 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2014-04-13T13:23:32.247Z,1397395412.247 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2014-04-13T13:23:32.248Z,1397395412.248 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 4083E4E0 2014-04-13T13:23:32.253Z,1397395412.253 [Supervisor](DEBUG): Running supervisor. 2014-04-13T13:23:32.254Z,1397395412.254 [CommandLine](INFO): Thread ID is 772 2014-04-13T13:23:32.257Z,1397395412.257 [controlThread](INFO): Thread ID is 771 2014-04-13T13:23:32.257Z,1397395412.257 [controlThread](DEBUG): Initializing ControlThread 2014-04-13T13:23:32.258Z,1397395412.258 [CycleStarter](INFO): Thread ID is 770 2014-04-13T13:23:32.261Z,1397395412.261 [logger](INFO): Thread ID is 773 2014-04-13T13:23:32.286Z,1397395412.286 [AsyncPiEstimator](INFO): Thread ID is 848 2014-04-13T13:23:32.287Z,1397395412.287 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator. 2014-04-13T13:23:32.310Z,1397395412.310 [CTD_NeilBrown](INFO): Thread ID is 849 2014-04-13T13:23:32.310Z,1397395412.310 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown. 2014-04-13T13:23:32.314Z,1397395412.314 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4 2014-04-13T13:23:32.323Z,1397395412.323 [WetLabsBB2FL](INFO): Thread ID is 850 2014-04-13T13:23:32.324Z,1397395412.324 [WetLabsBB2FL](INFO): Powering down 2014-04-13T13:23:32.346Z,1397395412.346 [NavChartDb](INFO): Thread ID is 851 2014-04-13T13:23:32.353Z,1397395412.353 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources 2014-04-13T13:23:32.356Z,1397395412.356 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2014-04-13T13:23:32.356Z,1397395412.356 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2014-04-13T13:23:32.356Z,1397395412.356 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2014-04-13T13:23:32.357Z,1397395412.357 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2014-04-13T13:23:32.357Z,1397395412.357 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2014-04-13T13:23:32.358Z,1397395412.358 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2014-04-13T13:23:32.358Z,1397395412.358 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2014-04-13T13:23:32.358Z,1397395412.358 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2014-04-13T13:23:33.734Z,1397395413.734 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized 2014-04-13T13:23:33.770Z,1397395413.770 [InternalSim](DEBUG): InternalSim initializing... 2014-04-13T13:23:34.056Z,1397395414.056 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2014-04-13T13:23:34.057Z,1397395414.057 [NavChart](DEBUG): Initialize NavChart Navigation. 2014-04-13T13:23:34.057Z,1397395414.057 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2014-04-13T13:23:34.059Z,1397395414.059 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2014-04-13T13:23:34.059Z,1397395414.059 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2014-04-13T13:23:34.060Z,1397395414.060 [LoopControl](DEBUG): Initialize LoopControlComponent. 2014-04-13T13:23:34.060Z,1397395414.060 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2014-04-13T13:23:34.061Z,1397395414.061 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2014-04-13T13:23:34.061Z,1397395414.061 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2014-04-13T13:23:34.061Z,1397395414.061 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2014-04-13T13:23:34.084Z,1397395414.084 [SBIT](INFO): Initialize SBIT Component. 2014-04-13T13:23:34.085Z,1397395414.085 [SBIT](IMPORTANT): Tethys CM Info: $Rev:11196 2014-04-13T13:23:34.085Z,1397395414.085 [SBIT](IMPORTANT): Kernel Release:2.6.27.8 2014-04-13T13:23:34.085Z,1397395414.085 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014 2014-04-13T13:23:34.086Z,1397395414.086 [IBIT](INFO): Initialize IBIT Component. 2014-04-13T13:23:34.087Z,1397395414.087 [CBIT](DEBUG): Initialize CBIT Component. 2014-04-13T13:23:34.087Z,1397395414.087 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2014-04-13T13:23:34.114Z,1397395414.114 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2014-04-13T13:23:34.153Z,1397395414.153 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-13T13:23:34.201Z,1397395414.201 [MissionManager](DEBUG): 2014-04-13T13:23:34.202Z,1397395414.202 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2014-04-13T13:23:34.292Z,1397395414.292 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool 2014-04-13T13:23:34.294Z,1397395414.294 [Default:GPS:A.SetSpeed](DEBUG): Construct. 2014-04-13T13:23:34.315Z,1397395414.315 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-13T13:23:34.331Z,1397395414.331 [Default:Iridium:A.SetSpeed](DEBUG): Construct. 2014-04-13T13:23:34.334Z,1397395414.334 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-13T13:23:34.355Z,1397395414.355 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2014-04-13T13:23:34.402Z,1397395414.402 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Construct. 2014-04-13T13:23:34.411Z,1397395414.411 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-13T13:23:34.426Z,1397395414.426 [MissionManager](DEBUG): 400 400 Burn 300 Dropped drop weight due to communications timeout 5.0 1.0 5 2014-04-13T13:23:34.431Z,1397395414.431 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,Radio_Freewave,SCPI,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2014-04-13T13:23:34.530Z,1397395414.530 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2014-04-13T13:23:34.692Z,1397395414.692 [DVL_micro](INFO): Initializing 2014-04-13T13:23:34.822Z,1397395414.822 [Radio_Freewave](INFO): Powering up 2014-04-13T13:23:35.043Z,1397395415.043 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:35.158Z,1397395415.158 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2014-04-13T13:23:35.182Z,1397395415.182 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2014-04-13T13:23:35.197Z,1397395415.197 [ElevatorServo](DEBUG): Initializing EZServoServo. 2014-04-13T13:23:35.206Z,1397395415.206 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2014-04-13T13:23:35.220Z,1397395415.220 [MassServo](DEBUG): Initializing EZServoServo. 2014-04-13T13:23:35.226Z,1397395415.226 [MassServo](DEBUG): Initializing MassServo. 2014-04-13T13:23:35.244Z,1397395415.244 [RudderServo](DEBUG): Initializing EZServoServo. 2014-04-13T13:23:35.250Z,1397395415.250 [RudderServo](DEBUG): Initializing RudderServo. 2014-04-13T13:23:35.256Z,1397395415.256 [ThrusterServo](DEBUG): Initializing EZServoServo. 2014-04-13T13:23:35.282Z,1397395415.282 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2014-04-13T13:23:35.639Z,1397395415.639 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:36.114Z,1397395416.114 [NAL9602](INFO): Powering up NAL9602 2014-04-13T13:23:36.158Z,1397395416.158 [Radio_Freewave](IMPORTANT): Starting PPPD with command:/sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0 2014-04-13T13:23:36.331Z,1397395416.331 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:37.152Z,1397395417.152 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:37.617Z,1397395417.617 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:38.115Z,1397395418.115 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:38.809Z,1397395418.809 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:39.389Z,1397395419.389 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:40.052Z,1397395420.052 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:40.746Z,1397395420.746 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:41.274Z,1397395421.274 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:41.723Z,1397395421.723 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:42.210Z,1397395422.210 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:42.655Z,1397395422.655 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:43.139Z,1397395423.139 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:43.657Z,1397395423.657 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:44.259Z,1397395424.259 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:44.723Z,1397395424.723 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:45.216Z,1397395425.216 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:45.656Z,1397395425.656 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:46.132Z,1397395426.132 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:46.598Z,1397395426.598 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:47.129Z,1397395427.129 [NAL9602](ERROR): NAL9602 initialize error - Can't enter command mode:-MSSTM: no network service 2014-04-13T13:23:47.129Z,1397395427.129 [NAL9602] Communications Fault, FailCount= 1 2014-04-13T13:23:47.129Z,1397395427.129 [NAL9602](ERROR): Communications Fault 2014-04-13T13:23:47.159Z,1397395427.159 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:47.212Z,1397395427.212 [CBIT](ERROR): Communications Fault in component: NAL9602 2014-04-13T13:23:47.580Z,1397395427.580 [NAL9602](INFO): Powering down 2014-04-13T13:23:47.662Z,1397395427.662 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:48.184Z,1397395428.184 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:48.671Z,1397395428.671 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:48.722Z,1397395428.722 [CBIT](INFO): Clearing failed state for component NAL9602 2014-04-13T13:23:48.722Z,1397395428.722 [NAL9602] No Fault, FailCount= 1 2014-04-13T13:23:49.127Z,1397395429.127 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:49.691Z,1397395429.691 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:49.746Z,1397395429.746 [SBIT](IMPORTANT): Beginning Startup BIT 2014-04-13T13:23:49.750Z,1397395429.750 [CBIT](IMPORTANT): Beginning GF scan 2014-04-13T13:23:50.250Z,1397395430.250 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:50.784Z,1397395430.784 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:51.297Z,1397395431.297 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:51.758Z,1397395431.758 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:52.327Z,1397395432.327 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:52.816Z,1397395432.816 [NAL9602](INFO): Powering up NAL9602 2014-04-13T13:23:52.844Z,1397395432.844 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:53.434Z,1397395433.434 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:54.006Z,1397395434.006 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:54.630Z,1397395434.630 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:55.283Z,1397395435.283 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:55.797Z,1397395435.797 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:56.313Z,1397395436.313 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:56.892Z,1397395436.892 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:57.425Z,1397395437.425 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:57.927Z,1397395437.927 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:58.356Z,1397395438.356 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:58.888Z,1397395438.888 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:23:59.533Z,1397395439.533 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:00.042Z,1397395440.042 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:102 Calculated:103 2014-04-13T13:24:00.042Z,1397395440.042 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 43.7 44.8 43.2 42.6 108.3 117.3 248.2 230.5 115 189 11 12 11 11 -186.7 -151.1 189.9 1 -66.7 229.5 191.4 1 -126 -78 173 2 -29 146 173 2 -2.67 -1.62 249.7 42.6 15.0 0.005 35.0 1489 102 2014-04-13T13:24:00.096Z,1397395440.096 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:00.579Z,1397395440.579 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:01.234Z,1397395441.234 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:01.720Z,1397395441.720 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:02.146Z,1397395442.146 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:02.586Z,1397395442.586 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:03.126Z,1397395443.126 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:03.718Z,1397395443.718 [NAL9602](INFO): NAL9602 initialized 2014-04-13T13:24:03.744Z,1397395443.744 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:04.208Z,1397395444.208 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:04.754Z,1397395444.754 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:05.254Z,1397395445.254 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:06.139Z,1397395446.139 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:06.801Z,1397395446.801 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:07.336Z,1397395447.336 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:07.862Z,1397395447.862 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:08.426Z,1397395448.426 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:08.937Z,1397395448.937 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:09.435Z,1397395449.435 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:10.145Z,1397395450.145 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:10.639Z,1397395450.639 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:11.150Z,1397395451.150 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:11.681Z,1397395451.681 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:12.244Z,1397395452.244 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:12.789Z,1397395452.789 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:13.386Z,1397395453.386 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T13:24:13.386Z,1397395453.386 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 42.2 44.6 45.8 42.6 -65.8 -39.0 68.9 57.4 -33 0 35 42 11 12 13 11 -179.8 -128.7 5.8 1 -47.2 216.0 -7.9 1 -90 -56 11 2 -15 105 11 2 .59 246.7 42.2 15.0 0.005 35.0 1489 96 2014-04-13T13:24:13.423Z,1397395453.423 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:13.944Z,1397395453.944 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:14.518Z,1397395454.518 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:15.156Z,1397395455.156 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:15.699Z,1397395455.699 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:16.215Z,1397395456.215 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:16.326Z,1397395456.326 [CBIT](IMPORTANT): No ground fault detected 2014-04-13T13:24:16.798Z,1397395456.798 [NAL9602](INFO): SBD MO Status=0, MOMSN=25354, MT Status=0, MTMSN=0 2014-04-13T13:24:16.799Z,1397395456.799 [NAL9602](INFO): No messages in MT queue 2014-04-13T13:24:16.832Z,1397395456.832 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:17.353Z,1397395457.353 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:17.882Z,1397395457.882 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:18.362Z,1397395458.362 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:18.884Z,1397395458.884 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:19.416Z,1397395459.416 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:20.022Z,1397395460.022 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:20.650Z,1397395460.650 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:21.140Z,1397395461.140 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:21.620Z,1397395461.620 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:22.144Z,1397395462.144 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:22.629Z,1397395462.629 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:23.229Z,1397395463.229 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:23.703Z,1397395463.703 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:24.194Z,1397395464.194 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:24.705Z,1397395464.705 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:25.192Z,1397395465.192 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:25.800Z,1397395465.800 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:26.333Z,1397395466.333 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:26.756Z,1397395466.756 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:27.229Z,1397395467.229 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:27.688Z,1397395467.688 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:28.160Z,1397395468.160 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:28.618Z,1397395468.618 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:29.084Z,1397395469.084 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:29.579Z,1397395469.579 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:30.049Z,1397395470.049 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:30.660Z,1397395470.660 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:31.157Z,1397395471.157 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:31.619Z,1397395471.619 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:32.115Z,1397395472.115 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:32.521Z,1397395472.521 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:33.200Z,1397395473.200 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:34.047Z,1397395474.047 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:34.548Z,1397395474.548 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:35.121Z,1397395475.121 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T13:24:35.762Z,1397395475.762 [NAL9602](IMPORTANT): GPS fix at: 1397395437.00 2014-04-13T13:24:35.816Z,1397395475.816 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T13:24:43.028Z,1397395483.028 [NAL9602](INFO): Powering down 2014-04-13T13:24:44.357Z,1397395484.357 [SBIT](IMPORTANT): SBIT PASSED 2014-04-13T13:24:44.758Z,1397395484.758 [MissionManager](IMPORTANT): Started mission Startup 2014-04-13T13:24:44.758Z,1397395484.758 [Startup] Running Loop=1 2014-04-13T13:24:44.758Z,1397395484.758 [Startup](INFO): Aggregate::initialize Startup 2014-04-13T13:24:44.758Z,1397395484.758 [Startup:A.GoToSurface] Running Loop=1 2014-04-13T13:24:44.758Z,1397395484.758 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T13:24:44.764Z,1397395484.764 [Startup:StartupSatComms] Running Loop=1 2014-04-13T13:24:44.764Z,1397395484.764 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms 2014-04-13T13:24:44.765Z,1397395484.765 [Startup:StartupSatComms:A] Running Loop=1 2014-04-13T13:24:45.195Z,1397395485.195 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2014-04-13T13:24:45.636Z,1397395485.636 [NAL9602](INFO): Powering up 2014-04-13T13:24:54.800Z,1397395494.800 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 38 of 46 2014-04-13T13:24:54.801Z,1397395494.801 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 43.2 44.4 44.5 43.0 -268.8 -280.6 -137.7 -88.1 -166 -175 -69 -73 1116.8 1 -129 -136 -130 2 -89 165 -130 2 -1.43 -4.92 252.0 43.0 15.0 0.005 35.0 1489 84 2014-04-13T13:24:56.119Z,1397395496.119 [NAL9602](INFO): NAL9602 initialized 2014-04-13T13:24:57.520Z,1397395497.520 [NAL9602](IMPORTANT): GPS fix at: 1397395459.00 2014-04-13T13:24:57.533Z,1397395497.533 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T13:24:57.536Z,1397395497.536 [Startup:StartupSatComms:A] Stopped 2014-04-13T13:24:57.536Z,1397395497.536 [Startup:StartupSatComms:B] Running Loop=1 2014-04-13T13:24:57.947Z,1397395497.947 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2014-04-13T13:25:20.423Z,1397395520.423 [NAL9602](INFO): SBD MO Status=1, MOMSN=25355, MT Status=0, MTMSN=0 2014-04-13T13:25:20.473Z,1397395520.473 [NAL9602](INFO): Sent 45 bytes from file Logs/20140413T130214/Courier0016.lzma 2014-04-13T13:25:20.474Z,1397395520.474 [NAL9602](INFO): Packets left to send: 0 2014-04-13T13:25:20.475Z,1397395520.475 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T130214/Courier0016.lzma.parts/0000.sbd 2014-04-13T13:25:20.476Z,1397395520.476 [NAL9602](INFO): Completed sending Logs/20140413T130214/Courier0016.lzma 2014-04-13T13:25:33.317Z,1397395533.317 [NAL9602](INFO): SBD MO Status=2, MOMSN=25356, MT Status=2, MTMSN=0 2014-04-13T13:25:33.317Z,1397395533.317 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2014-04-13T13:25:54.917Z,1397395554.917 [NAL9602](INFO): SBD MO Status=1, MOMSN=25356, MT Status=0, MTMSN=0 2014-04-13T13:25:54.975Z,1397395554.975 [NAL9602](INFO): Sent 293 bytes from file Logs/20140413T132323/Courier0000.lzma 2014-04-13T13:25:54.975Z,1397395554.975 [NAL9602](INFO): Packets left to send: 0 2014-04-13T13:25:54.977Z,1397395554.977 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Courier0000.lzma.parts/0000.sbd 2014-04-13T13:25:54.977Z,1397395554.977 [NAL9602](INFO): Completed sending Logs/20140413T132323/Courier0000.lzma 2014-04-13T13:25:58.604Z,1397395558.604 [Startup:StartupSatComms:B](INFO): Timed out from 2014-04-13T13:24:57.5Z 2014-04-13T13:25:58.604Z,1397395558.604 [Startup:StartupSatComms:B] Stopped 2014-04-13T13:25:58.605Z,1397395558.605 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2014-04-13T13:25:58.605Z,1397395558.605 [Startup:StartupSatComms] Stopped 2014-04-13T13:25:58.605Z,1397395558.605 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms 2014-04-13T13:25:58.606Z,1397395558.606 [Startup](INFO): Completed Startup 2014-04-13T13:25:58.606Z,1397395558.606 [Startup] Stopped 2014-04-13T13:25:58.606Z,1397395558.606 [Startup](INFO): Aggregate::uninitialize Startup 2014-04-13T13:25:58.606Z,1397395558.606 [Startup:A.GoToSurface] Stopped 2014-04-13T13:25:58.606Z,1397395558.606 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T13:25:59.241Z,1397395559.241 [MissionManager](IMPORTANT): Started mission Default 2014-04-13T13:25:59.241Z,1397395559.241 [Default] Running Loop=1 2014-04-13T13:25:59.241Z,1397395559.241 [Default](INFO): Aggregate::initialize Default 2014-04-13T13:25:59.241Z,1397395559.241 [Default:Iridium] Running Loop=1 2014-04-13T13:25:59.242Z,1397395559.242 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2014-04-13T13:25:59.242Z,1397395559.242 [Default:Iridium:A.SetSpeed] Running Loop=1 2014-04-13T13:25:59.242Z,1397395559.242 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2014-04-13T13:25:59.242Z,1397395559.242 [Default:Iridium:B.GoToSurface] Running Loop=1 2014-04-13T13:25:59.242Z,1397395559.242 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T13:25:59.243Z,1397395559.243 [Default:CallIridium] Running Loop=1 2014-04-13T13:25:59.243Z,1397395559.243 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2014-04-13T13:25:59.243Z,1397395559.243 [Default:CallIridium:A] Running Loop=1 2014-04-13T13:25:59.245Z,1397395559.245 [Default:CallIridium:A] Stopped 2014-04-13T13:25:59.245Z,1397395559.245 [Default:CallIridium:B] Running Loop=1 2014-04-13T13:25:59.245Z,1397395559.245 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2014-04-13T13:25:59.251Z,1397395559.251 [Default:Iridium:B.GoToSurface] Stopped 2014-04-13T13:25:59.251Z,1397395559.251 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T13:25:59.251Z,1397395559.251 [Default:Iridium:Read_Iridium] Running Loop=1 2014-04-13T13:25:59.251Z,1397395559.251 [Default:Iridium:A.SetSpeed] Running Loop=1 2014-04-13T13:25:59.257Z,1397395559.257 [Default:GPS] Running Loop=1 2014-04-13T13:25:59.257Z,1397395559.257 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2014-04-13T13:25:59.257Z,1397395559.257 [Default:GPS:A.SetSpeed] Running Loop=1 2014-04-13T13:25:59.257Z,1397395559.257 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2014-04-13T13:25:59.257Z,1397395559.257 [Default:GPS:B.GoToSurface] Running Loop=1 2014-04-13T13:25:59.257Z,1397395559.257 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T13:25:59.263Z,1397395559.263 [Default:GPS:B.GoToSurface] Stopped 2014-04-13T13:25:59.263Z,1397395559.263 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T13:25:59.263Z,1397395559.263 [Default:GPS:Read_GPS] Running Loop=1 2014-04-13T13:25:59.263Z,1397395559.263 [Default:GPS:A.SetSpeed] Running Loop=1 2014-04-13T13:25:59.712Z,1397395559.712 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2014-04-13T13:25:59.716Z,1397395559.716 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2014-04-13T13:26:04.017Z,1397395564.017 [NAL9602](INFO): SBD MO Status=1, MOMSN=25357, MT Status=0, MTMSN=0 2014-04-13T13:26:04.069Z,1397395564.069 [NAL9602](INFO): Sent 97 bytes from file Logs/20140413T130214/Express0013.lzma 2014-04-13T13:26:04.069Z,1397395564.069 [NAL9602](INFO): Packets left to send: 0 2014-04-13T13:26:04.071Z,1397395564.071 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T130214/Express0013.lzma.parts/0000.sbd 2014-04-13T13:26:04.071Z,1397395564.071 [NAL9602](INFO): Completed sending Logs/20140413T130214/Express0013.lzma 2014-04-13T13:26:13.736Z,1397395573.736 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 4 of 46 2014-04-13T13:26:13.736Z,1397395573.736 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 12 45.9 47.7 42.8 -179.8 -338.6 -188.4 -43.3 -153 -338 -280 -163 11 13 13 11 11.5 -394.1 -202.3 1 -384.4 152.3 -159.4 1 169 -233 -251 2 -284 -48 -251 2 -5.67 -7.05 243.7 42.2 15.0 0.005 35.0 1489 71 2014-04-13T13:27:10.903Z,1397395630.903 [NAL9602](INFO): SBD MO Status=2, MOMSN=25358, MT Status=2, MTMSN=0 2014-04-13T13:27:10.903Z,1397395630.903 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2014-04-13T13:27:11.320Z,1397395631.320 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 4 of 46 2014-04-13T13:27:11.321Z,1397395631.321 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 1 1 1 42.2 44.2 45.8 43.1 -132.6 -54.6 2.1 -83.6 -117 -131 -123 -113 11 12 13 11 -179.8 38.7 -72.5 1 41.4 172.2 -87.9 1 8 -24 -130 2 -24 -7 -130 2 -0.63 -4.88 268.8 42.2 15.0 0.005 35.0 1489 124 2014-04-13T13:27:12.186Z,1397395632.186 [NAL9602](IMPORTANT): GPS fix at: 1397395593.00 2014-04-13T13:27:12.218Z,1397395632.218 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T13:27:12.222Z,1397395632.222 [Default:GPS:Read_GPS] Stopped 2014-04-13T13:27:12.222Z,1397395632.222 [Default:GPS:D] Running Loop=1 2014-04-13T13:27:12.654Z,1397395632.654 [Default:GPS:D] Stopped 2014-04-13T13:27:12.654Z,1397395632.654 [Default:GPS](INFO): Completed Default:GPS 2014-04-13T13:27:12.655Z,1397395632.655 [Default:GPS] Stopped 2014-04-13T13:27:12.655Z,1397395632.655 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2014-04-13T13:27:12.655Z,1397395632.655 [Default:GPS:A.SetSpeed] Stopped 2014-04-13T13:27:12.655Z,1397395632.655 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2014-04-13T13:27:29.694Z,1397395649.694 [NAL9602](INFO): SBD MO Status=1, MOMSN=25358, MT Status=0, MTMSN=0 2014-04-13T13:27:29.742Z,1397395649.742 [NAL9602](INFO): Sent 75 bytes from file Logs/20140413T132323/Courier0004.lzma 2014-04-13T13:27:29.742Z,1397395649.742 [NAL9602](INFO): Packets left to send: 0 2014-04-13T13:27:29.743Z,1397395649.743 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Courier0004.lzma.parts/0000.sbd 2014-04-13T13:27:29.744Z,1397395649.744 [NAL9602](INFO): Completed sending Logs/20140413T132323/Courier0004.lzma 2014-04-13T13:27:37.434Z,1397395657.434 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T13:27:37.434Z,1397395657.434 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 43.9 43.2 43.2 43.5 127.4 140.4 219.0 203.9 184 132 175 171 12 11 11 11 -122.3 -84.7 186.2 1 -27.7 144.3 187.7 1 12 -52 178 2 -53 7 178 2 -2.39 -0.88 249.3 0 0.005 35.0 1489 68 2014-04-13T13:27:48.541Z,1397395668.541 [NAL9602](INFO): SBD MO Status=2, MOMSN=25359, MT Status=2, MTMSN=0 2014-04-13T13:27:48.541Z,1397395668.541 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2014-04-13T13:28:10.787Z,1397395690.787 [NAL9602](INFO): SBD MO Status=1, MOMSN=25359, MT Status=0, MTMSN=0 2014-04-13T13:28:10.837Z,1397395690.837 [NAL9602](INFO): Sent 142 bytes from file Logs/20140413T130214/Express0017.lzma 2014-04-13T13:28:10.838Z,1397395690.838 [NAL9602](INFO): Packets left to send: 0 2014-04-13T13:28:10.839Z,1397395690.839 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T130214/Express0017.lzma.parts/0000.sbd 2014-04-13T13:28:10.839Z,1397395690.839 [NAL9602](INFO): Completed sending Logs/20140413T130214/Express0017.lzma 2014-04-13T13:28:30.926Z,1397395710.926 [DVL_micro](ERROR): No DVL communication! Re-initializing 2014-04-13T13:28:30.926Z,1397395710.926 [DVL_micro] Communications Fault, FailCount= 1 2014-04-13T13:28:30.926Z,1397395710.926 [DVL_micro](ERROR): Communications Fault 2014-04-13T13:28:30.953Z,1397395710.953 [CBIT](ERROR): Communications Fault in component: DVL_micro 2014-04-13T13:28:31.335Z,1397395711.335 [DVL_micro](INFO): uninitialize:Powering down 2014-04-13T13:28:31.743Z,1397395711.743 [DVL_micro](FAULT): LCB fault: Software Overcurrent. 2014-04-13T13:28:31.743Z,1397395711.743 [DVL_micro] Hardware Fault, FailCount= 1 2014-04-13T13:28:31.743Z,1397395711.743 [DVL_micro](ERROR): Hardware Fault 2014-04-13T13:28:32.228Z,1397395712.228 [CBIT](INFO): Clearing failed state for component DVL_micro 2014-04-13T13:28:32.228Z,1397395712.228 [DVL_micro] No Fault, FailCount= 1 2014-04-13T13:28:32.606Z,1397395712.606 [DVL_micro](INFO): Initializing 2014-04-13T13:28:39.994Z,1397395719.994 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 4 of 46 2014-04-13T13:28:39.995Z,1397395719.995 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 146.7 48.1 41.7 -438.2 -313.3 -276.3 -427.0 -343 -179 -274 -332 10 13 14 11 -216.1 151.7 -392.3 1 139.5 132.1 -432.1 1 -92 204 -304 2 222 24 -304 2 -8.25 -6.56 252.1 41.6 15.0 0.005 35.0 1489 94 2014-04-13T13:28:43.826Z,1397395723.826 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T13:28:43.826Z,1397395723.826 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 41.2 43.2 46.7 44.6 -7.2 -156.7 -153.4 -26.7 13 -113 -230 -65 10 11 13 12 195.1 -173.5 -92.8 1 -224.2 -148.8 -65.9 1 324 -64 -106 2 -153 -293 -106 2 0.2853.6 41.2 15.0 0.005 35.0 1489 88 2014-04-13T13:29:10.842Z,1397395750.842 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:72 Calculated:91 2014-04-13T13:29:10.842Z,1397395750.842 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 43.0 43.0 44.0 43.5 74.3 113.4 226.3 195.2 93 144 209 210 11 11 12 11 -202.9 -109.2 164.2 1 .7 147.0 1 -154 -88 176 2 -8 177 176 2 1.48 -3.95 243.1 43.0 15.0 0.005 35.0 1489 72 2014-04-13T13:29:18.502Z,1397395758.502 [NAL9602](INFO): SBD MO Status=2, MOMSN=25360, MT Status=2, MTMSN=0 2014-04-13T13:29:18.503Z,1397395758.503 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2014-04-13T13:29:39.588Z,1397395779.588 [NAL9602](INFO): SBD MO Status=1, MOMSN=25360, MT Status=0, MTMSN=0 2014-04-13T13:29:39.639Z,1397395779.639 [NAL9602](INFO): Sent 332 bytes from file Logs/20140413T132323/Express0001.lzma 2014-04-13T13:29:39.639Z,1397395779.639 [NAL9602](INFO): Packets left to send: 1 2014-04-13T13:29:39.641Z,1397395779.641 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Express0001.lzma.parts/0001.sbd 2014-04-13T13:29:51.481Z,1397395791.481 [NAL9602](INFO): SBD MO Status=1, MOMSN=25361, MT Status=0, MTMSN=0 2014-04-13T13:29:51.530Z,1397395791.530 [NAL9602](INFO): Sent 295 bytes from file Logs/20140413T132323/Express0001.lzma 2014-04-13T13:29:51.530Z,1397395791.530 [NAL9602](INFO): Packets left to send: 0 2014-04-13T13:29:51.531Z,1397395791.531 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Express0001.lzma.parts/0000.sbd 2014-04-13T13:29:51.531Z,1397395791.531 [NAL9602](INFO): Completed sending Logs/20140413T132323/Express0001.lzma 2014-04-13T13:29:57.011Z,1397395797.011 [DVL_micro](ERROR): No DVL communication! Re-initializing 2014-04-13T13:29:57.011Z,1397395797.011 [DVL_micro] Communications Fault, FailCount= 1 2014-04-13T13:29:57.011Z,1397395797.011 [DVL_micro](ERROR): Communications Fault 2014-04-13T13:29:57.039Z,1397395797.039 [CBIT](ERROR): Communications Fault in component: DVL_micro 2014-04-13T13:29:57.417Z,1397395797.417 [DVL_micro](INFO): uninitialize:Powering down 2014-04-13T13:29:57.888Z,1397395797.888 [DVL_micro](FAULT): LCB fault: Software Overcurrent. 2014-04-13T13:29:57.889Z,1397395797.889 [DVL_micro] Hardware Fault, FailCount= 1 2014-04-13T13:29:57.889Z,1397395797.889 [DVL_micro](ERROR): Hardware Fault 2014-04-13T13:29:58.340Z,1397395798.340 [CBIT](INFO): Clearing failed state for component DVL_micro 2014-04-13T13:29:58.340Z,1397395798.340 [DVL_micro] No Fault, FailCount= 1 2014-04-13T13:29:58.699Z,1397395798.699 [DVL_micro](INFO): Initializing 2014-04-13T13:29:58.702Z,1397395798.702 [NAL9602](INFO): SBD MO Status=1, MOMSN=25362, MT Status=0, MTMSN=0 2014-04-13T13:29:58.749Z,1397395798.749 [NAL9602](INFO): Sent 185 bytes from file Logs/20140413T132323/Express0005.lzma 2014-04-13T13:29:58.749Z,1397395798.749 [NAL9602](INFO): Packets left to send: 0 2014-04-13T13:29:58.750Z,1397395798.750 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Express0005.lzma.parts/0000.sbd 2014-04-13T13:29:58.751Z,1397395798.751 [NAL9602](INFO): Completed sending Logs/20140413T132323/Express0005.lzma 2014-04-13T13:30:06.977Z,1397395806.977 [NAL9602](INFO): SBD MO Status=0, MOMSN=25363, MT Status=0, MTMSN=0 2014-04-13T13:30:07.058Z,1397395807.058 [Default:Iridium:Read_Iridium] Stopped 2014-04-13T13:30:07.059Z,1397395807.059 [Default:Iridium](INFO): Completed Default:Iridium 2014-04-13T13:30:07.059Z,1397395807.059 [Default:Iridium] Stopped 2014-04-13T13:30:07.059Z,1397395807.059 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2014-04-13T13:30:07.059Z,1397395807.059 [Default:Iridium:A.SetSpeed] Stopped 2014-04-13T13:30:07.059Z,1397395807.059 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2014-04-13T13:30:07.059Z,1397395807.059 [Default:WaitAtTheSurface] Running Loop=1 2014-04-13T13:30:07.060Z,1397395807.060 [Default:WaitAtTheSurface](INFO): Aggregate::initialize Default:WaitAtTheSurface 2014-04-13T13:30:07.060Z,1397395807.060 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Running Loop=1 2014-04-13T13:30:07.060Z,1397395807.060 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Initialize. 2014-04-13T13:30:07.060Z,1397395807.060 [Default:WaitAtTheSurface:B.GoToSurface] Running Loop=1 2014-04-13T13:30:07.060Z,1397395807.060 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T13:30:07.522Z,1397395807.522 [Default:WaitAtTheSurface:B.GoToSurface] Running Loop=1 2014-04-13T13:30:07.528Z,1397395807.528 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Running Loop=1 2014-04-13T13:30:07.535Z,1397395807.535 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2014-04-13T13:30:07.536Z,1397395807.536 [Default:CallIridium:B] Stopped 2014-04-13T13:30:07.536Z,1397395807.536 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2014-04-13T13:30:07.536Z,1397395807.536 [Default:CallIridium](INFO): Completed Default:CallIridium 2014-04-13T13:30:07.536Z,1397395807.536 [Default:CallIridium] Stopped 2014-04-13T13:30:07.536Z,1397395807.536 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2014-04-13T13:30:17.661Z,1397395817.661 [NAL9602](INFO): Powering down 2014-04-13T13:35:07.704Z,1397396107.704 [Default:CallIridium] Running Loop=1 2014-04-13T13:35:07.704Z,1397396107.704 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2014-04-13T13:35:07.704Z,1397396107.704 [Default:CallIridium:A] Running Loop=1 2014-04-13T13:35:07.705Z,1397396107.705 [Default:CallIridium:A] Stopped 2014-04-13T13:35:07.705Z,1397396107.705 [Default:CallIridium:B] Running Loop=1 2014-04-13T13:35:07.705Z,1397396107.705 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2014-04-13T13:35:12.720Z,1397396112.720 [Default:Iridium] Running Loop=1 2014-04-13T13:35:12.720Z,1397396112.720 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2014-04-13T13:35:12.720Z,1397396112.720 [Default:Iridium:A.SetSpeed] Running Loop=1 2014-04-13T13:35:12.720Z,1397396112.720 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2014-04-13T13:35:12.720Z,1397396112.720 [Default:Iridium:B.GoToSurface] Running Loop=1 2014-04-13T13:35:12.720Z,1397396112.720 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T13:35:12.721Z,1397396112.721 [Default:Iridium:B.GoToSurface] Stopped 2014-04-13T13:35:12.721Z,1397396112.721 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T13:35:12.721Z,1397396112.721 [Default:Iridium:Read_Iridium] Running Loop=1 2014-04-13T13:35:12.722Z,1397396112.722 [Default:GPS] Running Loop=1 2014-04-13T13:35:12.722Z,1397396112.722 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2014-04-13T13:35:12.722Z,1397396112.722 [Default:GPS:A.SetSpeed] Running Loop=1 2014-04-13T13:35:12.722Z,1397396112.722 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2014-04-13T13:35:12.722Z,1397396112.722 [Default:GPS:B.GoToSurface] Running Loop=1 2014-04-13T13:35:12.722Z,1397396112.722 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T13:35:12.723Z,1397396112.723 [Default:GPS:B.GoToSurface] Stopped 2014-04-13T13:35:12.723Z,1397396112.723 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T13:35:12.723Z,1397396112.723 [Default:GPS:Read_GPS] Running Loop=1 2014-04-13T13:35:14.346Z,1397396114.346 [NAL9602](INFO): Powering up 2014-04-13T13:35:25.315Z,1397396125.315 [NAL9602](INFO): NAL9602 initialized 2014-04-13T13:35:51.503Z,1397396151.503 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:126 Calculated:118 2014-04-13T13:35:51.503Z,1397396151.503 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 0 1 41.2 42.1 0 43.9 410.7 329.3 0 4 299 343 476 10 11 26 12 3.7 -213.5 441.4 1 -195.8 146.7 425.0 1 90 -236 412 2 -253 0 412 2 2.91 -9.18 248.8 41.2 15.0 0.005 35.0 1489 126 2014-04-13T13:35:52.749Z,1397396152.749 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 42 of 46 2014-04-13T13:35:52.749Z,1397396152.749 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 42.8 46.2 45.1 40.8 -97.0 364.5 -222.8 -27 -202 -337 -191 11 13 12 -194.5 -321.3 -219.9 1 413 -14 -204 2 -168 -378 -204 2 -10.31 -3.33 248.1 40.8 15.0 0.005 35.0 1489 98 2014-04-13T13:35:56.683Z,1397396156.683 [NAL9602](INFO): SBD MO Status=2, MOMSN=25364, MT Status=2, MTMSN=0 2014-04-13T13:35:56.684Z,1397396156.684 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2014-04-13T13:35:58.040Z,1397396158.040 [NAL9602](IMPORTANT): GPS fix at: 1397396119.00 2014-04-13T13:35:58.053Z,1397396158.053 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T13:35:58.058Z,1397396158.058 [Default:GPS:Read_GPS] Stopped 2014-04-13T13:35:58.058Z,1397396158.058 [Default:GPS:D] Running Loop=1 2014-04-13T13:35:58.522Z,1397396158.522 [Default:GPS:D] Stopped 2014-04-13T13:35:58.523Z,1397396158.523 [Default:GPS](INFO): Completed Default:GPS 2014-04-13T13:35:58.523Z,1397396158.523 [Default:GPS] Stopped 2014-04-13T13:35:58.523Z,1397396158.523 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2014-04-13T13:35:58.523Z,1397396158.523 [Default:GPS:A.SetSpeed] Stopped 2014-04-13T13:35:58.523Z,1397396158.523 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2014-04-13T13:36:22.939Z,1397396182.939 [NAL9602](INFO): SBD MO Status=2, MOMSN=25364, MT Status=2, MTMSN=0 2014-04-13T13:36:22.939Z,1397396182.939 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2014-04-13T13:36:49.164Z,1397396209.164 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=25364, MT Status=1, MTMSN=1756 2014-04-13T13:36:49.237Z,1397396209.237 [NAL9602](INFO): Sent 75 bytes from file Logs/20140413T132323/Courier0008.lzma 2014-04-13T13:36:49.237Z,1397396209.237 [NAL9602](INFO): Packets left to send: 0 2014-04-13T13:36:49.239Z,1397396209.239 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Courier0008.lzma.parts/0000.sbd 2014-04-13T13:36:49.239Z,1397396209.239 [NAL9602](INFO): Completed sending Logs/20140413T132323/Courier0008.lzma 2014-04-13T13:36:50.175Z,1397396210.175 [NAL9602](INFO): Received command:sched asap "load Transport/keepstation.xml;set keepstation.Latitude 33.584243 degree;set keepstation.Longitude -117.917365 degree;set keepstation.NeedCommsTime 15 minute;set keepstation.MaxDuration 6 hour" 3s891 1 2 2014-04-13T13:36:50.187Z,1397396210.187 [CommandLine](IMPORTANT): got command schedule asap "load Transport/keepstation.xml;set keepstation.Latitude 33.584243 degree;set keepstation.Longitude -117.917365 degree;set keepstation.NeedCommsTime 15 minute;set keepstation.MaxDuration 6 hour" 3s891 1 2.000000 2014-04-13T13:36:50.188Z,1397396210.188 [CommandLine](IMPORTANT): Scheduling command #1 of 2 with id=3s891 2014-04-13T13:36:50.189Z,1397396210.189 [CommandLine](IMPORTANT): Scheduled #1 (#1 of 2 with id='3s891'): "load Transport/keepstation.xml;set keepstation.Latitude 33.584243 degree;set keepstation.Longitude -117.917365 degree;set keepstation.NeedCommsTime 15 minute;set keepstation.MaxDuration 6 hour" ASAP 2014-04-13T13:36:59.731Z,1397396219.731 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T13:36:59.731Z,1397396219.731 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 39.9 43.4 47.3 43.1 -554.7 -490.6 -294.9 -363.4 -488 -439 -282 -354 10 11 13 11 -346.7 -169.8 -459.4 1 -181.5 270.5 -504.0 113 -421 2 -119 272 -421 2 -0.65 -8.57 271.3 39.9 15.0 0.005 35.0 1489 93 2014-04-13T13:37:15.852Z,1397396235.852 [NAL9602](INFO): SBD MO Status=2, MOMSN=25365, MT Status=2, MTMSN=0 2014-04-13T13:37:15.852Z,1397396235.852 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2014-04-13T13:37:36.608Z,1397396256.608 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=25365, MT Status=1, MTMSN=1757 2014-04-13T13:37:36.667Z,1397396256.667 [NAL9602](INFO): Sent 285 bytes from file Logs/20140413T132323/Express0009.lzma 2014-04-13T13:37:36.667Z,1397396256.667 [NAL9602](INFO): Packets left to send: 0 2014-04-13T13:37:36.669Z,1397396256.669 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Express0009.lzma.parts/0000.sbd 2014-04-13T13:37:36.669Z,1397396256.669 [NAL9602](INFO): Completed sending Logs/20140413T132323/Express0009.lzma 2014-04-13T13:37:37.424Z,1397396257.424 [NAL9602](INFO): Received command:sched asap "set keepstation.Speed 1 meter_per_second;run " 3s891 2 2 2014-04-13T13:37:37.470Z,1397396257.470 [CommandLine](IMPORTANT): got command schedule asap "set keepstation.Speed 1 meter_per_second;run " 3s891 2 2.000000 2014-04-13T13:37:37.471Z,1397396257.471 [CommandLine](IMPORTANT): Scheduling command #2 of 2 with id=3s891 2014-04-13T13:37:37.472Z,1397396257.472 [CommandLine](IMPORTANT): Scheduled #2 (#2 of 2 with id='3s891'): "set keepstation.Speed 1 meter_per_second;run " ASAP 2014-04-13T13:37:37.498Z,1397396257.498 [CommandLine](IMPORTANT): got command load ./Missions/Transport/keepstation.xml 2014-04-13T13:37:37.498Z,1397396257.498 [MissionManager](INFO): Loading Mission: ./Missions/Transport/keepstation.xml 2014-04-13T13:37:37.629Z,1397396257.629 [MissionManager](INFO): DefineArg keepstation.Depth = 30.000000 m 2014-04-13T13:37:37.631Z,1397396257.631 [MissionManager](INFO): DefineArg keepstation.FastDiveDepth = 10.000000 m 2014-04-13T13:37:37.634Z,1397396257.634 [MissionManager](INFO): DefineArg keepstation.Latitude = nan arcdeg 2014-04-13T13:37:37.638Z,1397396257.638 [MissionManager](INFO): DefineArg keepstation.Longitude = nan arcdeg 2014-04-13T13:37:37.641Z,1397396257.641 [MissionManager](INFO): DefineArg keepstation.Radius = 200.000000 m 2014-04-13T13:37:37.643Z,1397396257.643 [MissionManager](INFO): DefineArg keepstation.MinAltitude = 7.000000 m 2014-04-13T13:37:37.646Z,1397396257.646 [MissionManager](INFO): DefineArg keepstation.MaxDepth = 45.000000 m 2014-04-13T13:37:37.650Z,1397396257.650 [MissionManager](INFO): DefineArg keepstation.MinOffshore = 2000.000000 m 2014-04-13T13:37:37.653Z,1397396257.653 [MissionManager](INFO): DefineArg keepstation.NeedCommsTime = 45.000000 min 2014-04-13T13:37:37.656Z,1397396257.656 [MissionManager](INFO): DefineArg keepstation.MaxDuration = 24.000000 h 2014-04-13T13:37:37.660Z,1397396257.660 [MissionManager](INFO): DefineArg keepstation.DepthDeadband = 4.000000 m 2014-04-13T13:37:37.684Z,1397396257.684 [MissionManager](INFO): DefineArg keepstation.MassDefault = 0.000000 n/a 2014-04-13T13:37:37.695Z,1397396257.695 [MissionManager](INFO): DefineArg keepstation.BuoyancyNeutral = 0.000300 n/a 2014-04-13T13:37:37.698Z,1397396257.698 [MissionManager](INFO): DefineArg keepstation.Speed = 0.750000 m/s 2014-04-13T13:37:37.701Z,1397396257.701 [MissionManager](INFO): DefineArg keepstation.ApproachDepth = 15.000000 m 2014-04-13T13:37:37.704Z,1397396257.704 [keepstation:AltEnvWrapper:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope. 2014-04-13T13:37:37.719Z,1397396257.719 [keepstation:B.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2014-04-13T13:37:37.729Z,1397396257.729 [keepstation:SURFACECOMMS:A.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-13T13:37:37.742Z,1397396257.742 [keepstation:OffshoreWrapper:A.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope. 2014-04-13T13:37:37.753Z,1397396257.753 [keepstation:TransitToStation:A.Buoyancy](DEBUG): Construct Buoyancy. 2014-04-13T13:37:37.755Z,1397396257.755 [keepstation:TransitToStation:B.Pitch](DEBUG): Construct. 2014-04-13T13:37:37.761Z,1397396257.761 [keepstation:TransitToStation:C.Pitch](DEBUG): Construct. 2014-04-13T13:37:37.783Z,1397396257.783 [keepstation:TransitToStation:D.SetSpeed](DEBUG): Construct. 2014-04-13T13:37:37.786Z,1397396257.786 [keepstation:TransitToStation:Wpt1.Waypoint](DEBUG): Construct Waypoint. 2014-04-13T13:37:37.818Z,1397396257.818 [keepstation:KeepStation:B.Pitch](DEBUG): Construct. 2014-04-13T13:37:37.823Z,1397396257.823 [keepstation:KeepStation:C.SetSpeed](DEBUG): Construct. 2014-04-13T13:37:37.827Z,1397396257.827 [keepstation:KeepStation:D.KeepStation](DEBUG): Construct KeepStation. 2014-04-13T13:37:37.832Z,1397396257.832 [keepstation:KeepStation:E.Wait](DEBUG): Construct Wait. 2014-04-13T13:37:37.842Z,1397396257.842 [MissionManager](DEBUG): Vehicle transits to desired waypoint (or stays put if none is commanded) and stays within the specified radius. Depth held during drift mode 30.0 Depth to which vehicle should dive using propeller during drift mode 10.0 Latitude of waypoint to hold. If NaN, hold the latitude at start of mission. NaN Longitude of waypoint to hold. If NaN, hold the longitude at start of mission. NaN Radius of circle around waypoint to hold. 200 Minimum height above the sea floor. 7 Maximum allowable depth during the mission. 45 Minimum distance from the shoreline to maintain 2000 How often to surface for commumications 45 How long the mission can last 24 How much vertical drift from the specified depth is allowed in drift mode 4.0 Static setting for mass during the transit portion of the mission. Buoyancy bladder position while driving to station. Defaults to buoyancyNeutral setting in the Config/Control.cfg file. Vehicle transit speed. 0.75 Depth for initial approach to station. 15.0 0 Safety behavior that keeps vehicle off sea floor 0 Safety behavior that keeps vehicle away from the shore 1 2014-04-13T13:37:37.843Z,1397396257.843 [CommandLine](IMPORTANT): Loaded ./Missions/Transport/keepstation.xml 2014-04-13T13:37:43.816Z,1397396263.816 [CommandLine](IMPORTANT): got command set keepstation.Latitude 33.584244 degree 2014-04-13T13:37:43.827Z,1397396263.827 [CommandLine](IMPORTANT): got command set keepstation.Longitude -117.917366 degree 2014-04-13T13:37:43.828Z,1397396263.828 [CommandLine](IMPORTANT): got command set keepstation.NeedCommsTime 15.000000 minute 2014-04-13T13:37:43.829Z,1397396263.829 [CommandLine](IMPORTANT): got command set keepstation.MaxDuration 6.000000 hour 2014-04-13T13:37:45.189Z,1397396265.189 [CommandLine](IMPORTANT): got command set keepstation.Speed 1.000000 meter_per_second 2014-04-13T13:37:45.189Z,1397396265.189 [CommandLine](IMPORTANT): got command run 2014-04-13T13:37:45.200Z,1397396265.200 [CommandLine](IMPORTANT): Running 2014-04-13T13:37:45.645Z,1397396265.645 [Default] Stopped 2014-04-13T13:37:45.645Z,1397396265.645 [Default](INFO): Aggregate::uninitialize Default 2014-04-13T13:37:45.645Z,1397396265.645 [Default:Iridium] Stopped 2014-04-13T13:37:45.645Z,1397396265.645 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2014-04-13T13:37:45.645Z,1397396265.645 [Default:Iridium:A.SetSpeed] Stopped 2014-04-13T13:37:45.645Z,1397396265.645 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2014-04-13T13:37:45.646Z,1397396265.646 [Default:Iridium:Read_Iridium] Stopped 2014-04-13T13:37:45.646Z,1397396265.646 [Default:CallIridium] Stopped 2014-04-13T13:37:45.646Z,1397396265.646 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2014-04-13T13:37:45.646Z,1397396265.646 [Default:CallIridium:B] Stopped 2014-04-13T13:37:45.646Z,1397396265.646 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2014-04-13T13:37:45.646Z,1397396265.646 [Default:WaitAtTheSurface] Stopped 2014-04-13T13:37:45.646Z,1397396265.646 [Default:WaitAtTheSurface](INFO): Aggregate::uninitialize Default:WaitAtTheSurface 2014-04-13T13:37:45.646Z,1397396265.646 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Stopped 2014-04-13T13:37:45.646Z,1397396265.646 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Uninitialize. 2014-04-13T13:37:45.646Z,1397396265.646 [Default:WaitAtTheSurface:B.GoToSurface] Stopped 2014-04-13T13:37:45.646Z,1397396265.646 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T13:37:45.647Z,1397396265.647 [MissionManager](IMPORTANT): Started mission keepstation 2014-04-13T13:37:45.647Z,1397396265.647 [keepstation] Running Loop=1 2014-04-13T13:37:45.647Z,1397396265.647 [keepstation](INFO): Aggregate::initialize keepstation 2014-04-13T13:37:45.647Z,1397396265.647 [keepstation:B.DepthEnvelope] Running Loop=1 2014-04-13T13:37:45.647Z,1397396265.647 [keepstation:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent. 2014-04-13T13:37:45.647Z,1397396265.647 [keepstation:SURFACECOMMS] Running Loop=1 2014-04-13T13:37:45.648Z,1397396265.648 [keepstation:SURFACECOMMS](INFO): Aggregate::initialize keepstation:SURFACECOMMS 2014-04-13T13:37:45.648Z,1397396265.648 [keepstation:SURFACECOMMS:A.GoToSurface] Running Loop=1 2014-04-13T13:37:45.648Z,1397396265.648 [keepstation:SURFACECOMMS:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T13:37:45.649Z,1397396265.649 [keepstation:OffshoreWrapper] Running Loop=1 2014-04-13T13:37:45.649Z,1397396265.649 [keepstation:OffshoreWrapper](INFO): Aggregate::initialize keepstation:OffshoreWrapper 2014-04-13T13:37:45.649Z,1397396265.649 [keepstation:OffshoreWrapper:A.OffshoreEnvelope] Running Loop=1 2014-04-13T13:37:45.650Z,1397396265.650 [keepstation:OffshoreWrapper:A.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent. 2014-04-13T13:37:45.650Z,1397396265.650 [keepstation:OffshoreWrapper:A.OffshoreEnvelope] Running Loop=1 2014-04-13T13:37:45.660Z,1397396265.660 [keepstation:SURFACECOMMS:B] Running Loop=1 2014-04-13T13:37:45.661Z,1397396265.661 [keepstation:SURFACECOMMS:B](INFO): Aggregate::initialize keepstation:SURFACECOMMS:B 2014-04-13T13:37:45.661Z,1397396265.661 [keepstation:SURFACECOMMS:B:A] Running Loop=1 2014-04-13T13:37:45.661Z,1397396265.661 [keepstation:B.DepthEnvelope] Running Loop=1 2014-04-13T13:37:45.682Z,1397396265.682 [keepstation:AltEnvWrapper] Running Loop=1 2014-04-13T13:37:45.683Z,1397396265.683 [keepstation:AltEnvWrapper](INFO): Aggregate::initialize keepstation:AltEnvWrapper 2014-04-13T13:37:45.683Z,1397396265.683 [keepstation:AltEnvWrapper:A.AltitudeEnvelope] Running Loop=1 2014-04-13T13:37:45.683Z,1397396265.683 [keepstation:AltEnvWrapper:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent. 2014-04-13T13:37:45.683Z,1397396265.683 [keepstation:AltEnvWrapper:A.AltitudeEnvelope] Running Loop=1 2014-04-13T13:37:46.114Z,1397396266.114 [keepstation:SURFACECOMMS:B:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2014-04-13T13:37:57.442Z,1397396277.442 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T13:37:57.443Z,1397396277.443 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 41.1 46.0 46.4 40.7 35.9 -27.3 75.3 108.3 68 1 -7 15 10 13 13 10 -52.6 -181.0 51.8 1 -125.8 130.2 73.7 1 100 -18 20 2 -61 -81 20 2 -98 243.4 40.7 15.0 0.005 35.0 1489 96 2014-04-13T13:38:00.111Z,1397396280.111 [NAL9602](INFO): SBD MO Status=2, MOMSN=25366, MT Status=2, MTMSN=0 2014-04-13T13:38:00.111Z,1397396280.111 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2014-04-13T13:38:01.402Z,1397396281.402 [NAL9602](IMPORTANT): GPS fix at: 1397396243.00 2014-04-13T13:38:01.417Z,1397396281.417 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T13:38:01.420Z,1397396281.420 [keepstation:SURFACECOMMS:B:A] Stopped 2014-04-13T13:38:01.420Z,1397396281.420 [keepstation:SURFACECOMMS:B:B] Running Loop=1 2014-04-13T13:38:01.863Z,1397396281.863 [keepstation:SURFACECOMMS:B:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2014-04-13T13:38:20.606Z,1397396300.606 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:103 Calculated:102 2014-04-13T13:38:20.607Z,1397396300.607 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 40.5 41.6 45.8 44.0 -338.6 -390.7 -289.0 -232-317 -337 -260 10 11 13 12 -66.2 -211.0 -337.3 1 -186.4 108.3 -340.8 1 126 -76 -311 2 -114 -93 -311 2 -0.20 -4.69 250.1 40.5 15.0 0.005 35.0 1489 103 2014-04-13T13:38:31.589Z,1397396311.589 [NAL9602](INFO): SBD MO Status=1, MOMSN=25366, MT Status=0, MTMSN=0 2014-04-13T13:38:31.636Z,1397396311.636 [NAL9602](INFO): Sent 75 bytes from file Logs/20140413T132323/Courier0012.lzma 2014-04-13T13:38:31.636Z,1397396311.636 [NAL9602](INFO): Packets left to send: 0 2014-04-13T13:38:31.638Z,1397396311.638 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Courier0012.lzma.parts/0000.sbd 2014-04-13T13:38:31.638Z,1397396311.638 [NAL9602](INFO): Completed sending Logs/20140413T132323/Courier0012.lzma 2014-04-13T13:38:48.512Z,1397396328.512 [NAL9602](INFO): SBD MO Status=1, MOMSN=25367, MT Status=0, MTMSN=0 2014-04-13T13:38:48.566Z,1397396328.566 [NAL9602](INFO): Sent 332 bytes from file Logs/20140413T132323/Express0013.lzma 2014-04-13T13:38:48.566Z,1397396328.566 [NAL9602](INFO): Packets left to send: 1 2014-04-13T13:38:48.568Z,1397396328.568 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Express0013.lzma.parts/0001.sbd 2014-04-13T13:39:06.226Z,1397396346.226 [NAL9602](INFO): SBD MO Status=1, MOMSN=25368, MT Status=0, MTMSN=0 2014-04-13T13:39:06.286Z,1397396346.286 [NAL9602](INFO): Sent 254 bytes from file Logs/20140413T132323/Express0013.lzma 2014-04-13T13:39:06.286Z,1397396346.286 [NAL9602](INFO): Packets left to send: 0 2014-04-13T13:39:06.287Z,1397396346.287 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Express0013.lzma.parts/0000.sbd 2014-04-13T13:39:06.287Z,1397396346.287 [NAL9602](INFO): Completed sending Logs/20140413T132323/Express0013.lzma 2014-04-13T13:39:09.009Z,1397396349.009 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:80 Calculated:95 2014-04-13T13:39:09.009Z,1397396349.009 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 40.0 42.8 46.3 43.6 59.7 65.8 0.0 128 93 120 185 10 11 13 12 -186.3 -192.5 144.2 1 -189.2 208.6 115.0 1 10 -122 141 2 -123 -8 141 2 -0.02 -8.54 269.1 40.0 15.0 0.005 35.0 1489 80 2014-04-13T13:39:18.597Z,1397396358.597 [NAL9602](INFO): SBD MO Status=0, MOMSN=25369, MT Status=0, MTMSN=0 2014-04-13T13:39:33.907Z,1397396373.907 [NAL9602](INFO): SBD MO Status=1, MOMSN=25370, MT Status=0, MTMSN=0 2014-04-13T13:39:33.957Z,1397396373.957 [NAL9602](INFO): Sent 45 bytes from file Logs/20140413T132323/Courier0016.lzma 2014-04-13T13:39:33.957Z,1397396373.957 [NAL9602](INFO): Packets left to send: 0 2014-04-13T13:39:33.958Z,1397396373.958 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Courier0016.lzma.parts/0000.sbd 2014-04-13T13:39:33.959Z,1397396373.959 [NAL9602](INFO): Completed sending Logs/20140413T132323/Courier0016.lzma 2014-04-13T13:39:43.792Z,1397396383.792 [NAL9602](INFO): SBD MO Status=1, MOMSN=25371, MT Status=0, MTMSN=0 2014-04-13T13:39:43.840Z,1397396383.840 [NAL9602](INFO): Sent 62 bytes from file Logs/20140413T132323/Express0017.lzma 2014-04-13T13:39:43.840Z,1397396383.840 [NAL9602](INFO): Packets left to send: 0 2014-04-13T13:39:43.842Z,1397396383.842 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Express0017.lzma.parts/0000.sbd 2014-04-13T13:39:43.842Z,1397396383.842 [NAL9602](INFO): Completed sending Logs/20140413T132323/Express0017.lzma 2014-04-13T13:39:52.994Z,1397396392.994 [NAL9602](INFO): SBD MO Status=0, MOMSN=25372, MT Status=0, MTMSN=0 2014-04-13T13:39:53.095Z,1397396393.095 [keepstation:SURFACECOMMS:B:B] Stopped 2014-04-13T13:39:53.096Z,1397396393.096 [keepstation:SURFACECOMMS:B:C] Running Loop=1 2014-04-13T13:39:53.510Z,1397396393.510 [keepstation:SURFACECOMMS:B:C](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2014-04-13T13:39:55.660Z,1397396395.660 [NAL9602](IMPORTANT): GPS fix at: 1397396357.00 2014-04-13T13:39:55.712Z,1397396395.712 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T13:39:55.717Z,1397396395.717 [keepstation:SURFACECOMMS:B:C] Stopped 2014-04-13T13:39:55.718Z,1397396395.718 [keepstation:SURFACECOMMS:B](INFO): Completed keepstation:SURFACECOMMS:B 2014-04-13T13:39:55.718Z,1397396395.718 [keepstation:SURFACECOMMS:B] Stopped 2014-04-13T13:39:55.718Z,1397396395.718 [keepstation:SURFACECOMMS:B](INFO): Aggregate::uninitialize keepstation:SURFACECOMMS:B 2014-04-13T13:39:55.719Z,1397396395.719 [keepstation:SURFACECOMMS](INFO): Completed keepstation:SURFACECOMMS 2014-04-13T13:39:55.719Z,1397396395.719 [keepstation:SURFACECOMMS] Stopped 2014-04-13T13:39:55.719Z,1397396395.719 [keepstation:SURFACECOMMS](INFO): Aggregate::uninitialize keepstation:SURFACECOMMS 2014-04-13T13:39:55.719Z,1397396395.719 [keepstation:SURFACECOMMS:A.GoToSurface] Stopped 2014-04-13T13:39:55.719Z,1397396395.719 [keepstation:SURFACECOMMS:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T13:39:55.720Z,1397396395.720 [keepstation:TransitToStation] Running Loop=1 2014-04-13T13:39:55.720Z,1397396395.720 [keepstation:TransitToStation](INFO): Aggregate::initialize keepstation:TransitToStation 2014-04-13T13:39:55.720Z,1397396395.720 [keepstation:TransitToStation:A.Buoyancy] Running Loop=1 2014-04-13T13:39:55.720Z,1397396395.720 [keepstation:TransitToStation:A.Buoyancy](DEBUG): Initialize Buoyancy Component. 2014-04-13T13:39:55.720Z,1397396395.720 [keepstation:TransitToStation:B.Pitch] Running Loop=1 2014-04-13T13:39:55.720Z,1397396395.720 [keepstation:TransitToStation:B.Pitch](DEBUG): Initialize. 2014-04-13T13:39:55.720Z,1397396395.720 [keepstation:TransitToStation:C.Pitch] Running Loop=1 2014-04-13T13:39:55.720Z,1397396395.720 [keepstation:TransitToStation:C.Pitch](DEBUG): Initialize. 2014-04-13T13:39:55.721Z,1397396395.721 [keepstation:TransitToStation:D.SetSpeed] Running Loop=1 2014-04-13T13:39:55.721Z,1397396395.721 [keepstation:TransitToStation:D.SetSpeed](DEBUG): Initialize. 2014-04-13T13:39:55.721Z,1397396395.721 [keepstation:TransitToStation:Wpt1.Waypoint] Running Loop=1 2014-04-13T13:39:55.721Z,1397396395.721 [keepstation:TransitToStation:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent. 2014-04-13T13:39:56.212Z,1397396396.212 [keepstation:TransitToStation:D.SetSpeed] Running Loop=1 2014-04-13T13:39:56.217Z,1397396396.217 [keepstation:TransitToStation:C.Pitch] Running Loop=1 2014-04-13T13:39:56.222Z,1397396396.222 [keepstation:TransitToStation:B.Pitch] Running Loop=1 2014-04-13T13:39:56.228Z,1397396396.228 [keepstation:TransitToStation:A.Buoyancy] Running Loop=1 2014-04-13T13:40:02.703Z,1397396402.703 [NAL9602](INFO): Powering down 2014-04-13T13:40:14.812Z,1397396414.812 [Radio_Freewave](INFO): Powering down 2014-04-13T13:40:48.757Z,1397396448.757 [Radio_Freewave](INFO): Powering up 2014-04-13T13:40:49.947Z,1397396449.947 [Radio_Freewave](IMPORTANT): Starting PPPD with command:/sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0 2014-04-13T13:42:02.050Z,1397396522.050 [Radio_Freewave](INFO): Powering down 2014-04-13T13:42:06.144Z,1397396526.144 [Radio_Freewave](INFO): Powering up 2014-04-13T13:42:07.409Z,1397396527.409 [Radio_Freewave](IMPORTANT): Starting PPPD with command:/sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0 2014-04-13T13:44:38.853Z,1397396678.853 [Radio_Freewave](INFO): Powering down 2014-04-13T13:54:55.727Z,1397397295.727 [keepstation:NeedComms] Running Loop=1 2014-04-13T13:54:55.727Z,1397397295.727 [keepstation:NeedComms](INFO): Aggregate::initialize keepstation:NeedComms 2014-04-13T13:54:55.727Z,1397397295.727 [keepstation:NeedComms:A] Running Loop=1 2014-04-13T13:54:55.728Z,1397397295.728 [keepstation:NeedComms:A](INFO): Aggregate::initialize keepstation:NeedComms:A 2014-04-13T13:54:56.199Z,1397397296.199 [keepstation:SURFACECOMMS] Running Loop=1 2014-04-13T13:54:56.199Z,1397397296.199 [keepstation:SURFACECOMMS](INFO): Aggregate::initialize keepstation:SURFACECOMMS 2014-04-13T13:54:56.199Z,1397397296.199 [keepstation:SURFACECOMMS:A.GoToSurface] Running Loop=1 2014-04-13T13:54:56.199Z,1397397296.199 [keepstation:SURFACECOMMS:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T13:58:18.330Z,1397397498.330 [Radio_Freewave](INFO): Powering up 2014-04-13T13:58:18.414Z,1397397498.414 [keepstation:SURFACECOMMS:B] Running Loop=1 2014-04-13T13:58:18.414Z,1397397498.414 [keepstation:SURFACECOMMS:B](INFO): Aggregate::initialize keepstation:SURFACECOMMS:B 2014-04-13T13:58:18.414Z,1397397498.414 [keepstation:SURFACECOMMS:B:A] Running Loop=1 2014-04-13T13:58:19.396Z,1397397499.396 [NAL9602](INFO): Powering up 2014-04-13T13:58:19.417Z,1397397499.417 [Radio_Freewave](IMPORTANT): Starting PPPD with command:/sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0 2014-04-13T13:58:30.174Z,1397397510.174 [NAL9602](INFO): NAL9602 initialized 2014-04-13T13:58:46.060Z,1397397526.060 [NAL9602](INFO): SBD MO Status=0, MOMSN=25373, MT Status=0, MTMSN=0 2014-04-13T13:58:46.060Z,1397397526.060 [NAL9602](INFO): No messages in MT queue 2014-04-13T13:58:47.361Z,1397397527.361 [NAL9602](IMPORTANT): GPS fix at: 1397397489.00 2014-04-13T13:58:47.395Z,1397397527.395 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T13:58:47.395Z,1397397527.395 [DeadReckonUsingMultipleVelocitySources](DEBUG): horizontalPathLengthSinceLastFix_ = 751.053, recording fix residuals... 2014-04-13T13:58:47.405Z,1397397527.405 [keepstation:SURFACECOMMS:B:A] Stopped 2014-04-13T13:58:47.405Z,1397397527.405 [keepstation:SURFACECOMMS:B:B] Running Loop=1 2014-04-13T13:58:58.221Z,1397397538.221 [NAL9602](INFO): SBD MO Status=1, MOMSN=25374, MT Status=0, MTMSN=0 2014-04-13T13:58:58.274Z,1397397538.274 [NAL9602](INFO): Sent 74 bytes from file Logs/20140413T132323/Courier0020.lzma 2014-04-13T13:58:58.274Z,1397397538.274 [NAL9602](INFO): Packets left to send: 0 2014-04-13T13:58:58.276Z,1397397538.276 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Courier0020.lzma.parts/0000.sbd 2014-04-13T13:58:58.276Z,1397397538.276 [NAL9602](INFO): Completed sending Logs/20140413T132323/Courier0020.lzma 2014-04-13T13:59:10.722Z,1397397550.722 [NAL9602](INFO): SBD MO Status=1, MOMSN=25375, MT Status=0, MTMSN=0 2014-04-13T13:59:10.781Z,1397397550.781 [NAL9602](INFO): Sent 332 bytes from file Logs/20140413T132323/Express0021.lzma 2014-04-13T13:59:10.781Z,1397397550.781 [NAL9602](INFO): Packets left to send: 1 2014-04-13T13:59:10.783Z,1397397550.783 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Express0021.lzma.parts/0001.sbd 2014-04-13T13:59:24.108Z,1397397564.108 [NAL9602](INFO): SBD MO Status=1, MOMSN=25376, MT Status=0, MTMSN=0 2014-04-13T13:59:24.158Z,1397397564.158 [NAL9602](INFO): Sent 216 bytes from file Logs/20140413T132323/Express0021.lzma 2014-04-13T13:59:24.158Z,1397397564.158 [NAL9602](INFO): Packets left to send: 0 2014-04-13T13:59:24.159Z,1397397564.159 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Express0021.lzma.parts/0000.sbd 2014-04-13T13:59:24.159Z,1397397564.159 [NAL9602](INFO): Completed sending Logs/20140413T132323/Express0021.lzma 2014-04-13T13:59:34.693Z,1397397574.693 [NAL9602](INFO): SBD MO Status=0, MOMSN=25377, MT Status=0, MTMSN=0 2014-04-13T13:59:34.785Z,1397397574.785 [keepstation:SURFACECOMMS:B:B] Stopped 2014-04-13T13:59:34.790Z,1397397574.790 [keepstation:SURFACECOMMS:B:C] Running Loop=1 2014-04-13T13:59:37.437Z,1397397577.437 [NAL9602](IMPORTANT): GPS fix at: 1397397539.00 2014-04-13T13:59:37.450Z,1397397577.450 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T13:59:37.453Z,1397397577.453 [keepstation:SURFACECOMMS:B:C] Stopped 2014-04-13T13:59:37.454Z,1397397577.454 [keepstation:SURFACECOMMS:B](INFO): Completed keepstation:SURFACECOMMS:B 2014-04-13T13:59:37.454Z,1397397577.454 [keepstation:SURFACECOMMS:B] Stopped 2014-04-13T13:59:37.454Z,1397397577.454 [keepstation:SURFACECOMMS:B](INFO): Aggregate::uninitialize keepstation:SURFACECOMMS:B 2014-04-13T13:59:37.455Z,1397397577.455 [keepstation:SURFACECOMMS](INFO): Completed keepstation:SURFACECOMMS 2014-04-13T13:59:37.455Z,1397397577.455 [keepstation:SURFACECOMMS] Stopped 2014-04-13T13:59:37.455Z,1397397577.455 [keepstation:SURFACECOMMS](INFO): Aggregate::uninitialize keepstation:SURFACECOMMS 2014-04-13T13:59:37.455Z,1397397577.455 [keepstation:SURFACECOMMS:A.GoToSurface] Stopped 2014-04-13T13:59:37.455Z,1397397577.455 [keepstation:SURFACECOMMS:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T13:59:38.018Z,1397397578.018 [keepstation:NeedComms:A](INFO): Completed keepstation:NeedComms:A 2014-04-13T13:59:38.018Z,1397397578.018 [keepstation:NeedComms:A] Stopped 2014-04-13T13:59:38.018Z,1397397578.018 [keepstation:NeedComms:A](INFO): Aggregate::uninitialize keepstation:NeedComms:A 2014-04-13T13:59:38.018Z,1397397578.018 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms 2014-04-13T13:59:38.018Z,1397397578.018 [keepstation:NeedComms] Stopped 2014-04-13T13:59:38.019Z,1397397578.019 [keepstation:NeedComms](INFO): Aggregate::uninitialize keepstation:NeedComms 2014-04-13T13:59:45.028Z,1397397585.028 [NAL9602](INFO): Powering down 2014-04-13T13:59:58.695Z,1397397598.695 [Radio_Freewave](INFO): Powering down 2014-04-13T14:00:37.143Z,1397397637.143 [Radio_Freewave](INFO): Powering up 2014-04-13T14:00:38.426Z,1397397638.426 [Radio_Freewave](IMPORTANT): Starting PPPD with command:/sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0 2014-04-13T14:01:53.933Z,1397397713.933 [Radio_Freewave](INFO): Powering down 2014-04-13T14:14:37.558Z,1397398477.558 [keepstation:NeedComms] Running Loop=1 2014-04-13T14:14:37.558Z,1397398477.558 [keepstation:NeedComms](INFO): Aggregate::initialize keepstation:NeedComms 2014-04-13T14:14:37.559Z,1397398477.559 [keepstation:NeedComms:A] Running Loop=1 2014-04-13T14:14:37.559Z,1397398477.559 [keepstation:NeedComms:A](INFO): Aggregate::initialize keepstation:NeedComms:A 2014-04-13T14:14:38.131Z,1397398478.131 [keepstation:SURFACECOMMS] Running Loop=1 2014-04-13T14:14:38.131Z,1397398478.131 [keepstation:SURFACECOMMS](INFO): Aggregate::initialize keepstation:SURFACECOMMS 2014-04-13T14:14:38.131Z,1397398478.131 [keepstation:SURFACECOMMS:A.GoToSurface] Running Loop=1 2014-04-13T14:14:38.132Z,1397398478.132 [keepstation:SURFACECOMMS:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T14:17:52.136Z,1397398672.136 [Radio_Freewave](INFO): Powering up 2014-04-13T14:17:52.195Z,1397398672.195 [keepstation:SURFACECOMMS:B] Running Loop=1 2014-04-13T14:17:52.196Z,1397398672.196 [keepstation:SURFACECOMMS:B](INFO): Aggregate::initialize keepstation:SURFACECOMMS:B 2014-04-13T14:17:52.196Z,1397398672.196 [keepstation:SURFACECOMMS:B:A] Running Loop=1 2014-04-13T14:17:53.259Z,1397398673.259 [NAL9602](INFO): Powering up 2014-04-13T14:17:53.266Z,1397398673.266 [Radio_Freewave](IMPORTANT): Starting PPPD with command:/sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0 2014-04-13T14:18:03.974Z,1397398683.974 [NAL9602](INFO): NAL9602 initialized 2014-04-13T14:18:24.544Z,1397398704.544 [NAL9602](INFO): SBD MO Status=0, MOMSN=25378, MT Status=0, MTMSN=0 2014-04-13T14:18:24.544Z,1397398704.544 [NAL9602](INFO): No messages in MT queue 2014-04-13T14:18:31.590Z,1397398711.590 [NAL9602](IMPORTANT): GPS fix at: 1397398673.00 2014-04-13T14:18:31.616Z,1397398711.616 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T14:18:31.616Z,1397398711.616 [DeadReckonUsingMultipleVelocitySources](DEBUG): horizontalPathLengthSinceLastFix_ = 767.978, recording fix residuals... 2014-04-13T14:18:31.631Z,1397398711.631 [keepstation:SURFACECOMMS:B:A] Stopped 2014-04-13T14:18:31.632Z,1397398711.632 [keepstation:SURFACECOMMS:B:B] Running Loop=1 2014-04-13T14:18:50.567Z,1397398730.567 [NAL9602](INFO): SBD MO Status=1, MOMSN=25379, MT Status=0, MTMSN=0 2014-04-13T14:18:50.614Z,1397398730.614 [NAL9602](INFO): Sent 74 bytes from file Logs/20140413T132323/Courier0024.lzma 2014-04-13T14:18:50.615Z,1397398730.615 [NAL9602](INFO): Packets left to send: 0 2014-04-13T14:18:50.616Z,1397398730.616 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Courier0024.lzma.parts/0000.sbd 2014-04-13T14:18:50.617Z,1397398730.617 [NAL9602](INFO): Completed sending Logs/20140413T132323/Courier0024.lzma 2014-04-13T14:19:00.458Z,1397398740.458 [NAL9602](INFO): SBD MO Status=1, MOMSN=25380, MT Status=0, MTMSN=0 2014-04-13T14:19:00.510Z,1397398740.510 [NAL9602](INFO): Sent 332 bytes from file Logs/20140413T132323/Express0025.lzma 2014-04-13T14:19:00.510Z,1397398740.510 [NAL9602](INFO): Packets left to send: 1 2014-04-13T14:19:00.512Z,1397398740.512 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Express0025.lzma.parts/0001.sbd 2014-04-13T14:19:10.107Z,1397398750.107 [NAL9602](INFO): SBD MO Status=1, MOMSN=25381, MT Status=0, MTMSN=0 2014-04-13T14:19:10.157Z,1397398750.157 [NAL9602](INFO): Sent 98 bytes from file Logs/20140413T132323/Express0025.lzma 2014-04-13T14:19:10.157Z,1397398750.157 [NAL9602](INFO): Packets left to send: 0 2014-04-13T14:19:10.158Z,1397398750.158 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Express0025.lzma.parts/0000.sbd 2014-04-13T14:19:10.158Z,1397398750.158 [NAL9602](INFO): Completed sending Logs/20140413T132323/Express0025.lzma 2014-04-13T14:19:19.333Z,1397398759.333 [NAL9602](INFO): SBD MO Status=0, MOMSN=25382, MT Status=0, MTMSN=0 2014-04-13T14:19:19.430Z,1397398759.430 [keepstation:SURFACECOMMS:B:B] Stopped 2014-04-13T14:19:19.431Z,1397398759.431 [keepstation:SURFACECOMMS:B:C] Running Loop=1 2014-04-13T14:19:22.087Z,1397398762.087 [NAL9602](IMPORTANT): GPS fix at: 1397398724.00 2014-04-13T14:19:22.117Z,1397398762.117 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T14:19:22.124Z,1397398762.124 [keepstation:SURFACECOMMS:B:C] Stopped 2014-04-13T14:19:22.124Z,1397398762.124 [keepstation:SURFACECOMMS:B](INFO): Completed keepstation:SURFACECOMMS:B 2014-04-13T14:19:22.124Z,1397398762.124 [keepstation:SURFACECOMMS:B] Stopped 2014-04-13T14:19:22.124Z,1397398762.124 [keepstation:SURFACECOMMS:B](INFO): Aggregate::uninitialize keepstation:SURFACECOMMS:B 2014-04-13T14:19:22.125Z,1397398762.125 [keepstation:SURFACECOMMS](INFO): Completed keepstation:SURFACECOMMS 2014-04-13T14:19:22.125Z,1397398762.125 [keepstation:SURFACECOMMS] Stopped 2014-04-13T14:19:22.126Z,1397398762.126 [keepstation:SURFACECOMMS](INFO): Aggregate::uninitialize keepstation:SURFACECOMMS 2014-04-13T14:19:22.126Z,1397398762.126 [keepstation:SURFACECOMMS:A.GoToSurface] Stopped 2014-04-13T14:19:22.126Z,1397398762.126 [keepstation:SURFACECOMMS:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T14:19:22.532Z,1397398762.532 [keepstation:NeedComms:A](INFO): Completed keepstation:NeedComms:A 2014-04-13T14:19:22.532Z,1397398762.532 [keepstation:NeedComms:A] Stopped 2014-04-13T14:19:22.532Z,1397398762.532 [keepstation:NeedComms:A](INFO): Aggregate::uninitialize keepstation:NeedComms:A 2014-04-13T14:19:22.533Z,1397398762.533 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms 2014-04-13T14:19:22.533Z,1397398762.533 [keepstation:NeedComms] Stopped 2014-04-13T14:19:22.533Z,1397398762.533 [keepstation:NeedComms](INFO): Aggregate::uninitialize keepstation:NeedComms 2014-04-13T14:19:27.176Z,1397398767.176 [DVL_micro](ERROR): No DVL communication! Re-initializing 2014-04-13T14:19:27.176Z,1397398767.176 [DVL_micro] Communications Fault, FailCount= 1 2014-04-13T14:19:27.177Z,1397398767.177 [DVL_micro](ERROR): Communications Fault 2014-04-13T14:19:27.369Z,1397398767.369 [CBIT](ERROR): Communications Fault in component: DVL_micro 2014-04-13T14:19:27.795Z,1397398767.795 [DVL_micro](INFO): uninitialize:Powering down 2014-04-13T14:19:28.357Z,1397398768.357 [DVL_micro](FAULT): LCB fault: Software Overcurrent. 2014-04-13T14:19:28.357Z,1397398768.357 [DVL_micro] Hardware Fault, FailCount= 1 2014-04-13T14:19:28.357Z,1397398768.357 [DVL_micro](ERROR): Hardware Fault 2014-04-13T14:19:28.868Z,1397398768.868 [NAL9602](INFO): Powering down 2014-04-13T14:19:28.996Z,1397398768.996 [CBIT](INFO): Clearing failed state for component DVL_micro 2014-04-13T14:19:28.996Z,1397398768.996 [DVL_micro] No Fault, FailCount= 1 2014-04-13T14:19:29.364Z,1397398769.364 [DVL_micro](INFO): Initializing 2014-04-13T14:19:45.826Z,1397398785.826 [Radio_Freewave](INFO): Powering down 2014-04-13T14:20:14.945Z,1397398814.945 [Radio_Freewave](INFO): Powering up 2014-04-13T14:20:16.032Z,1397398816.032 [Radio_Freewave](IMPORTANT): Starting PPPD with command:/sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0 2014-04-13T14:20:56.726Z,1397398856.726 [Radio_Freewave](INFO): Powering down 2014-04-13T14:21:03.869Z,1397398863.869 [Radio_Freewave](INFO): Powering up 2014-04-13T14:21:05.156Z,1397398865.156 [Radio_Freewave](IMPORTANT): Starting PPPD with command:/sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0 2014-04-13T14:21:13.660Z,1397398873.660 [Radio_Freewave](INFO): Powering down 2014-04-13T14:34:22.557Z,1397399662.557 [keepstation:NeedComms] Running Loop=1 2014-04-13T14:34:22.557Z,1397399662.557 [keepstation:NeedComms](INFO): Aggregate::initialize keepstation:NeedComms 2014-04-13T14:34:22.557Z,1397399662.557 [keepstation:NeedComms:A] Running Loop=1 2014-04-13T14:34:22.557Z,1397399662.557 [keepstation:NeedComms:A](INFO): Aggregate::initialize keepstation:NeedComms:A 2014-04-13T14:34:23.140Z,1397399663.140 [keepstation:SURFACECOMMS] Running Loop=1 2014-04-13T14:34:23.140Z,1397399663.140 [keepstation:SURFACECOMMS](INFO): Aggregate::initialize keepstation:SURFACECOMMS 2014-04-13T14:34:23.141Z,1397399663.141 [keepstation:SURFACECOMMS:A.GoToSurface] Running Loop=1 2014-04-13T14:34:23.141Z,1397399663.141 [keepstation:SURFACECOMMS:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T14:37:32.666Z,1397399852.666 [Radio_Freewave](INFO): Powering up 2014-04-13T14:37:32.729Z,1397399852.729 [keepstation:SURFACECOMMS:B] Running Loop=1 2014-04-13T14:37:32.729Z,1397399852.729 [keepstation:SURFACECOMMS:B](INFO): Aggregate::initialize keepstation:SURFACECOMMS:B 2014-04-13T14:37:32.729Z,1397399852.729 [keepstation:SURFACECOMMS:B:A] Running Loop=1 2014-04-13T14:37:33.731Z,1397399853.731 [NAL9602](INFO): Powering up 2014-04-13T14:37:33.737Z,1397399853.737 [Radio_Freewave](IMPORTANT): Starting PPPD with command:/sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0 2014-04-13T14:37:44.733Z,1397399864.733 [NAL9602](INFO): NAL9602 initialized 2014-04-13T14:38:06.833Z,1397399886.833 [NAL9602](INFO): SBD MO Status=0, MOMSN=25383, MT Status=0, MTMSN=0 2014-04-13T14:38:06.833Z,1397399886.833 [NAL9602](INFO): No messages in MT queue 2014-04-13T14:38:14.357Z,1397399894.357 [NAL9602](IMPORTANT): GPS fix at: 1397399856.00 2014-04-13T14:38:14.371Z,1397399894.371 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T14:38:14.371Z,1397399894.371 [DeadReckonUsingMultipleVelocitySources](DEBUG): horizontalPathLengthSinceLastFix_ = 786.507, recording fix residuals... 2014-04-13T14:38:14.395Z,1397399894.395 [keepstation:SURFACECOMMS:B:A] Stopped 2014-04-13T14:38:14.396Z,1397399894.396 [keepstation:SURFACECOMMS:B:B] Running Loop=1 2014-04-13T14:39:04.338Z,1397399944.338 [NAL9602](INFO): SBD MO Status=2, MOMSN=25384, MT Status=2, MTMSN=0 2014-04-13T14:39:04.339Z,1397399944.339 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2014-04-13T14:39:22.144Z,1397399962.144 [NAL9602](INFO): SBD MO Status=1, MOMSN=25384, MT Status=0, MTMSN=0 2014-04-13T14:39:22.192Z,1397399962.192 [NAL9602](INFO): Sent 74 bytes from file Logs/20140413T132323/Courier0028.lzma 2014-04-13T14:39:22.192Z,1397399962.192 [NAL9602](INFO): Packets left to send: 0 2014-04-13T14:39:22.194Z,1397399962.194 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Courier0028.lzma.parts/0000.sbd 2014-04-13T14:39:22.194Z,1397399962.194 [NAL9602](INFO): Completed sending Logs/20140413T132323/Courier0028.lzma 2014-04-13T14:39:31.614Z,1397399971.614 [NAL9602](INFO): SBD MO Status=1, MOMSN=25385, MT Status=0, MTMSN=0 2014-04-13T14:39:31.663Z,1397399971.663 [NAL9602](INFO): Sent 332 bytes from file Logs/20140413T132323/Express0029.lzma 2014-04-13T14:39:31.663Z,1397399971.663 [NAL9602](INFO): Packets left to send: 1 2014-04-13T14:39:31.664Z,1397399971.664 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Express0029.lzma.parts/0001.sbd 2014-04-13T14:39:41.961Z,1397399981.961 [NAL9602](INFO): SBD MO Status=1, MOMSN=25386, MT Status=0, MTMSN=0 2014-04-13T14:39:42.015Z,1397399982.015 [NAL9602](INFO): Sent 109 bytes from file Logs/20140413T132323/Express0029.lzma 2014-04-13T14:39:42.015Z,1397399982.015 [NAL9602](INFO): Packets left to send: 0 2014-04-13T14:39:42.016Z,1397399982.016 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Express0029.lzma.parts/0000.sbd 2014-04-13T14:39:42.016Z,1397399982.016 [NAL9602](INFO): Completed sending Logs/20140413T132323/Express0029.lzma 2014-04-13T14:39:52.442Z,1397399992.442 [NAL9602](INFO): SBD MO Status=0, MOMSN=25387, MT Status=0, MTMSN=0 2014-04-13T14:39:52.534Z,1397399992.534 [keepstation:SURFACECOMMS:B:B] Stopped 2014-04-13T14:39:52.535Z,1397399992.535 [keepstation:SURFACECOMMS:B:C] Running Loop=1 2014-04-13T14:39:55.146Z,1397399995.146 [NAL9602](IMPORTANT): GPS fix at: 1397399957.00 2014-04-13T14:39:55.160Z,1397399995.160 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T14:39:55.163Z,1397399995.163 [keepstation:SURFACECOMMS:B:C] Stopped 2014-04-13T14:39:55.163Z,1397399995.163 [keepstation:SURFACECOMMS:B](INFO): Completed keepstation:SURFACECOMMS:B 2014-04-13T14:39:55.163Z,1397399995.163 [keepstation:SURFACECOMMS:B] Stopped 2014-04-13T14:39:55.163Z,1397399995.163 [keepstation:SURFACECOMMS:B](INFO): Aggregate::uninitialize keepstation:SURFACECOMMS:B 2014-04-13T14:39:55.164Z,1397399995.164 [keepstation:SURFACECOMMS](INFO): Completed keepstation:SURFACECOMMS 2014-04-13T14:39:55.164Z,1397399995.164 [keepstation:SURFACECOMMS] Stopped 2014-04-13T14:39:55.164Z,1397399995.164 [keepstation:SURFACECOMMS](INFO): Aggregate::uninitialize keepstation:SURFACECOMMS 2014-04-13T14:39:55.165Z,1397399995.165 [keepstation:SURFACECOMMS:A.GoToSurface] Stopped 2014-04-13T14:39:55.165Z,1397399995.165 [keepstation:SURFACECOMMS:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T14:39:55.636Z,1397399995.636 [keepstation:NeedComms:A](INFO): Completed keepstation:NeedComms:A 2014-04-13T14:39:55.636Z,1397399995.636 [keepstation:NeedComms:A] Stopped 2014-04-13T14:39:55.636Z,1397399995.636 [keepstation:NeedComms:A](INFO): Aggregate::uninitialize keepstation:NeedComms:A 2014-04-13T14:39:55.636Z,1397399995.636 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms 2014-04-13T14:39:55.636Z,1397399995.636 [keepstation:NeedComms] Stopped 2014-04-13T14:39:55.636Z,1397399995.636 [keepstation:NeedComms](INFO): Aggregate::uninitialize keepstation:NeedComms 2014-04-13T14:40:02.972Z,1397400002.972 [NAL9602](INFO): Powering down 2014-04-13T14:40:19.553Z,1397400019.553 [Radio_Freewave](INFO): Powering down 2014-04-13T14:40:51.327Z,1397400051.327 [Radio_Freewave](INFO): Powering up 2014-04-13T14:40:52.436Z,1397400052.436 [Radio_Freewave](IMPORTANT): Starting PPPD with command:/sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0 2014-04-13T14:41:48.350Z,1397400108.350 [Radio_Freewave](INFO): Powering down 2014-04-13T14:50:53.549Z,1397400653.549 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:50:56.020Z,1397400656.020 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:50:58.346Z,1397400658.346 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:51:00.790Z,1397400660.790 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:51:03.216Z,1397400663.216 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:51:05.706Z,1397400665.706 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:51:08.183Z,1397400668.183 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:51:10.682Z,1397400670.682 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:51:13.030Z,1397400673.030 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:51:15.452Z,1397400675.452 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:51:17.748Z,1397400677.748 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:51:20.590Z,1397400680.590 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:51:22.685Z,1397400682.685 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:51:25.094Z,1397400685.094 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:51:28.052Z,1397400688.052 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:51:30.094Z,1397400690.094 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:51:32.588Z,1397400692.588 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:51:34.941Z,1397400694.941 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:51:37.471Z,1397400697.471 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:51:39.787Z,1397400699.787 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:51:42.275Z,1397400702.275 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:51:44.707Z,1397400704.707 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:51:47.245Z,1397400707.245 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:51:49.955Z,1397400709.955 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:51:52.314Z,1397400712.314 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:51:54.614Z,1397400714.614 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:51:57.034Z,1397400717.034 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:51:59.417Z,1397400719.417 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:52:01.833Z,1397400721.833 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:52:04.281Z,1397400724.281 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:52:06.782Z,1397400726.782 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:52:09.152Z,1397400729.152 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:52:11.538Z,1397400731.538 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:52:14.140Z,1397400734.140 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:52:16.651Z,1397400736.651 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:52:19.116Z,1397400739.116 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:52:21.436Z,1397400741.436 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:52:23.893Z,1397400743.893 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T14:54:20.769Z,1397400860.769 [ThrusterServo](FAULT): getVelocity uart error serial timeout 2014-04-13T14:54:20.769Z,1397400860.769 [ThrusterServo](FAULT): Thruster uart error: serial timeout 2014-04-13T14:54:20.769Z,1397400860.769 [ThrusterServo] Communications Fault, FailCount= 1 2014-04-13T14:54:20.769Z,1397400860.769 [ThrusterServo](ERROR): Communications Fault 2014-04-13T14:54:20.772Z,1397400860.772 [CBIT](ERROR): Communications Fault in component: ThrusterServo 2014-04-13T14:54:21.193Z,1397400861.193 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2014-04-13T14:54:21.194Z,1397400861.194 [ThrusterServo](INFO): Powering down 2014-04-13T14:54:22.097Z,1397400862.097 [ThrusterServo](DEBUG): Initializing EZServoServo. 2014-04-13T14:54:22.212Z,1397400862.212 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2014-04-13T14:54:22.215Z,1397400862.215 [CBIT](INFO): Clearing failed state for component ThrusterServo 2014-04-13T14:54:22.215Z,1397400862.215 [ThrusterServo] No Fault, FailCount= 1 2014-04-13T14:54:55.208Z,1397400895.208 [keepstation:NeedComms] Running Loop=1 2014-04-13T14:54:55.208Z,1397400895.208 [keepstation:NeedComms](INFO): Aggregate::initialize keepstation:NeedComms 2014-04-13T14:54:55.209Z,1397400895.209 [keepstation:NeedComms:A] Running Loop=1 2014-04-13T14:54:55.209Z,1397400895.209 [keepstation:NeedComms:A](INFO): Aggregate::initialize keepstation:NeedComms:A 2014-04-13T14:54:55.734Z,1397400895.734 [keepstation:SURFACECOMMS] Running Loop=1 2014-04-13T14:54:55.734Z,1397400895.734 [keepstation:SURFACECOMMS](INFO): Aggregate::initialize keepstation:SURFACECOMMS 2014-04-13T14:54:55.734Z,1397400895.734 [keepstation:SURFACECOMMS:A.GoToSurface] Running Loop=1 2014-04-13T14:54:55.734Z,1397400895.734 [keepstation:SURFACECOMMS:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T14:58:04.191Z,1397401084.191 [Radio_Freewave](INFO): Powering up 2014-04-13T14:58:04.273Z,1397401084.273 [keepstation:SURFACECOMMS:B] Running Loop=1 2014-04-13T14:58:04.273Z,1397401084.273 [keepstation:SURFACECOMMS:B](INFO): Aggregate::initialize keepstation:SURFACECOMMS:B 2014-04-13T14:58:04.273Z,1397401084.273 [keepstation:SURFACECOMMS:B:A] Running Loop=1 2014-04-13T14:58:05.260Z,1397401085.260 [NAL9602](INFO): Powering up 2014-04-13T14:58:05.272Z,1397401085.272 [Radio_Freewave](IMPORTANT): Starting PPPD with command:/sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0 2014-04-13T14:58:16.146Z,1397401096.146 [NAL9602](INFO): NAL9602 initialized 2014-04-13T14:58:30.560Z,1397401110.560 [NAL9602](INFO): SBD MO Status=0, MOMSN=25388, MT Status=0, MTMSN=0 2014-04-13T14:58:30.560Z,1397401110.560 [NAL9602](INFO): No messages in MT queue 2014-04-13T14:58:40.632Z,1397401120.632 [NAL9602](IMPORTANT): GPS fix at: 1397401082.00 2014-04-13T14:58:40.646Z,1397401120.646 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T14:58:40.646Z,1397401120.646 [DeadReckonUsingMultipleVelocitySources](DEBUG): horizontalPathLengthSinceLastFix_ = 761.332, recording fix residuals... 2014-04-13T14:58:40.651Z,1397401120.651 [keepstation:SURFACECOMMS:B:A] Stopped 2014-04-13T14:58:40.651Z,1397401120.651 [keepstation:SURFACECOMMS:B:B] Running Loop=1 2014-04-13T14:58:55.434Z,1397401135.434 [NAL9602](INFO): SBD MO Status=1, MOMSN=25389, MT Status=0, MTMSN=0 2014-04-13T14:58:55.488Z,1397401135.488 [NAL9602](INFO): Sent 77 bytes from file Logs/20140413T132323/Courier0032.lzma 2014-04-13T14:58:55.488Z,1397401135.488 [NAL9602](INFO): Packets left to send: 0 2014-04-13T14:58:55.490Z,1397401135.490 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Courier0032.lzma.parts/0000.sbd 2014-04-13T14:58:55.490Z,1397401135.490 [NAL9602](INFO): Completed sending Logs/20140413T132323/Courier0032.lzma 2014-04-13T14:59:06.506Z,1397401146.506 [NAL9602](INFO): SBD MO Status=1, MOMSN=25390, MT Status=0, MTMSN=0 2014-04-13T14:59:06.560Z,1397401146.560 [NAL9602](INFO): Sent 332 bytes from file Logs/20140413T132323/Express0033.lzma 2014-04-13T14:59:06.560Z,1397401146.560 [NAL9602](INFO): Packets left to send: 1 2014-04-13T14:59:06.562Z,1397401146.562 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Express0033.lzma.parts/0001.sbd 2014-04-13T14:59:14.714Z,1397401154.714 [NAL9602](INFO): SBD MO Status=1, MOMSN=25391, MT Status=0, MTMSN=0 2014-04-13T14:59:14.781Z,1397401154.781 [NAL9602](INFO): Sent 165 bytes from file Logs/20140413T132323/Express0033.lzma 2014-04-13T14:59:14.781Z,1397401154.781 [NAL9602](INFO): Packets left to send: 0 2014-04-13T14:59:14.782Z,1397401154.782 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Express0033.lzma.parts/0000.sbd 2014-04-13T14:59:14.783Z,1397401154.783 [NAL9602](INFO): Completed sending Logs/20140413T132323/Express0033.lzma 2014-04-13T14:59:25.538Z,1397401165.538 [NAL9602](INFO): SBD MO Status=0, MOMSN=25392, MT Status=0, MTMSN=0 2014-04-13T14:59:25.638Z,1397401165.638 [keepstation:SURFACECOMMS:B:B] Stopped 2014-04-13T14:59:25.638Z,1397401165.638 [keepstation:SURFACECOMMS:B:C] Running Loop=1 2014-04-13T14:59:28.135Z,1397401168.135 [NAL9602](IMPORTANT): GPS fix at: 1397401130.00 2014-04-13T14:59:28.148Z,1397401168.148 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T14:59:28.152Z,1397401168.152 [keepstation:SURFACECOMMS:B:C] Stopped 2014-04-13T14:59:28.152Z,1397401168.152 [keepstation:SURFACECOMMS:B](INFO): Completed keepstation:SURFACECOMMS:B 2014-04-13T14:59:28.152Z,1397401168.152 [keepstation:SURFACECOMMS:B] Stopped 2014-04-13T14:59:28.152Z,1397401168.152 [keepstation:SURFACECOMMS:B](INFO): Aggregate::uninitialize keepstation:SURFACECOMMS:B 2014-04-13T14:59:28.153Z,1397401168.153 [keepstation:SURFACECOMMS](INFO): Completed keepstation:SURFACECOMMS 2014-04-13T14:59:28.153Z,1397401168.153 [keepstation:SURFACECOMMS] Stopped 2014-04-13T14:59:28.153Z,1397401168.153 [keepstation:SURFACECOMMS](INFO): Aggregate::uninitialize keepstation:SURFACECOMMS 2014-04-13T14:59:28.154Z,1397401168.154 [keepstation:SURFACECOMMS:A.GoToSurface] Stopped 2014-04-13T14:59:28.154Z,1397401168.154 [keepstation:SURFACECOMMS:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T14:59:28.789Z,1397401168.789 [keepstation:NeedComms:A](INFO): Completed keepstation:NeedComms:A 2014-04-13T14:59:28.789Z,1397401168.789 [keepstation:NeedComms:A] Stopped 2014-04-13T14:59:28.789Z,1397401168.789 [keepstation:NeedComms:A](INFO): Aggregate::uninitialize keepstation:NeedComms:A 2014-04-13T14:59:28.789Z,1397401168.789 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms 2014-04-13T14:59:28.790Z,1397401168.790 [keepstation:NeedComms] Stopped 2014-04-13T14:59:28.790Z,1397401168.790 [keepstation:NeedComms](INFO): Aggregate::uninitialize keepstation:NeedComms 2014-04-13T14:59:36.354Z,1397401176.354 [NAL9602](INFO): Powering down 2014-04-13T14:59:49.555Z,1397401189.555 [Radio_Freewave](INFO): Powering down 2014-04-13T15:00:28.868Z,1397401228.868 [Radio_Freewave](INFO): Powering up 2014-04-13T15:00:30.164Z,1397401230.164 [Radio_Freewave](IMPORTANT): Starting PPPD with command:/sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0 2014-04-13T15:00:38.507Z,1397401238.507 [Radio_Freewave](INFO): Powering down 2014-04-13T15:14:28.382Z,1397402068.382 [keepstation:NeedComms] Running Loop=1 2014-04-13T15:14:28.382Z,1397402068.382 [keepstation:NeedComms](INFO): Aggregate::initialize keepstation:NeedComms 2014-04-13T15:14:28.382Z,1397402068.382 [keepstation:NeedComms:A] Running Loop=1 2014-04-13T15:14:28.383Z,1397402068.383 [keepstation:NeedComms:A](INFO): Aggregate::initialize keepstation:NeedComms:A 2014-04-13T15:14:28.896Z,1397402068.896 [keepstation:SURFACECOMMS] Running Loop=1 2014-04-13T15:14:28.896Z,1397402068.896 [keepstation:SURFACECOMMS](INFO): Aggregate::initialize keepstation:SURFACECOMMS 2014-04-13T15:14:28.897Z,1397402068.897 [keepstation:SURFACECOMMS:A.GoToSurface] Running Loop=1 2014-04-13T15:14:28.897Z,1397402068.897 [keepstation:SURFACECOMMS:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T15:17:35.391Z,1397402255.391 [Radio_Freewave](INFO): Powering up 2014-04-13T15:17:35.448Z,1397402255.448 [keepstation:SURFACECOMMS:B] Running Loop=1 2014-04-13T15:17:35.449Z,1397402255.449 [keepstation:SURFACECOMMS:B](INFO): Aggregate::initialize keepstation:SURFACECOMMS:B 2014-04-13T15:17:35.449Z,1397402255.449 [keepstation:SURFACECOMMS:B:A] Running Loop=1 2014-04-13T15:17:36.391Z,1397402256.391 [NAL9602](INFO): Powering up 2014-04-13T15:17:36.398Z,1397402256.398 [Radio_Freewave](IMPORTANT): Starting PPPD with command:/sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0 2014-04-13T15:17:47.286Z,1397402267.286 [NAL9602](INFO): NAL9602 initialized 2014-04-13T15:18:05.867Z,1397402285.867 [NAL9602](INFO): SBD MO Status=0, MOMSN=25393, MT Status=0, MTMSN=0 2014-04-13T15:18:05.867Z,1397402285.867 [NAL9602](INFO): No messages in MT queue 2014-04-13T15:18:10.600Z,1397402290.600 [NAL9602](IMPORTANT): GPS fix at: 1397402252.00 2014-04-13T15:18:10.616Z,1397402290.616 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T15:18:10.616Z,1397402290.616 [DeadReckonUsingMultipleVelocitySources](DEBUG): horizontalPathLengthSinceLastFix_ = 763.671, recording fix residuals... 2014-04-13T15:18:10.646Z,1397402290.646 [keepstation:SURFACECOMMS:B:A] Stopped 2014-04-13T15:18:10.646Z,1397402290.646 [keepstation:SURFACECOMMS:B:B] Running Loop=1 2014-04-13T15:18:26.634Z,1397402306.634 [NAL9602](INFO): SBD MO Status=1, MOMSN=25394, MT Status=0, MTMSN=0 2014-04-13T15:18:26.683Z,1397402306.683 [NAL9602](INFO): Sent 74 bytes from file Logs/20140413T132323/Courier0036.lzma 2014-04-13T15:18:26.683Z,1397402306.683 [NAL9602](INFO): Packets left to send: 0 2014-04-13T15:18:26.686Z,1397402306.686 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Courier0036.lzma.parts/0000.sbd 2014-04-13T15:18:26.686Z,1397402306.686 [NAL9602](INFO): Completed sending Logs/20140413T132323/Courier0036.lzma 2014-04-13T15:18:38.310Z,1397402318.310 [NAL9602](INFO): SBD MO Status=1, MOMSN=25395, MT Status=0, MTMSN=0 2014-04-13T15:18:38.373Z,1397402318.373 [NAL9602](INFO): Sent 332 bytes from file Logs/20140413T132323/Express0037.lzma 2014-04-13T15:18:38.373Z,1397402318.373 [NAL9602](INFO): Packets left to send: 1 2014-04-13T15:18:38.375Z,1397402318.375 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Express0037.lzma.parts/0001.sbd 2014-04-13T15:18:45.270Z,1397402325.270 [NAL9602](INFO): SBD MO Status=1, MOMSN=25396, MT Status=0, MTMSN=0 2014-04-13T15:18:45.332Z,1397402325.332 [NAL9602](INFO): Sent 50 bytes from file Logs/20140413T132323/Express0037.lzma 2014-04-13T15:18:45.332Z,1397402325.332 [NAL9602](INFO): Packets left to send: 0 2014-04-13T15:18:45.333Z,1397402325.333 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Express0037.lzma.parts/0000.sbd 2014-04-13T15:18:45.333Z,1397402325.333 [NAL9602](INFO): Completed sending Logs/20140413T132323/Express0037.lzma 2014-04-13T15:18:52.911Z,1397402332.911 [NAL9602](INFO): SBD MO Status=0, MOMSN=25397, MT Status=0, MTMSN=0 2014-04-13T15:18:53.008Z,1397402333.008 [keepstation:SURFACECOMMS:B:B] Stopped 2014-04-13T15:18:53.009Z,1397402333.009 [keepstation:SURFACECOMMS:B:C] Running Loop=1 2014-04-13T15:18:55.472Z,1397402335.472 [NAL9602](IMPORTANT): GPS fix at: 1397402297.00 2014-04-13T15:18:55.486Z,1397402335.486 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T15:18:55.489Z,1397402335.489 [keepstation:SURFACECOMMS:B:C] Stopped 2014-04-13T15:18:55.489Z,1397402335.489 [keepstation:SURFACECOMMS:B](INFO): Completed keepstation:SURFACECOMMS:B 2014-04-13T15:18:55.489Z,1397402335.489 [keepstation:SURFACECOMMS:B] Stopped 2014-04-13T15:18:55.490Z,1397402335.490 [keepstation:SURFACECOMMS:B](INFO): Aggregate::uninitialize keepstation:SURFACECOMMS:B 2014-04-13T15:18:55.490Z,1397402335.490 [keepstation:SURFACECOMMS](INFO): Completed keepstation:SURFACECOMMS 2014-04-13T15:18:55.491Z,1397402335.491 [keepstation:SURFACECOMMS] Stopped 2014-04-13T15:18:55.491Z,1397402335.491 [keepstation:SURFACECOMMS](INFO): Aggregate::uninitialize keepstation:SURFACECOMMS 2014-04-13T15:18:55.491Z,1397402335.491 [keepstation:SURFACECOMMS:A.GoToSurface] Stopped 2014-04-13T15:18:55.491Z,1397402335.491 [keepstation:SURFACECOMMS:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T15:18:56.078Z,1397402336.078 [keepstation:NeedComms:A](INFO): Completed keepstation:NeedComms:A 2014-04-13T15:18:56.079Z,1397402336.079 [keepstation:NeedComms:A] Stopped 2014-04-13T15:18:56.079Z,1397402336.079 [keepstation:NeedComms:A](INFO): Aggregate::uninitialize keepstation:NeedComms:A 2014-04-13T15:18:56.079Z,1397402336.079 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms 2014-04-13T15:18:56.079Z,1397402336.079 [keepstation:NeedComms] Stopped 2014-04-13T15:18:56.079Z,1397402336.079 [keepstation:NeedComms](INFO): Aggregate::uninitialize keepstation:NeedComms 2014-04-13T15:19:03.177Z,1397402343.177 [NAL9602](INFO): Powering down 2014-04-13T15:19:14.957Z,1397402354.957 [Radio_Freewave](INFO): Powering down 2014-04-13T15:19:44.968Z,1397402384.968 [Radio_Freewave](INFO): Powering up 2014-04-13T15:19:46.313Z,1397402386.313 [Radio_Freewave](IMPORTANT): Starting PPPD with command:/sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0 2014-04-13T15:19:57.980Z,1397402397.980 [Radio_Freewave](INFO): Powering down 2014-04-13T15:20:03.613Z,1397402403.613 [Radio_Freewave](INFO): Powering up 2014-04-13T15:20:04.803Z,1397402404.803 [Radio_Freewave](IMPORTANT): Starting PPPD with command:/sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0 2014-04-13T15:21:30.444Z,1397402490.444 [Radio_Freewave](INFO): Powering down 2014-04-13T15:24:51.801Z,1397402691.801 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 37 of 46 2014-04-13T15:24:51.801Z,1397402691.801 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 48.5 53.4 48.5 44.9 -361.3 -67.7 219.6 -63.1 -396 -8 295 -59 9 16 13 12 -775.3 -6 -923 -45 2 -7.48 0.43 96.8 44.9 12.9 0.005 35.0 1489 101 2014-04-13T15:33:55.800Z,1397403235.800 [keepstation:NeedComms] Running Loop=1 2014-04-13T15:33:55.800Z,1397403235.800 [keepstation:NeedComms](INFO): Aggregate::initialize keepstation:NeedComms 2014-04-13T15:33:55.801Z,1397403235.801 [keepstation:NeedComms:A] Running Loop=1 2014-04-13T15:33:55.801Z,1397403235.801 [keepstation:NeedComms:A](INFO): Aggregate::initialize keepstation:NeedComms:A 2014-04-13T15:33:56.276Z,1397403236.276 [keepstation:SURFACECOMMS] Running Loop=1 2014-04-13T15:33:56.276Z,1397403236.276 [keepstation:SURFACECOMMS](INFO): Aggregate::initialize keepstation:SURFACECOMMS 2014-04-13T15:33:56.276Z,1397403236.276 [keepstation:SURFACECOMMS:A.GoToSurface] Running Loop=1 2014-04-13T15:33:56.276Z,1397403236.276 [keepstation:SURFACECOMMS:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T15:36:31.953Z,1397403391.953 [BuoyancyServo](ERROR): getPosition uart error serial timeout 2014-04-13T15:36:31.953Z,1397403391.953 [BuoyancyServo](FAULT): Buoyancy getPosition uart error.serial timeout 2014-04-13T15:36:31.954Z,1397403391.954 [BuoyancyServo] Communications Fault, FailCount= 1 2014-04-13T15:36:31.954Z,1397403391.954 [BuoyancyServo](ERROR): Communications Fault 2014-04-13T15:36:31.958Z,1397403391.958 [CBIT](ERROR): Communications Fault in component: BuoyancyServo 2014-04-13T15:36:32.379Z,1397403392.379 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2014-04-13T15:36:32.379Z,1397403392.379 [BuoyancyServo](INFO): Powering down 2014-04-13T15:36:34.679Z,1397403394.679 [CBIT](INFO): Clearing failed state for component BuoyancyServo 2014-04-13T15:36:34.679Z,1397403394.679 [BuoyancyServo] No Fault, FailCount= 1 2014-04-13T15:36:35.080Z,1397403395.080 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2014-04-13T15:36:35.195Z,1397403395.195 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2014-04-13T15:36:35.587Z,1397403395.587 [DVL_micro](ERROR): No DVL communication! Re-initializing 2014-04-13T15:36:35.587Z,1397403395.587 [DVL_micro] Communications Fault, FailCount= 1 2014-04-13T15:36:35.587Z,1397403395.587 [DVL_micro](ERROR): Communications Fault 2014-04-13T15:36:35.638Z,1397403395.638 [CBIT](ERROR): Communications Fault in component: DVL_micro 2014-04-13T15:36:36.092Z,1397403396.092 [DVL_micro](INFO): uninitialize:Powering down 2014-04-13T15:36:36.666Z,1397403396.666 [DVL_micro](FAULT): LCB fault: Software Overcurrent. 2014-04-13T15:36:36.666Z,1397403396.666 [DVL_micro] Hardware Fault, FailCount= 1 2014-04-13T15:36:36.667Z,1397403396.667 [DVL_micro](ERROR): Hardware Fault 2014-04-13T15:36:37.135Z,1397403397.135 [CBIT](INFO): Clearing failed state for component DVL_micro 2014-04-13T15:36:37.135Z,1397403397.135 [DVL_micro] No Fault, FailCount= 1 2014-04-13T15:36:37.505Z,1397403397.505 [DVL_micro](INFO): Initializing 2014-04-13T15:37:26.314Z,1397403446.314 [Radio_Freewave](INFO): Powering up 2014-04-13T15:37:26.391Z,1397403446.391 [keepstation:SURFACECOMMS:B] Running Loop=1 2014-04-13T15:37:26.391Z,1397403446.391 [keepstation:SURFACECOMMS:B](INFO): Aggregate::initialize keepstation:SURFACECOMMS:B 2014-04-13T15:37:26.391Z,1397403446.391 [keepstation:SURFACECOMMS:B:A] Running Loop=1 2014-04-13T15:37:27.337Z,1397403447.337 [NAL9602](INFO): Powering up 2014-04-13T15:37:27.354Z,1397403447.354 [Radio_Freewave](IMPORTANT): Starting PPPD with command:/sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0 2014-04-13T15:37:38.048Z,1397403458.048 [NAL9602](INFO): NAL9602 initialized 2014-04-13T15:37:54.689Z,1397403474.689 [NAL9602](INFO): SBD MO Status=0, MOMSN=25398, MT Status=0, MTMSN=0 2014-04-13T15:37:54.690Z,1397403474.690 [NAL9602](INFO): No messages in MT queue 2014-04-13T15:38:10.535Z,1397403490.535 [NAL9602](IMPORTANT): GPS fix at: 1397403452.00 2014-04-13T15:38:10.548Z,1397403490.548 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T15:38:10.549Z,1397403490.549 [DeadReckonUsingMultipleVelocitySources](DEBUG): horizontalPathLengthSinceLastFix_ = 755.425, recording fix residuals... 2014-04-13T15:38:10.553Z,1397403490.553 [keepstation:SURFACECOMMS:B:A] Stopped 2014-04-13T15:38:10.554Z,1397403490.554 [keepstation:SURFACECOMMS:B:B] Running Loop=1 2014-04-13T15:38:32.584Z,1397403512.584 [NAL9602](INFO): SBD MO Status=1, MOMSN=25399, MT Status=0, MTMSN=0 2014-04-13T15:38:32.637Z,1397403512.637 [NAL9602](INFO): Sent 75 bytes from file Logs/20140413T132323/Courier0040.lzma 2014-04-13T15:38:32.637Z,1397403512.637 [NAL9602](INFO): Packets left to send: 0 2014-04-13T15:38:32.639Z,1397403512.639 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Courier0040.lzma.parts/0000.sbd 2014-04-13T15:38:32.639Z,1397403512.639 [NAL9602](INFO): Completed sending Logs/20140413T132323/Courier0040.lzma 2014-04-13T15:38:43.751Z,1397403523.751 [NAL9602](INFO): SBD MO Status=1, MOMSN=25400, MT Status=0, MTMSN=0 2014-04-13T15:38:43.802Z,1397403523.802 [NAL9602](INFO): Sent 332 bytes from file Logs/20140413T132323/Express0041.lzma 2014-04-13T15:38:43.802Z,1397403523.802 [NAL9602](INFO): Packets left to send: 1 2014-04-13T15:38:43.804Z,1397403523.804 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Express0041.lzma.parts/0001.sbd 2014-04-13T15:38:56.143Z,1397403536.143 [NAL9602](INFO): SBD MO Status=1, MOMSN=25401, MT Status=0, MTMSN=0 2014-04-13T15:38:56.193Z,1397403536.193 [NAL9602](INFO): Sent 191 bytes from file Logs/20140413T132323/Express0041.lzma 2014-04-13T15:38:56.193Z,1397403536.193 [NAL9602](INFO): Packets left to send: 0 2014-04-13T15:38:56.194Z,1397403536.194 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Express0041.lzma.parts/0000.sbd 2014-04-13T15:38:56.195Z,1397403536.195 [NAL9602](INFO): Completed sending Logs/20140413T132323/Express0041.lzma 2014-04-13T15:39:27.385Z,1397403567.385 [NAL9602](INFO): SBD MO Status=0, MOMSN=25402, MT Status=0, MTMSN=0 2014-04-13T15:39:27.468Z,1397403567.468 [keepstation:SURFACECOMMS:B:B] Stopped 2014-04-13T15:39:27.468Z,1397403567.468 [keepstation:SURFACECOMMS:B:C] Running Loop=1 2014-04-13T15:39:30.102Z,1397403570.102 [NAL9602](IMPORTANT): GPS fix at: 1397403531.00 2014-04-13T15:39:30.147Z,1397403570.147 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T15:39:30.158Z,1397403570.158 [keepstation:SURFACECOMMS:B:C] Stopped 2014-04-13T15:39:30.158Z,1397403570.158 [keepstation:SURFACECOMMS:B](INFO): Completed keepstation:SURFACECOMMS:B 2014-04-13T15:39:30.159Z,1397403570.159 [keepstation:SURFACECOMMS:B] Stopped 2014-04-13T15:39:30.159Z,1397403570.159 [keepstation:SURFACECOMMS:B](INFO): Aggregate::uninitialize keepstation:SURFACECOMMS:B 2014-04-13T15:39:30.160Z,1397403570.160 [keepstation:SURFACECOMMS](INFO): Completed keepstation:SURFACECOMMS 2014-04-13T15:39:30.160Z,1397403570.160 [keepstation:SURFACECOMMS] Stopped 2014-04-13T15:39:30.160Z,1397403570.160 [keepstation:SURFACECOMMS](INFO): Aggregate::uninitialize keepstation:SURFACECOMMS 2014-04-13T15:39:30.160Z,1397403570.160 [keepstation:SURFACECOMMS:A.GoToSurface] Stopped 2014-04-13T15:39:30.160Z,1397403570.160 [keepstation:SURFACECOMMS:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T15:39:30.588Z,1397403570.588 [keepstation:NeedComms:A](INFO): Completed keepstation:NeedComms:A 2014-04-13T15:39:30.588Z,1397403570.588 [keepstation:NeedComms:A] Stopped 2014-04-13T15:39:30.588Z,1397403570.588 [keepstation:NeedComms:A](INFO): Aggregate::uninitialize keepstation:NeedComms:A 2014-04-13T15:39:30.588Z,1397403570.588 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms 2014-04-13T15:39:30.588Z,1397403570.588 [keepstation:NeedComms] Stopped 2014-04-13T15:39:30.588Z,1397403570.588 [keepstation:NeedComms](INFO): Aggregate::uninitialize keepstation:NeedComms 2014-04-13T15:39:37.832Z,1397403577.832 [NAL9602](INFO): Powering down 2014-04-13T15:39:46.090Z,1397403586.090 [Radio_Freewave](INFO): Powering down 2014-04-13T15:40:19.474Z,1397403619.474 [Radio_Freewave](INFO): Powering up 2014-04-13T15:40:20.610Z,1397403620.610 [Radio_Freewave](IMPORTANT): Starting PPPD with command:/sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0 2014-04-13T15:40:41.384Z,1397403641.384 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:119 Calculated:111 2014-04-13T15:40:41.385Z,1397403641.385 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 -0.1 -0.1 -0.1 -0.1 0 0 0 -188.1 -441 -129 112 -214 12 21 16 21 -738.1 113.4 -181.2 2 26.3 -181.2 2 -738 113 -181 2 173 -726 -181 2 -8.08 4.05 112.2 -1.0 14.8 0.005 35.0 1489 119 2014-04-13T15:41:41.101Z,1397403701.101 [Radio_Freewave](INFO): Powering down 2014-04-13T15:41:46.421Z,1397403706.421 [Radio_Freewave](INFO): Powering up 2014-04-13T15:41:47.799Z,1397403707.799 [Radio_Freewave](IMPORTANT): Starting PPPD with command:/sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0 2014-04-13T15:42:39.491Z,1397403759.491 [Radio_Freewave](INFO): Powering down 2014-04-13T15:42:42.925Z,1397403762.925 [Radio_Freewave](INFO): Powering up 2014-04-13T15:42:44.197Z,1397403764.197 [Radio_Freewave](IMPORTANT): Starting PPPD with command:/sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0 2014-04-13T15:42:52.632Z,1397403772.632 [Radio_Freewave](INFO): Powering down 2014-04-13T15:42:59.494Z,1397403779.494 [Radio_Freewave](INFO): Powering up 2014-04-13T15:43:00.187Z,1397403780.187 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:110 Calculated:120 2014-04-13T15:43:00.188Z,1397403780.188 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 -0.1 -0.1 -0.1 -0.1 -264.1 0 0 51.4 -342 157 444 40 11 23 10 21 -1049.0 156.2 1.2 -1059.7 80.6 2 -1049 156 80 2 41 -1059 80 2 -6.86 6.13 100.7 -1.0 15.3 0.005 35.0 1489 110 2014-04-13T15:43:00.805Z,1397403780.805 [Radio_Freewave](IMPORTANT): Starting PPPD with command:/sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0 2014-04-13T15:43:09.822Z,1397403789.822 [Radio_Freewave](INFO): Powering down 2014-04-13T15:54:30.270Z,1397404470.270 [keepstation:NeedComms] Running Loop=1 2014-04-13T15:54:30.270Z,1397404470.270 [keepstation:NeedComms](INFO): Aggregate::initialize keepstation:NeedComms 2014-04-13T15:54:30.270Z,1397404470.270 [keepstation:NeedComms:A] Running Loop=1 2014-04-13T15:54:30.270Z,1397404470.270 [keepstation:NeedComms:A](INFO): Aggregate::initialize keepstation:NeedComms:A 2014-04-13T15:54:30.984Z,1397404470.984 [keepstation:SURFACECOMMS] Running Loop=1 2014-04-13T15:54:30.984Z,1397404470.984 [keepstation:SURFACECOMMS](INFO): Aggregate::initialize keepstation:SURFACECOMMS 2014-04-13T15:54:30.984Z,1397404470.984 [keepstation:SURFACECOMMS:A.GoToSurface] Running Loop=1 2014-04-13T15:54:30.984Z,1397404470.984 [keepstation:SURFACECOMMS:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T15:57:38.205Z,1397404658.205 [Radio_Freewave](INFO): Powering up 2014-04-13T15:57:38.307Z,1397404658.307 [keepstation:SURFACECOMMS:B] Running Loop=1 2014-04-13T15:57:38.307Z,1397404658.307 [keepstation:SURFACECOMMS:B](INFO): Aggregate::initialize keepstation:SURFACECOMMS:B 2014-04-13T15:57:38.308Z,1397404658.308 [keepstation:SURFACECOMMS:B:A] Running Loop=1 2014-04-13T15:57:39.335Z,1397404659.335 [NAL9602](INFO): Powering up 2014-04-13T15:57:39.342Z,1397404659.342 [Radio_Freewave](IMPORTANT): Starting PPPD with command:/sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0 2014-04-13T15:57:50.059Z,1397404670.059 [NAL9602](INFO): NAL9602 initialized 2014-04-13T15:58:10.128Z,1397404690.128 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 43 of 46 2014-04-13T15:58:10.129Z,1397404690.129 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 1 1 1 0 11 -109.8 90.1 98 -76 -109 46 20 24 16 20 273.9 -259.7 -7.8 1 -226.3 297.2 54.9 1 276 -162 -11 2 -246 204 -11 2 -6.10 -7.34 170.8 103.1 12.6 0.005 35.0 1489 123 2014-04-13T15:58:14.531Z,1397404694.531 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=25403, MT Status=1, MTMSN=1758 2014-04-13T15:58:14.531Z,1397404694.531 [NAL9602](INFO): Data available in MT queue 2014-04-13T15:58:15.054Z,1397404695.054 [NAL9602](INFO): Received command:Stop 2014-04-13T15:58:15.098Z,1397404695.098 [CommandLine](IMPORTANT): got command stop 2014-04-13T15:58:15.110Z,1397404695.110 [keepstation] Stopped 2014-04-13T15:58:15.110Z,1397404695.110 [keepstation](INFO): Aggregate::uninitialize keepstation 2014-04-13T15:58:15.110Z,1397404695.110 [keepstation:AltEnvWrapper] Stopped 2014-04-13T15:58:15.110Z,1397404695.110 [keepstation:AltEnvWrapper](INFO): Aggregate::uninitialize keepstation:AltEnvWrapper 2014-04-13T15:58:15.110Z,1397404695.110 [keepstation:AltEnvWrapper:A.AltitudeEnvelope] Stopped 2014-04-13T15:58:15.111Z,1397404695.111 [keepstation:AltEnvWrapper:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent. 2014-04-13T15:58:15.111Z,1397404695.111 [keepstation:B.DepthEnvelope] Stopped 2014-04-13T15:58:15.111Z,1397404695.111 [keepstation:B.DepthEnvelope](DEBUG): Uninitialize. 2014-04-13T15:58:15.111Z,1397404695.111 [keepstation:SURFACECOMMS] Stopped 2014-04-13T15:58:15.111Z,1397404695.111 [keepstation:SURFACECOMMS](INFO): Aggregate::uninitialize keepstation:SURFACECOMMS 2014-04-13T15:58:15.111Z,1397404695.111 [keepstation:SURFACECOMMS:A.GoToSurface] Stopped 2014-04-13T15:58:15.111Z,1397404695.111 [keepstation:SURFACECOMMS:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T15:58:15.111Z,1397404695.111 [keepstation:SURFACECOMMS:B] Stopped 2014-04-13T15:58:15.111Z,1397404695.111 [keepstation:SURFACECOMMS:B](INFO): Aggregate::uninitialize keepstation:SURFACECOMMS:B 2014-04-13T15:58:15.111Z,1397404695.111 [keepstation:SURFACECOMMS:B:A] Stopped 2014-04-13T15:58:15.112Z,1397404695.112 [keepstation:OffshoreWrapper] Stopped 2014-04-13T15:58:15.112Z,1397404695.112 [keepstation:OffshoreWrapper](INFO): Aggregate::uninitialize keepstation:OffshoreWrapper 2014-04-13T15:58:15.112Z,1397404695.112 [keepstation:OffshoreWrapper:A.OffshoreEnvelope] Stopped 2014-04-13T15:58:15.112Z,1397404695.112 [keepstation:OffshoreWrapper:A.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent. 2014-04-13T15:58:15.112Z,1397404695.112 [keepstation:NeedComms] Stopped 2014-04-13T15:58:15.112Z,1397404695.112 [keepstation:NeedComms](INFO): Aggregate::uninitialize keepstation:NeedComms 2014-04-13T15:58:15.112Z,1397404695.112 [keepstation:NeedComms:A] Stopped 2014-04-13T15:58:15.112Z,1397404695.112 [keepstation:NeedComms:A](INFO): Aggregate::uninitialize keepstation:NeedComms:A 2014-04-13T15:58:15.112Z,1397404695.112 [keepstation:TransitToStation] Stopped 2014-04-13T15:58:15.113Z,1397404695.113 [keepstation:TransitToStation](INFO): Aggregate::uninitialize keepstation:TransitToStation 2014-04-13T15:58:15.113Z,1397404695.113 [keepstation:TransitToStation:A.Buoyancy] Stopped 2014-04-13T15:58:15.113Z,1397404695.113 [keepstation:TransitToStation:A.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2014-04-13T15:58:15.113Z,1397404695.113 [keepstation:TransitToStation:B.Pitch] Stopped 2014-04-13T15:58:15.113Z,1397404695.113 [keepstation:TransitToStation:C.Pitch] Stopped 2014-04-13T15:58:15.113Z,1397404695.113 [keepstation:TransitToStation:D.SetSpeed] Stopped 2014-04-13T15:58:15.113Z,1397404695.113 [keepstation:TransitToStation:D.SetSpeed](DEBUG): Uninitialize. 2014-04-13T15:58:15.113Z,1397404695.113 [keepstation:TransitToStation:Wpt1.Waypoint] Stopped 2014-04-13T15:58:15.113Z,1397404695.113 [keepstation:TransitToStation:Wpt1.Waypoint](DEBUG): Uninitialize WaypointComponent. 2014-04-13T15:58:15.610Z,1397404695.610 [MissionManager](IMPORTANT): Started mission Default 2014-04-13T15:58:15.610Z,1397404695.610 [Default] Running Loop=1 2014-04-13T15:58:15.610Z,1397404695.610 [Default](INFO): Aggregate::initialize Default 2014-04-13T15:58:15.611Z,1397404695.611 [Default:Iridium] Running Loop=1 2014-04-13T15:58:15.611Z,1397404695.611 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2014-04-13T15:58:15.611Z,1397404695.611 [Default:Iridium:A.SetSpeed] Running Loop=1 2014-04-13T15:58:15.611Z,1397404695.611 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2014-04-13T15:58:15.611Z,1397404695.611 [Default:Iridium:B.GoToSurface] Running Loop=1 2014-04-13T15:58:15.611Z,1397404695.611 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T15:58:15.612Z,1397404695.612 [Default:CallIridium] Running Loop=1 2014-04-13T15:58:15.612Z,1397404695.612 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2014-04-13T15:58:15.612Z,1397404695.612 [Default:CallIridium:A] Running Loop=1 2014-04-13T15:58:15.613Z,1397404695.613 [Default:CallIridium:A] Stopped 2014-04-13T15:58:15.613Z,1397404695.613 [Default:CallIridium:B] Running Loop=1 2014-04-13T15:58:15.613Z,1397404695.613 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2014-04-13T15:58:15.614Z,1397404695.614 [Default:Iridium:B.GoToSurface] Stopped 2014-04-13T15:58:15.614Z,1397404695.614 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T15:58:15.614Z,1397404695.614 [Default:Iridium:Read_Iridium] Running Loop=1 2014-04-13T15:58:16.007Z,1397404696.007 [Default:GPS] Running Loop=1 2014-04-13T15:58:16.007Z,1397404696.007 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2014-04-13T15:58:16.007Z,1397404696.007 [Default:GPS:A.SetSpeed] Running Loop=1 2014-04-13T15:58:16.007Z,1397404696.007 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2014-04-13T15:58:16.008Z,1397404696.008 [Default:GPS:B.GoToSurface] Running Loop=1 2014-04-13T15:58:16.008Z,1397404696.008 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T15:58:16.008Z,1397404696.008 [Default:GPS:B.GoToSurface] Stopped 2014-04-13T15:58:16.009Z,1397404696.009 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T15:58:16.009Z,1397404696.009 [Default:GPS:Read_GPS] Running Loop=1 2014-04-13T15:58:18.621Z,1397404698.621 [NAL9602](IMPORTANT): GPS fix at: 1397404660.00 2014-04-13T15:58:18.635Z,1397404698.635 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T15:58:18.635Z,1397404698.635 [DeadReckonUsingMultipleVelocitySources](DEBUG): horizontalPathLengthSinceLastFix_ = 807.773, recording fix residuals... 2014-04-13T15:58:18.640Z,1397404698.640 [Default:GPS:Read_GPS] Stopped 2014-04-13T15:58:18.640Z,1397404698.640 [Default:GPS:D] Running Loop=1 2014-04-13T15:58:19.197Z,1397404699.197 [Default:GPS:D] Stopped 2014-04-13T15:58:19.197Z,1397404699.197 [Default:GPS](INFO): Completed Default:GPS 2014-04-13T15:58:19.197Z,1397404699.197 [Default:GPS] Stopped 2014-04-13T15:58:19.197Z,1397404699.197 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2014-04-13T15:58:19.197Z,1397404699.197 [Default:GPS:A.SetSpeed] Stopped 2014-04-13T15:58:19.198Z,1397404699.198 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2014-04-13T15:58:54.182Z,1397404734.182 [NAL9602](INFO): SBD MO Status=2, MOMSN=25404, MT Status=2, MTMSN=0 2014-04-13T15:58:54.183Z,1397404734.183 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2014-04-13T15:59:20.373Z,1397404760.373 [NAL9602](INFO): SBD MO Status=2, MOMSN=25404, MT Status=2, MTMSN=0 2014-04-13T15:59:20.374Z,1397404760.374 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2014-04-13T15:59:46.067Z,1397404786.067 [NAL9602](INFO): SBD MO Status=2, MOMSN=25404, MT Status=2, MTMSN=0 2014-04-13T15:59:46.067Z,1397404786.067 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2014-04-13T16:00:36.311Z,1397404836.311 [NAL9602](INFO): SBD MO Status=1, MOMSN=25404, MT Status=0, MTMSN=0 2014-04-13T16:00:36.365Z,1397404836.365 [NAL9602](INFO): Sent 75 bytes from file Logs/20140413T132323/Courier0044.lzma 2014-04-13T16:00:36.365Z,1397404836.365 [NAL9602](INFO): Packets left to send: 0 2014-04-13T16:00:36.367Z,1397404836.367 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Courier0044.lzma.parts/0000.sbd 2014-04-13T16:00:36.367Z,1397404836.367 [NAL9602](INFO): Completed sending Logs/20140413T132323/Courier0044.lzma 2014-04-13T16:01:37.195Z,1397404897.195 [NAL9602](INFO): SBD MO Status=2, MOMSN=25405, MT Status=2, MTMSN=0 2014-04-13T16:01:37.195Z,1397404897.195 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2014-04-13T16:01:51.437Z,1397404911.437 [NAL9602](INFO): SBD MO Status=1, MOMSN=25405, MT Status=0, MTMSN=0 2014-04-13T16:01:51.517Z,1397404911.517 [NAL9602](INFO): Sent 332 bytes from file Logs/20140413T132323/Express0045.lzma 2014-04-13T16:01:51.517Z,1397404911.517 [NAL9602](INFO): Packets left to send: 1 2014-04-13T16:01:51.519Z,1397404911.519 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Express0045.lzma.parts/0001.sbd 2014-04-13T16:01:58.876Z,1397404918.876 [NAL9602](INFO): SBD MO Status=1, MOMSN=25406, MT Status=0, MTMSN=0 2014-04-13T16:01:58.925Z,1397404918.925 [NAL9602](INFO): Sent 128 bytes from file Logs/20140413T132323/Express0045.lzma 2014-04-13T16:01:58.925Z,1397404918.925 [NAL9602](INFO): Packets left to send: 0 2014-04-13T16:01:58.926Z,1397404918.926 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Express0045.lzma.parts/0000.sbd 2014-04-13T16:01:58.926Z,1397404918.926 [NAL9602](INFO): Completed sending Logs/20140413T132323/Express0045.lzma 2014-04-13T16:02:07.140Z,1397404927.140 [NAL9602](INFO): SBD MO Status=1, MOMSN=25407, MT Status=0, MTMSN=0 2014-04-13T16:02:07.202Z,1397404927.202 [NAL9602](INFO): Sent 60 bytes from file Logs/20140413T132323/Express0046.lzma 2014-04-13T16:02:07.202Z,1397404927.202 [NAL9602](INFO): Packets left to send: 0 2014-04-13T16:02:07.204Z,1397404927.204 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Express0046.lzma.parts/0000.sbd 2014-04-13T16:02:07.204Z,1397404927.204 [NAL9602](INFO): Completed sending Logs/20140413T132323/Express0046.lzma 2014-04-13T16:02:15.544Z,1397404935.544 [NAL9602](INFO): SBD MO Status=0, MOMSN=25408, MT Status=0, MTMSN=0 2014-04-13T16:02:30.033Z,1397404950.033 [NAL9602](INFO): SBD MO Status=1, MOMSN=25409, MT Status=0, MTMSN=0 2014-04-13T16:02:30.081Z,1397404950.081 [NAL9602](INFO): Sent 75 bytes from file Logs/20140413T132323/Courier0048.lzma 2014-04-13T16:02:30.081Z,1397404950.081 [NAL9602](INFO): Packets left to send: 0 2014-04-13T16:02:30.083Z,1397404950.083 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Courier0048.lzma.parts/0000.sbd 2014-04-13T16:02:30.083Z,1397404950.083 [NAL9602](INFO): Completed sending Logs/20140413T132323/Courier0048.lzma 2014-04-13T16:02:38.987Z,1397404958.987 [NAL9602](INFO): SBD MO Status=1, MOMSN=25410, MT Status=0, MTMSN=0 2014-04-13T16:02:39.035Z,1397404959.035 [NAL9602](INFO): Sent 116 bytes from file Logs/20140413T132323/Express0049.lzma 2014-04-13T16:02:39.035Z,1397404959.035 [NAL9602](INFO): Packets left to send: 0 2014-04-13T16:02:39.037Z,1397404959.037 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Express0049.lzma.parts/0000.sbd 2014-04-13T16:02:39.037Z,1397404959.037 [NAL9602](INFO): Completed sending Logs/20140413T132323/Express0049.lzma 2014-04-13T16:02:49.584Z,1397404969.584 [NAL9602](INFO): SBD MO Status=0, MOMSN=25411, MT Status=0, MTMSN=0 2014-04-13T16:02:49.687Z,1397404969.687 [Default:Iridium:Read_Iridium] Stopped 2014-04-13T16:02:49.691Z,1397404969.691 [Default:Iridium](INFO): Completed Default:Iridium 2014-04-13T16:02:49.692Z,1397404969.692 [Default:Iridium] Stopped 2014-04-13T16:02:49.692Z,1397404969.692 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2014-04-13T16:02:49.692Z,1397404969.692 [Default:Iridium:A.SetSpeed] Stopped 2014-04-13T16:02:49.692Z,1397404969.692 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2014-04-13T16:02:49.692Z,1397404969.692 [Default:WaitAtTheSurface] Running Loop=1 2014-04-13T16:02:49.692Z,1397404969.692 [Default:WaitAtTheSurface](INFO): Aggregate::initialize Default:WaitAtTheSurface 2014-04-13T16:02:49.692Z,1397404969.692 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Running Loop=1 2014-04-13T16:02:49.692Z,1397404969.692 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Initialize. 2014-04-13T16:02:49.692Z,1397404969.692 [Default:WaitAtTheSurface:B.GoToSurface] Running Loop=1 2014-04-13T16:02:49.692Z,1397404969.692 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T16:02:50.076Z,1397404970.076 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2014-04-13T16:02:50.077Z,1397404970.077 [Default:CallIridium:B] Stopped 2014-04-13T16:02:50.077Z,1397404970.077 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2014-04-13T16:02:50.077Z,1397404970.077 [Default:CallIridium](INFO): Completed Default:CallIridium 2014-04-13T16:02:50.077Z,1397404970.077 [Default:CallIridium] Stopped 2014-04-13T16:02:50.077Z,1397404970.077 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2014-04-13T16:03:00.306Z,1397404980.306 [NAL9602](INFO): Powering down 2014-04-13T16:07:30.264Z,1397405250.264 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T16:07:35.268Z,1397405255.268 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T16:07:40.264Z,1397405260.264 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T16:07:45.263Z,1397405265.263 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T16:07:50.264Z,1397405270.264 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T16:07:50.321Z,1397405270.321 [Default:CallIridium] Running Loop=1 2014-04-13T16:07:50.321Z,1397405270.321 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2014-04-13T16:07:50.325Z,1397405270.325 [Default:CallIridium:A] Running Loop=1 2014-04-13T16:07:50.326Z,1397405270.326 [Default:CallIridium:A] Stopped 2014-04-13T16:07:50.326Z,1397405270.326 [Default:CallIridium:B] Running Loop=1 2014-04-13T16:07:50.326Z,1397405270.326 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2014-04-13T16:07:55.333Z,1397405275.333 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T16:07:55.386Z,1397405275.386 [Default:Iridium] Running Loop=1 2014-04-13T16:07:55.386Z,1397405275.386 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2014-04-13T16:07:55.386Z,1397405275.386 [Default:Iridium:A.SetSpeed] Running Loop=1 2014-04-13T16:07:55.386Z,1397405275.386 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2014-04-13T16:07:55.386Z,1397405275.386 [Default:Iridium:B.GoToSurface] Running Loop=1 2014-04-13T16:07:55.386Z,1397405275.386 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T16:07:55.387Z,1397405275.387 [Default:Iridium:B.GoToSurface] Stopped 2014-04-13T16:07:55.387Z,1397405275.387 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T16:07:55.387Z,1397405275.387 [Default:Iridium:Read_Iridium] Running Loop=1 2014-04-13T16:07:55.387Z,1397405275.387 [Default:GPS] Running Loop=1 2014-04-13T16:07:55.388Z,1397405275.388 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2014-04-13T16:07:55.388Z,1397405275.388 [Default:GPS:A.SetSpeed] Running Loop=1 2014-04-13T16:07:55.388Z,1397405275.388 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2014-04-13T16:07:55.388Z,1397405275.388 [Default:GPS:B.GoToSurface] Running Loop=1 2014-04-13T16:07:55.388Z,1397405275.388 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T16:07:55.389Z,1397405275.389 [Default:GPS:B.GoToSurface] Stopped 2014-04-13T16:07:55.389Z,1397405275.389 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T16:07:55.389Z,1397405275.389 [Default:GPS:Read_GPS] Running Loop=1 2014-04-13T16:07:56.891Z,1397405276.891 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T16:07:56.958Z,1397405276.958 [NAL9602](INFO): Powering up 2014-04-13T16:08:07.909Z,1397405287.909 [NAL9602](INFO): NAL9602 initialized 2014-04-13T16:08:36.008Z,1397405316.008 [NAL9602](INFO): SBD MO Status=1, MOMSN=25412, MT Status=0, MTMSN=0 2014-04-13T16:08:36.056Z,1397405316.056 [NAL9602](INFO): Sent 45 bytes from file Logs/20140413T132323/Courier0052.lzma 2014-04-13T16:08:36.057Z,1397405316.057 [NAL9602](INFO): Packets left to send: 0 2014-04-13T16:08:36.059Z,1397405316.059 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Courier0052.lzma.parts/0000.sbd 2014-04-13T16:08:36.059Z,1397405316.059 [NAL9602](INFO): Completed sending Logs/20140413T132323/Courier0052.lzma 2014-04-13T16:08:45.070Z,1397405325.070 [NAL9602](INFO): SBD MO Status=1, MOMSN=25413, MT Status=0, MTMSN=0 2014-04-13T16:08:45.115Z,1397405325.115 [NAL9602](INFO): Sent 62 bytes from file Logs/20140413T132323/Express0053.lzma 2014-04-13T16:08:45.115Z,1397405325.115 [NAL9602](INFO): Packets left to send: 0 2014-04-13T16:08:45.117Z,1397405325.117 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Express0053.lzma.parts/0000.sbd 2014-04-13T16:08:45.117Z,1397405325.117 [NAL9602](INFO): Completed sending Logs/20140413T132323/Express0053.lzma 2014-04-13T16:09:13.536Z,1397405353.536 [NAL9602](INFO): SBD MO Status=2, MOMSN=25414, MT Status=2, MTMSN=0 2014-04-13T16:09:13.537Z,1397405353.537 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2014-04-13T16:09:14.855Z,1397405354.855 [NAL9602](IMPORTANT): GPS fix at: 1397405316.00 2014-04-13T16:09:14.868Z,1397405354.868 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T16:09:14.873Z,1397405354.873 [Default:GPS:Read_GPS] Stopped 2014-04-13T16:09:14.873Z,1397405354.873 [Default:GPS:D] Running Loop=1 2014-04-13T16:09:15.340Z,1397405355.340 [Default:GPS:D] Stopped 2014-04-13T16:09:15.340Z,1397405355.340 [Default:GPS](INFO): Completed Default:GPS 2014-04-13T16:09:15.340Z,1397405355.340 [Default:GPS] Stopped 2014-04-13T16:09:15.340Z,1397405355.340 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2014-04-13T16:09:15.340Z,1397405355.340 [Default:GPS:A.SetSpeed] Stopped 2014-04-13T16:09:15.340Z,1397405355.340 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2014-04-13T16:09:30.157Z,1397405370.157 [NAL9602](INFO): SBD MO Status=0, MOMSN=25414, MT Status=0, MTMSN=0 2014-04-13T16:09:30.254Z,1397405370.254 [Default:Iridium:Read_Iridium] Stopped 2014-04-13T16:09:30.254Z,1397405370.254 [Default:Iridium](INFO): Completed Default:Iridium 2014-04-13T16:09:30.254Z,1397405370.254 [Default:Iridium] Stopped 2014-04-13T16:09:30.254Z,1397405370.254 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2014-04-13T16:09:30.255Z,1397405370.255 [Default:Iridium:A.SetSpeed] Stopped 2014-04-13T16:09:30.255Z,1397405370.255 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2014-04-13T16:09:30.653Z,1397405370.653 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2014-04-13T16:09:30.653Z,1397405370.653 [Default:CallIridium:B] Stopped 2014-04-13T16:09:30.653Z,1397405370.653 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2014-04-13T16:09:30.653Z,1397405370.653 [Default:CallIridium](INFO): Completed Default:CallIridium 2014-04-13T16:09:30.654Z,1397405370.654 [Default:CallIridium] Stopped 2014-04-13T16:09:30.654Z,1397405370.654 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2014-04-13T16:09:40.867Z,1397405380.867 [NAL9602](INFO): Powering down 2014-04-13T16:14:30.878Z,1397405670.878 [Default:CallIridium] Running Loop=1 2014-04-13T16:14:30.878Z,1397405670.878 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2014-04-13T16:14:30.878Z,1397405670.878 [Default:CallIridium:A] Running Loop=1 2014-04-13T16:14:30.879Z,1397405670.879 [Default:CallIridium:A] Stopped 2014-04-13T16:14:30.879Z,1397405670.879 [Default:CallIridium:B] Running Loop=1 2014-04-13T16:14:30.879Z,1397405670.879 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2014-04-13T16:14:35.858Z,1397405675.858 [Default:Iridium] Running Loop=1 2014-04-13T16:14:35.858Z,1397405675.858 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2014-04-13T16:14:35.859Z,1397405675.859 [Default:Iridium:A.SetSpeed] Running Loop=1 2014-04-13T16:14:35.859Z,1397405675.859 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2014-04-13T16:14:35.859Z,1397405675.859 [Default:Iridium:B.GoToSurface] Running Loop=1 2014-04-13T16:14:35.859Z,1397405675.859 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T16:14:35.860Z,1397405675.860 [Default:Iridium:B.GoToSurface] Stopped 2014-04-13T16:14:35.860Z,1397405675.860 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T16:14:35.860Z,1397405675.860 [Default:Iridium:Read_Iridium] Running Loop=1 2014-04-13T16:14:35.860Z,1397405675.860 [Default:GPS] Running Loop=1 2014-04-13T16:14:35.860Z,1397405675.860 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2014-04-13T16:14:35.860Z,1397405675.860 [Default:GPS:A.SetSpeed] Running Loop=1 2014-04-13T16:14:35.860Z,1397405675.860 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2014-04-13T16:14:35.861Z,1397405675.861 [Default:GPS:B.GoToSurface] Running Loop=1 2014-04-13T16:14:35.861Z,1397405675.861 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T16:14:35.861Z,1397405675.861 [Default:GPS:B.GoToSurface] Stopped 2014-04-13T16:14:35.861Z,1397405675.861 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T16:14:35.862Z,1397405675.862 [Default:GPS:Read_GPS] Running Loop=1 2014-04-13T16:14:37.327Z,1397405677.327 [NAL9602](INFO): Powering up 2014-04-13T16:14:48.169Z,1397405688.169 [NAL9602](INFO): NAL9602 initialized 2014-04-13T16:15:14.649Z,1397405714.649 [NAL9602](INFO): SBD MO Status=1, MOMSN=25415, MT Status=0, MTMSN=0 2014-04-13T16:15:14.703Z,1397405714.703 [NAL9602](INFO): Sent 75 bytes from file Logs/20140413T132323/Courier0056.lzma 2014-04-13T16:15:14.703Z,1397405714.703 [NAL9602](INFO): Packets left to send: 0 2014-04-13T16:15:14.705Z,1397405714.705 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Courier0056.lzma.parts/0000.sbd 2014-04-13T16:15:14.705Z,1397405714.705 [NAL9602](INFO): Completed sending Logs/20140413T132323/Courier0056.lzma 2014-04-13T16:15:23.772Z,1397405723.772 [NAL9602](INFO): SBD MO Status=1, MOMSN=25416, MT Status=0, MTMSN=0 2014-04-13T16:15:23.821Z,1397405723.821 [NAL9602](INFO): Sent 108 bytes from file Logs/20140413T132323/Express0057.lzma 2014-04-13T16:15:23.821Z,1397405723.821 [NAL9602](INFO): Packets left to send: 0 2014-04-13T16:15:23.823Z,1397405723.823 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Express0057.lzma.parts/0000.sbd 2014-04-13T16:15:23.823Z,1397405723.823 [NAL9602](INFO): Completed sending Logs/20140413T132323/Express0057.lzma 2014-04-13T16:15:34.953Z,1397405734.953 [NAL9602](INFO): SBD MO Status=0, MOMSN=25417, MT Status=0, MTMSN=0 2014-04-13T16:15:35.048Z,1397405735.048 [Default:Iridium:Read_Iridium] Stopped 2014-04-13T16:15:35.049Z,1397405735.049 [Default:Iridium](INFO): Completed Default:Iridium 2014-04-13T16:15:35.049Z,1397405735.049 [Default:Iridium] Stopped 2014-04-13T16:15:35.049Z,1397405735.049 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2014-04-13T16:15:35.049Z,1397405735.049 [Default:Iridium:A.SetSpeed] Stopped 2014-04-13T16:15:35.049Z,1397405735.049 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2014-04-13T16:15:35.458Z,1397405735.458 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2014-04-13T16:15:35.458Z,1397405735.458 [Default:CallIridium:B] Stopped 2014-04-13T16:15:35.458Z,1397405735.458 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2014-04-13T16:15:35.458Z,1397405735.458 [Default:CallIridium](INFO): Completed Default:CallIridium 2014-04-13T16:15:35.458Z,1397405735.458 [Default:CallIridium] Stopped 2014-04-13T16:15:35.458Z,1397405735.458 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2014-04-13T16:15:36.265Z,1397405736.265 [NAL9602](IMPORTANT): GPS fix at: 1397405698.00 2014-04-13T16:15:36.278Z,1397405736.278 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T16:15:36.285Z,1397405736.285 [Default:GPS:Read_GPS] Stopped 2014-04-13T16:15:36.285Z,1397405736.285 [Default:GPS:D] Running Loop=1 2014-04-13T16:15:36.859Z,1397405736.859 [Default:GPS:D] Stopped 2014-04-13T16:15:36.860Z,1397405736.860 [Default:GPS](INFO): Completed Default:GPS 2014-04-13T16:15:36.860Z,1397405736.860 [Default:GPS] Stopped 2014-04-13T16:15:36.860Z,1397405736.860 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2014-04-13T16:15:36.860Z,1397405736.860 [Default:GPS:A.SetSpeed] Stopped 2014-04-13T16:15:36.860Z,1397405736.860 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2014-04-13T16:15:57.460Z,1397405757.460 [NAL9602](INFO): Powering down 2014-04-13T16:20:37.429Z,1397406037.429 [Default:CallIridium] Running Loop=1 2014-04-13T16:20:37.430Z,1397406037.430 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2014-04-13T16:20:37.430Z,1397406037.430 [Default:CallIridium:A] Running Loop=1 2014-04-13T16:20:37.435Z,1397406037.435 [Default:CallIridium:A] Stopped 2014-04-13T16:20:37.435Z,1397406037.435 [Default:CallIridium:B] Running Loop=1 2014-04-13T16:20:37.435Z,1397406037.435 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2014-04-13T16:20:42.465Z,1397406042.465 [Default:Iridium] Running Loop=1 2014-04-13T16:20:42.465Z,1397406042.465 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2014-04-13T16:20:42.465Z,1397406042.465 [Default:Iridium:A.SetSpeed] Running Loop=1 2014-04-13T16:20:42.465Z,1397406042.465 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2014-04-13T16:20:42.465Z,1397406042.465 [Default:Iridium:B.GoToSurface] Running Loop=1 2014-04-13T16:20:42.466Z,1397406042.466 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T16:20:42.466Z,1397406042.466 [Default:Iridium:B.GoToSurface] Stopped 2014-04-13T16:20:42.467Z,1397406042.467 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T16:20:42.467Z,1397406042.467 [Default:Iridium:Read_Iridium] Running Loop=1 2014-04-13T16:20:42.467Z,1397406042.467 [Default:GPS] Running Loop=1 2014-04-13T16:20:42.467Z,1397406042.467 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2014-04-13T16:20:42.467Z,1397406042.467 [Default:GPS:A.SetSpeed] Running Loop=1 2014-04-13T16:20:42.467Z,1397406042.467 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2014-04-13T16:20:42.467Z,1397406042.467 [Default:GPS:B.GoToSurface] Running Loop=1 2014-04-13T16:20:42.468Z,1397406042.468 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T16:20:42.468Z,1397406042.468 [Default:GPS:B.GoToSurface] Stopped 2014-04-13T16:20:42.468Z,1397406042.468 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T16:20:42.468Z,1397406042.468 [Default:GPS:Read_GPS] Running Loop=1 2014-04-13T16:20:43.949Z,1397406043.949 [NAL9602](INFO): Powering up 2014-04-13T16:20:54.702Z,1397406054.702 [NAL9602](INFO): NAL9602 initialized 2014-04-13T16:21:13.921Z,1397406073.921 [NAL9602](INFO): SBD MO Status=1, MOMSN=25418, MT Status=0, MTMSN=0 2014-04-13T16:21:13.972Z,1397406073.972 [NAL9602](INFO): Sent 75 bytes from file Logs/20140413T132323/Courier0060.lzma 2014-04-13T16:21:13.972Z,1397406073.972 [NAL9602](INFO): Packets left to send: 0 2014-04-13T16:21:13.974Z,1397406073.974 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Courier0060.lzma.parts/0000.sbd 2014-04-13T16:21:13.974Z,1397406073.974 [NAL9602](INFO): Completed sending Logs/20140413T132323/Courier0060.lzma 2014-04-13T16:21:28.372Z,1397406088.372 [NAL9602](INFO): SBD MO Status=1, MOMSN=25419, MT Status=0, MTMSN=0 2014-04-13T16:21:28.426Z,1397406088.426 [NAL9602](INFO): Sent 97 bytes from file Logs/20140413T132323/Express0061.lzma 2014-04-13T16:21:28.426Z,1397406088.426 [NAL9602](INFO): Packets left to send: 0 2014-04-13T16:21:28.428Z,1397406088.428 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Express0061.lzma.parts/0000.sbd 2014-04-13T16:21:28.428Z,1397406088.428 [NAL9602](INFO): Completed sending Logs/20140413T132323/Express0061.lzma 2014-04-13T16:21:39.934Z,1397406099.934 [NAL9602](INFO): SBD MO Status=0, MOMSN=25420, MT Status=0, MTMSN=0 2014-04-13T16:21:40.058Z,1397406100.058 [Default:Iridium:Read_Iridium] Stopped 2014-04-13T16:21:40.058Z,1397406100.058 [Default:Iridium](INFO): Completed Default:Iridium 2014-04-13T16:21:40.059Z,1397406100.059 [Default:Iridium] Stopped 2014-04-13T16:21:40.059Z,1397406100.059 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2014-04-13T16:21:40.059Z,1397406100.059 [Default:Iridium:A.SetSpeed] Stopped 2014-04-13T16:21:40.059Z,1397406100.059 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2014-04-13T16:21:40.489Z,1397406100.489 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2014-04-13T16:21:40.489Z,1397406100.489 [Default:CallIridium:B] Stopped 2014-04-13T16:21:40.489Z,1397406100.489 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2014-04-13T16:21:40.489Z,1397406100.489 [Default:CallIridium](INFO): Completed Default:CallIridium 2014-04-13T16:21:40.489Z,1397406100.489 [Default:CallIridium] Stopped 2014-04-13T16:21:40.490Z,1397406100.490 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2014-04-13T16:21:41.338Z,1397406101.338 [NAL9602](IMPORTANT): GPS fix at: 1397406063.00 2014-04-13T16:21:41.352Z,1397406101.352 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T16:21:41.356Z,1397406101.356 [Default:GPS:Read_GPS] Stopped 2014-04-13T16:21:41.356Z,1397406101.356 [Default:GPS:D] Running Loop=1 2014-04-13T16:21:41.812Z,1397406101.812 [Default:GPS:D] Stopped 2014-04-13T16:21:41.813Z,1397406101.813 [Default:GPS](INFO): Completed Default:GPS 2014-04-13T16:21:41.813Z,1397406101.813 [Default:GPS] Stopped 2014-04-13T16:21:41.813Z,1397406101.813 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2014-04-13T16:21:41.813Z,1397406101.813 [Default:GPS:A.SetSpeed] Stopped 2014-04-13T16:21:41.813Z,1397406101.813 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2014-04-13T16:22:02.377Z,1397406122.377 [NAL9602](INFO): Powering down 2014-04-13T16:25:37.319Z,1397406337.319 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535 2014-04-13T16:25:42.464Z,1397406342.464 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535 2014-04-13T16:25:47.343Z,1397406347.343 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535 2014-04-13T16:25:52.352Z,1397406352.352 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535 2014-04-13T16:25:57.350Z,1397406357.350 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535 2014-04-13T16:26:02.370Z,1397406362.370 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535 2014-04-13T16:26:07.374Z,1397406367.374 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535 2014-04-13T16:26:12.374Z,1397406372.374 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535 2014-04-13T16:26:17.390Z,1397406377.390 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535 2014-04-13T16:26:22.384Z,1397406382.384 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535 2014-04-13T16:26:42.454Z,1397406402.454 [Default:CallIridium] Running Loop=1 2014-04-13T16:26:42.454Z,1397406402.454 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2014-04-13T16:26:42.454Z,1397406402.454 [Default:CallIridium:A] Running Loop=1 2014-04-13T16:26:42.455Z,1397406402.455 [Default:CallIridium:A] Stopped 2014-04-13T16:26:42.455Z,1397406402.455 [Default:CallIridium:B] Running Loop=1 2014-04-13T16:26:42.455Z,1397406402.455 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2014-04-13T16:26:47.457Z,1397406407.457 [Default:Iridium] Running Loop=1 2014-04-13T16:26:47.457Z,1397406407.457 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2014-04-13T16:26:47.457Z,1397406407.457 [Default:Iridium:A.SetSpeed] Running Loop=1 2014-04-13T16:26:47.457Z,1397406407.457 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2014-04-13T16:26:47.458Z,1397406407.458 [Default:Iridium:B.GoToSurface] Running Loop=1 2014-04-13T16:26:47.458Z,1397406407.458 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T16:26:47.458Z,1397406407.458 [Default:Iridium:B.GoToSurface] Stopped 2014-04-13T16:26:47.458Z,1397406407.458 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T16:26:47.459Z,1397406407.459 [Default:Iridium:Read_Iridium] Running Loop=1 2014-04-13T16:26:47.459Z,1397406407.459 [Default:GPS] Running Loop=1 2014-04-13T16:26:47.459Z,1397406407.459 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2014-04-13T16:26:47.459Z,1397406407.459 [Default:GPS:A.SetSpeed] Running Loop=1 2014-04-13T16:26:47.459Z,1397406407.459 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2014-04-13T16:26:47.459Z,1397406407.459 [Default:GPS:B.GoToSurface] Running Loop=1 2014-04-13T16:26:47.459Z,1397406407.459 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T16:26:47.460Z,1397406407.460 [Default:GPS:B.GoToSurface] Stopped 2014-04-13T16:26:47.460Z,1397406407.460 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T16:26:47.460Z,1397406407.460 [Default:GPS:Read_GPS] Running Loop=1 2014-04-13T16:26:47.869Z,1397406407.869 [Radio_Freewave](INFO): Powering down 2014-04-13T16:26:49.189Z,1397406409.189 [NAL9602](INFO): Powering up 2014-04-13T16:26:54.304Z,1397406414.304 [MassServo](FAULT): Overload Error 2014-04-13T16:26:54.304Z,1397406414.304 [MassServo] Hardware Fault, FailCount= 1 2014-04-13T16:26:54.304Z,1397406414.304 [MassServo](ERROR): Hardware Fault 2014-04-13T16:26:54.346Z,1397406414.346 [CBIT](ERROR): Hardware Fault in component: MassServo 2014-04-13T16:26:54.736Z,1397406414.736 [Radio_Freewave](INFO): Powering up 2014-04-13T16:26:54.812Z,1397406414.812 [MassServo](DEBUG): Uninitialize Mass Servo. 2014-04-13T16:26:54.812Z,1397406414.812 [MassServo](INFO): Powering down 2014-04-13T16:26:55.857Z,1397406415.857 [Radio_Freewave](IMPORTANT): Starting PPPD with command:/sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0 2014-04-13T16:26:55.952Z,1397406415.952 [MassServo](DEBUG): Initializing EZServoServo. 2014-04-13T16:26:55.952Z,1397406415.952 [MassServo](DEBUG): Initializing MassServo. 2014-04-13T16:26:55.961Z,1397406415.961 [CBIT](INFO): Clearing failed state for component MassServo 2014-04-13T16:26:55.961Z,1397406415.961 [MassServo] No Fault, FailCount= 1 2014-04-13T16:27:00.024Z,1397406420.024 [NAL9602](INFO): NAL9602 initialized 2014-04-13T16:27:28.864Z,1397406448.864 [NAL9602](INFO): SBD MO Status=1, MOMSN=25421, MT Status=0, MTMSN=0 2014-04-13T16:27:28.913Z,1397406448.913 [NAL9602](INFO): Sent 75 bytes from file Logs/20140413T132323/Courier0064.lzma 2014-04-13T16:27:28.913Z,1397406448.913 [NAL9602](INFO): Packets left to send: 0 2014-04-13T16:27:28.915Z,1397406448.915 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Courier0064.lzma.parts/0000.sbd 2014-04-13T16:27:28.915Z,1397406448.915 [NAL9602](INFO): Completed sending Logs/20140413T132323/Courier0064.lzma 2014-04-13T16:27:38.884Z,1397406458.884 [NAL9602](INFO): SBD MO Status=1, MOMSN=25422, MT Status=0, MTMSN=0 2014-04-13T16:27:38.940Z,1397406458.940 [NAL9602](INFO): Sent 107 bytes from file Logs/20140413T132323/Express0065.lzma 2014-04-13T16:27:38.941Z,1397406458.941 [NAL9602](INFO): Packets left to send: 0 2014-04-13T16:27:38.942Z,1397406458.942 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Express0065.lzma.parts/0000.sbd 2014-04-13T16:27:38.943Z,1397406458.943 [NAL9602](INFO): Completed sending Logs/20140413T132323/Express0065.lzma 2014-04-13T16:27:50.807Z,1397406470.807 [NAL9602](INFO): SBD MO Status=0, MOMSN=25423, MT Status=0, MTMSN=0 2014-04-13T16:27:50.889Z,1397406470.889 [Default:Iridium:Read_Iridium] Stopped 2014-04-13T16:27:50.889Z,1397406470.889 [Default:Iridium](INFO): Completed Default:Iridium 2014-04-13T16:27:50.889Z,1397406470.889 [Default:Iridium] Stopped 2014-04-13T16:27:50.889Z,1397406470.889 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2014-04-13T16:27:50.890Z,1397406470.890 [Default:Iridium:A.SetSpeed] Stopped 2014-04-13T16:27:50.890Z,1397406470.890 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2014-04-13T16:27:51.339Z,1397406471.339 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2014-04-13T16:27:51.339Z,1397406471.339 [Default:CallIridium:B] Stopped 2014-04-13T16:27:51.339Z,1397406471.339 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2014-04-13T16:27:51.339Z,1397406471.339 [Default:CallIridium](INFO): Completed Default:CallIridium 2014-04-13T16:27:51.343Z,1397406471.343 [Default:CallIridium] Stopped 2014-04-13T16:27:51.343Z,1397406471.343 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2014-04-13T16:28:04.394Z,1397406484.394 [NAL9602](IMPORTANT): GPS fix at: 1397406446.00 2014-04-13T16:28:04.436Z,1397406484.436 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T16:28:04.444Z,1397406484.444 [Default:GPS:Read_GPS] Stopped 2014-04-13T16:28:04.444Z,1397406484.444 [Default:GPS:D] Running Loop=1 2014-04-13T16:28:04.873Z,1397406484.873 [Default:GPS:D] Stopped 2014-04-13T16:28:04.874Z,1397406484.874 [Default:GPS](INFO): Completed Default:GPS 2014-04-13T16:28:04.874Z,1397406484.874 [Default:GPS] Stopped 2014-04-13T16:28:04.874Z,1397406484.874 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2014-04-13T16:28:04.874Z,1397406484.874 [Default:GPS:A.SetSpeed] Stopped 2014-04-13T16:28:04.874Z,1397406484.874 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2014-04-13T16:28:25.459Z,1397406505.459 [NAL9602](INFO): Powering down 2014-04-13T16:29:50.390Z,1397406590.390 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2014-04-13T16:29:50.390Z,1397406590.390 [DVL_micro] Data Fault, FailCount= 1 2014-04-13T16:29:50.390Z,1397406590.390 [DVL_micro](ERROR): Data Fault 2014-04-13T16:29:50.450Z,1397406590.450 [CBIT](ERROR): Data Fault in component: DVL_micro 2014-04-13T16:29:55.438Z,1397406595.438 [DVL_micro](INFO): uninitialize:Powering down 2014-04-13T16:30:00.409Z,1397406600.409 [DVL_micro](FAULT): LCB fault: Software Overcurrent. 2014-04-13T16:30:00.409Z,1397406600.409 [DVL_micro] Hardware Fault, FailCount= 1 2014-04-13T16:30:00.409Z,1397406600.409 [DVL_micro](ERROR): Hardware Fault 2014-04-13T16:30:05.530Z,1397406605.530 [CBIT](INFO): Clearing failed state for component DVL_micro 2014-04-13T16:30:05.530Z,1397406605.530 [DVL_micro] No Fault, FailCount= 1 2014-04-13T16:30:10.439Z,1397406610.439 [DVL_micro](INFO): Initializing 2014-04-13T16:32:55.455Z,1397406775.455 [Default:CallIridium] Running Loop=1 2014-04-13T16:32:55.456Z,1397406775.456 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2014-04-13T16:32:55.456Z,1397406775.456 [Default:CallIridium:A] Running Loop=1 2014-04-13T16:32:55.457Z,1397406775.457 [Default:CallIridium:A] Stopped 2014-04-13T16:32:55.457Z,1397406775.457 [Default:CallIridium:B] Running Loop=1 2014-04-13T16:32:55.457Z,1397406775.457 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2014-04-13T16:33:00.465Z,1397406780.465 [Default:Iridium] Running Loop=1 2014-04-13T16:33:00.465Z,1397406780.465 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2014-04-13T16:33:00.465Z,1397406780.465 [Default:Iridium:A.SetSpeed] Running Loop=1 2014-04-13T16:33:00.465Z,1397406780.465 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2014-04-13T16:33:00.465Z,1397406780.465 [Default:Iridium:B.GoToSurface] Running Loop=1 2014-04-13T16:33:00.465Z,1397406780.465 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T16:33:00.466Z,1397406780.466 [Default:Iridium:B.GoToSurface] Stopped 2014-04-13T16:33:00.466Z,1397406780.466 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T16:33:00.466Z,1397406780.466 [Default:Iridium:Read_Iridium] Running Loop=1 2014-04-13T16:33:00.467Z,1397406780.467 [Default:GPS] Running Loop=1 2014-04-13T16:33:00.467Z,1397406780.467 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2014-04-13T16:33:00.467Z,1397406780.467 [Default:GPS:A.SetSpeed] Running Loop=1 2014-04-13T16:33:00.467Z,1397406780.467 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2014-04-13T16:33:00.467Z,1397406780.467 [Default:GPS:B.GoToSurface] Running Loop=1 2014-04-13T16:33:00.467Z,1397406780.467 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T16:33:00.468Z,1397406780.468 [Default:GPS:B.GoToSurface] Stopped 2014-04-13T16:33:00.468Z,1397406780.468 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T16:33:00.468Z,1397406780.468 [Default:GPS:Read_GPS] Running Loop=1 2014-04-13T16:33:02.027Z,1397406782.027 [NAL9602](INFO): Powering up 2014-04-13T16:33:12.703Z,1397406792.703 [NAL9602](INFO): NAL9602 initialized 2014-04-13T16:33:30.659Z,1397406810.659 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2014-04-13T16:33:30.659Z,1397406810.659 [DVL_micro] Data Fault, FailCount= 1 2014-04-13T16:33:30.659Z,1397406810.659 [DVL_micro](ERROR): Data Fault 2014-04-13T16:33:30.712Z,1397406810.712 [CBIT](ERROR): Data Fault in component: DVL_micro 2014-04-13T16:33:31.140Z,1397406811.140 [DVL_micro](INFO): uninitialize:Powering down 2014-04-13T16:33:31.143Z,1397406811.143 [NAL9602](INFO): SBD MO Status=1, MOMSN=25424, MT Status=0, MTMSN=0 2014-04-13T16:33:31.191Z,1397406811.191 [NAL9602](INFO): Sent 75 bytes from file Logs/20140413T132323/Courier0068.lzma 2014-04-13T16:33:31.191Z,1397406811.191 [NAL9602](INFO): Packets left to send: 0 2014-04-13T16:33:31.192Z,1397406811.192 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Courier0068.lzma.parts/0000.sbd 2014-04-13T16:33:31.193Z,1397406811.193 [NAL9602](INFO): Completed sending Logs/20140413T132323/Courier0068.lzma 2014-04-13T16:33:31.608Z,1397406811.608 [DVL_micro](FAULT): LCB fault: Software Overcurrent. 2014-04-13T16:33:31.608Z,1397406811.608 [DVL_micro] Hardware Fault, FailCount= 1 2014-04-13T16:33:31.609Z,1397406811.609 [DVL_micro](ERROR): Hardware Fault 2014-04-13T16:33:34.931Z,1397406814.931 [CBIT](INFO): Clearing failed state for component DVL_micro 2014-04-13T16:33:34.931Z,1397406814.931 [DVL_micro] No Fault, FailCount= 1 2014-04-13T16:33:35.349Z,1397406815.349 [DVL_micro](INFO): Initializing 2014-04-13T16:33:40.865Z,1397406820.865 [NAL9602](INFO): SBD MO Status=1, MOMSN=25425, MT Status=0, MTMSN=0 2014-04-13T16:33:40.918Z,1397406820.918 [NAL9602](INFO): Sent 332 bytes from file Logs/20140413T132323/Express0069.lzma 2014-04-13T16:33:40.918Z,1397406820.918 [NAL9602](INFO): Packets left to send: 1 2014-04-13T16:33:40.920Z,1397406820.920 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Express0069.lzma.parts/0001.sbd 2014-04-13T16:33:51.374Z,1397406831.374 [NAL9602](INFO): SBD MO Status=1, MOMSN=25426, MT Status=0, MTMSN=0 2014-04-13T16:33:51.422Z,1397406831.422 [NAL9602](INFO): Sent 9 bytes from file Logs/20140413T132323/Express0069.lzma 2014-04-13T16:33:51.422Z,1397406831.422 [NAL9602](INFO): Packets left to send: 0 2014-04-13T16:33:51.423Z,1397406831.423 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Express0069.lzma.parts/0000.sbd 2014-04-13T16:33:51.424Z,1397406831.424 [NAL9602](INFO): Completed sending Logs/20140413T132323/Express0069.lzma 2014-04-13T16:34:02.936Z,1397406842.936 [NAL9602](INFO): SBD MO Status=0, MOMSN=25427, MT Status=0, MTMSN=0 2014-04-13T16:34:03.051Z,1397406843.051 [Default:Iridium:Read_Iridium] Stopped 2014-04-13T16:34:03.052Z,1397406843.052 [Default:Iridium](INFO): Completed Default:Iridium 2014-04-13T16:34:03.052Z,1397406843.052 [Default:Iridium] Stopped 2014-04-13T16:34:03.052Z,1397406843.052 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2014-04-13T16:34:03.052Z,1397406843.052 [Default:Iridium:A.SetSpeed] Stopped 2014-04-13T16:34:03.052Z,1397406843.052 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2014-04-13T16:34:03.462Z,1397406843.462 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2014-04-13T16:34:03.462Z,1397406843.462 [Default:CallIridium:B] Stopped 2014-04-13T16:34:03.462Z,1397406843.462 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2014-04-13T16:34:03.462Z,1397406843.462 [Default:CallIridium](INFO): Completed Default:CallIridium 2014-04-13T16:34:03.462Z,1397406843.462 [Default:CallIridium] Stopped 2014-04-13T16:34:03.462Z,1397406843.462 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2014-04-13T16:34:04.327Z,1397406844.327 [NAL9602](IMPORTANT): GPS fix at: 1397406806.00 2014-04-13T16:34:04.357Z,1397406844.357 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T16:34:04.361Z,1397406844.361 [Default:GPS:Read_GPS] Stopped 2014-04-13T16:34:04.361Z,1397406844.361 [Default:GPS:D] Running Loop=1 2014-04-13T16:34:04.757Z,1397406844.757 [Default:GPS:D] Stopped 2014-04-13T16:34:04.757Z,1397406844.757 [Default:GPS](INFO): Completed Default:GPS 2014-04-13T16:34:04.757Z,1397406844.757 [Default:GPS] Stopped 2014-04-13T16:34:04.757Z,1397406844.757 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2014-04-13T16:34:04.758Z,1397406844.758 [Default:GPS:A.SetSpeed] Stopped 2014-04-13T16:34:04.758Z,1397406844.758 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2014-04-13T16:34:25.289Z,1397406865.289 [NAL9602](INFO): Powering down 2014-04-13T16:36:40.345Z,1397407000.345 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2014-04-13T16:36:40.345Z,1397407000.345 [DVL_micro] Data Fault, FailCount= 1 2014-04-13T16:36:40.345Z,1397407000.345 [DVL_micro](ERROR): Data Fault 2014-04-13T16:36:40.376Z,1397407000.376 [CBIT](ERROR): Data Fault in component: DVL_micro 2014-04-13T16:36:45.337Z,1397407005.337 [DVL_micro](INFO): uninitialize:Powering down 2014-04-13T16:36:50.361Z,1397407010.361 [DVL_micro](FAULT): LCB fault: Software Overcurrent. 2014-04-13T16:36:50.361Z,1397407010.361 [DVL_micro] Hardware Fault, FailCount= 1 2014-04-13T16:36:50.362Z,1397407010.362 [DVL_micro](ERROR): Hardware Fault 2014-04-13T16:36:55.370Z,1397407015.370 [CBIT](INFO): Clearing failed state for component DVL_micro 2014-04-13T16:36:55.370Z,1397407015.370 [DVL_micro] No Fault, FailCount= 1 2014-04-13T16:37:00.355Z,1397407020.355 [DVL_micro](INFO): Initializing 2014-04-13T16:37:05.291Z,1397407025.291 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T16:37:10.338Z,1397407030.338 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T16:37:15.331Z,1397407035.331 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T16:37:20.346Z,1397407040.346 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T16:37:25.291Z,1397407045.291 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T16:37:30.327Z,1397407050.327 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T16:37:40.337Z,1397407060.337 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T16:37:45.334Z,1397407065.334 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T16:37:50.336Z,1397407070.336 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T16:39:05.364Z,1397407145.364 [Default:CallIridium] Running Loop=1 2014-04-13T16:39:05.364Z,1397407145.364 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2014-04-13T16:39:05.365Z,1397407145.365 [Default:CallIridium:A] Running Loop=1 2014-04-13T16:39:05.365Z,1397407145.365 [Default:CallIridium:A] Stopped 2014-04-13T16:39:05.365Z,1397407145.365 [Default:CallIridium:B] Running Loop=1 2014-04-13T16:39:05.365Z,1397407145.365 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2014-04-13T16:39:10.367Z,1397407150.367 [Default:Iridium] Running Loop=1 2014-04-13T16:39:10.367Z,1397407150.367 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2014-04-13T16:39:10.367Z,1397407150.367 [Default:Iridium:A.SetSpeed] Running Loop=1 2014-04-13T16:39:10.368Z,1397407150.368 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2014-04-13T16:39:10.368Z,1397407150.368 [Default:Iridium:B.GoToSurface] Running Loop=1 2014-04-13T16:39:10.368Z,1397407150.368 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T16:39:10.369Z,1397407150.369 [Default:Iridium:B.GoToSurface] Stopped 2014-04-13T16:39:10.369Z,1397407150.369 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T16:39:10.369Z,1397407150.369 [Default:Iridium:Read_Iridium] Running Loop=1 2014-04-13T16:39:10.369Z,1397407150.369 [Default:GPS] Running Loop=1 2014-04-13T16:39:10.369Z,1397407150.369 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2014-04-13T16:39:10.370Z,1397407150.370 [Default:GPS:A.SetSpeed] Running Loop=1 2014-04-13T16:39:10.370Z,1397407150.370 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2014-04-13T16:39:10.370Z,1397407150.370 [Default:GPS:B.GoToSurface] Running Loop=1 2014-04-13T16:39:10.370Z,1397407150.370 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T16:39:10.371Z,1397407150.371 [Default:GPS:B.GoToSurface] Stopped 2014-04-13T16:39:10.371Z,1397407150.371 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T16:39:10.371Z,1397407150.371 [Default:GPS:Read_GPS] Running Loop=1 2014-04-13T16:39:11.970Z,1397407151.970 [NAL9602](INFO): Powering up 2014-04-13T16:39:22.716Z,1397407162.716 [NAL9602](INFO): NAL9602 initialized 2014-04-13T16:39:41.674Z,1397407181.674 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=25428, MT Status=1, MTMSN=1759 2014-04-13T16:39:41.725Z,1397407181.725 [NAL9602](INFO): Sent 75 bytes from file Logs/20140413T132323/Courier0072.lzma 2014-04-13T16:39:41.725Z,1397407181.725 [NAL9602](INFO): Packets left to send: 0 2014-04-13T16:39:41.727Z,1397407181.727 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Courier0072.lzma.parts/0000.sbd 2014-04-13T16:39:41.727Z,1397407181.727 [NAL9602](INFO): Completed sending Logs/20140413T132323/Courier0072.lzma 2014-04-13T16:39:42.386Z,1397407182.386 [NAL9602](INFO): Received command:Restart app 2014-04-13T16:39:42.439Z,1397407182.439 [CommandLine](IMPORTANT): got command restart application 2014-04-13T16:39:43.544Z,1397407183.544 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2014-04-13T16:39:43.546Z,1397407183.546 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2014-04-13T16:39:43.757Z,1397407183.757 [NAL9602](IMPORTANT): GPS fix at: 1397407145.00 2014-04-13T16:39:43.771Z,1397407183.771 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T16:39:43.775Z,1397407183.775 [Default:GPS:Read_GPS] Stopped 2014-04-13T16:39:43.776Z,1397407183.776 [Default:GPS:D] Running Loop=1 2014-04-13T16:39:43.948Z,1397407183.948 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2014-04-13T16:39:44.201Z,1397407184.201 [WetLabsBB2FL](INFO): Powering down 2014-04-13T16:39:44.209Z,1397407184.209 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler 2014-04-13T16:39:44.232Z,1397407184.232 [Default:GPS:D] Stopped 2014-04-13T16:39:44.233Z,1397407184.233 [Default:GPS](INFO): Completed Default:GPS 2014-04-13T16:39:44.233Z,1397407184.233 [Default:GPS] Stopped 2014-04-13T16:39:44.233Z,1397407184.233 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2014-04-13T16:39:44.234Z,1397407184.234 [Default:GPS:A.SetSpeed] Stopped 2014-04-13T16:39:44.234Z,1397407184.234 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2014-04-13T16:39:44.569Z,1397407184.569 [CTD_NeilBrown](INFO): Powering down 2014-04-13T16:39:44.589Z,1397407184.589 [ComponentRegistry](INFO): Shutting down AsyncPiEstimator ThreadHandler 2014-04-13T16:39:44.609Z,1397407184.609 [AsyncPiEstimator](DEBUG): Uninitialize AsyncPiEstimator. 2014-04-13T16:39:44.619Z,1397407184.619 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2014-04-13T16:39:44.666Z,1397407184.666 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2014-04-13T16:39:44.666Z,1397407184.666 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2014-04-13T16:39:44.679Z,1397407184.679 [controlThread](DEBUG): Uninitializing ControlThread 2014-04-13T16:39:44.680Z,1397407184.680 [AHRS_sp3003D](INFO): Powering down 2014-04-13T16:39:44.681Z,1397407184.681 [DVL_micro](INFO): uninitialize:Powering down 2014-04-13T16:39:44.682Z,1397407184.682 [NAL9602](INFO): Powering down 2014-04-13T16:39:44.718Z,1397407184.718 [Radio_Freewave](INFO): Powering down 2014-04-13T16:39:44.730Z,1397407184.730 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2014-04-13T16:39:44.731Z,1397407184.731 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2014-04-13T16:39:44.732Z,1397407184.732 [Default] Stopped 2014-04-13T16:39:44.732Z,1397407184.732 [Default](INFO): Aggregate::uninitialize Default 2014-04-13T16:39:44.732Z,1397407184.732 [Default:Iridium] Stopped 2014-04-13T16:39:44.732Z,1397407184.732 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2014-04-13T16:39:44.732Z,1397407184.732 [Default:Iridium:A.SetSpeed] Stopped 2014-04-13T16:39:44.732Z,1397407184.732 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2014-04-13T16:39:44.733Z,1397407184.733 [Default:Iridium:Read_Iridium] Stopped 2014-04-13T16:39:44.733Z,1397407184.733 [Default:CallIridium] Stopped 2014-04-13T16:39:44.733Z,1397407184.733 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2014-04-13T16:39:44.733Z,1397407184.733 [Default:CallIridium:B] Stopped 2014-04-13T16:39:44.741Z,1397407184.741 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2014-04-13T16:39:44.742Z,1397407184.742 [Default:WaitAtTheSurface] Stopped 2014-04-13T16:39:44.742Z,1397407184.742 [Default:WaitAtTheSurface](INFO): Aggregate::uninitialize Default:WaitAtTheSurface 2014-04-13T16:39:44.742Z,1397407184.742 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Stopped 2014-04-13T16:39:44.742Z,1397407184.742 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Uninitialize. 2014-04-13T16:39:44.742Z,1397407184.742 [Default:WaitAtTheSurface:B.GoToSurface] Stopped 2014-04-13T16:39:44.742Z,1397407184.742 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T16:39:44.756Z,1397407184.756 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2014-04-13T16:39:44.757Z,1397407184.757 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2014-04-13T16:39:44.766Z,1397407184.766 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2014-04-13T16:39:44.766Z,1397407184.766 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2014-04-13T16:39:44.766Z,1397407184.766 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2014-04-13T16:39:44.766Z,1397407184.766 [BuoyancyServo](INFO): Powering down 2014-04-13T16:39:44.782Z,1397407184.782 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2014-04-13T16:39:44.782Z,1397407184.782 [ElevatorServo](INFO): Powering down 2014-04-13T16:39:44.783Z,1397407184.783 [MassServo](DEBUG): Uninitialize Mass Servo. 2014-04-13T16:39:44.783Z,1397407184.783 [MassServo](INFO): Powering down 2014-04-13T16:39:44.784Z,1397407184.784 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2014-04-13T16:39:44.785Z,1397407184.785 [RudderServo](INFO): Powering down 2014-04-13T16:39:44.786Z,1397407184.786 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2014-04-13T16:39:44.786Z,1397407184.786 [ThrusterServo](INFO): Powering down 2014-04-13T16:39:44.787Z,1397407184.787 [SBIT](DEBUG): Uninitialize SBIT Component. 2014-04-13T16:39:44.787Z,1397407184.787 [IBIT](DEBUG): Uninitialize IBIT Component. 2014-04-13T16:39:44.787Z,1397407184.787 [CBIT](DEBUG): Uninitialize CBIT Component.