2014-04-13T04:02:09.858Z,1397361729.858 [Supervisor](DEBUG): Initializing supervisor. 2014-04-13T04:02:09.861Z,1397361729.861 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0 2014-04-13T04:02:09.861Z,1397361729.861 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2014-04-13T04:02:09.862Z,1397361729.862 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0 2014-04-13T04:02:09.866Z,1397361729.866 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2014-04-13T04:02:09.877Z,1397361729.877 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2014-04-13T04:02:09.878Z,1397361729.878 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0 2014-04-13T04:02:09.879Z,1397361729.879 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2014-04-13T04:02:09.880Z,1397361729.880 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0 2014-04-13T04:02:09.882Z,1397361729.882 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2014-04-13T04:02:09.883Z,1397361729.883 [Supervisor](INFO): Looking for Config files in directory: Config/ 2014-04-13T04:02:09.884Z,1397361729.884 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2014-04-13T04:02:10.238Z,1397361730.238 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2014-04-13T04:02:10.239Z,1397361730.239 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2014-04-13T04:02:10.509Z,1397361730.509 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2014-04-13T04:02:10.510Z,1397361730.510 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2014-04-13T04:02:10.595Z,1397361730.595 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2014-04-13T04:02:10.596Z,1397361730.596 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2014-04-13T04:02:10.790Z,1397361730.790 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2014-04-13T04:02:10.790Z,1397361730.790 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2014-04-13T04:02:10.948Z,1397361730.948 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2014-04-13T04:02:10.949Z,1397361730.949 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2014-04-13T04:02:11.249Z,1397361731.249 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2014-04-13T04:02:11.249Z,1397361731.249 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2014-04-13T04:02:11.437Z,1397361731.437 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2014-04-13T04:02:11.438Z,1397361731.438 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2014-04-13T04:02:11.771Z,1397361731.771 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2014-04-13T04:02:11.772Z,1397361731.772 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2014-04-13T04:02:11.886Z,1397361731.886 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2014-04-13T04:02:11.886Z,1397361731.886 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2014-04-13T04:02:12.386Z,1397361732.386 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2014-04-13T04:02:12.386Z,1397361732.386 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2014-04-13T04:02:12.496Z,1397361732.496 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2014-04-13T04:02:12.497Z,1397361732.497 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2014-04-13T04:02:12.583Z,1397361732.583 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2014-04-13T04:02:12.695Z,1397361732.695 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2014-04-13T04:02:12.695Z,1397361732.695 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2014-04-13T04:02:12.852Z,1397361732.852 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2014-04-13T04:02:12.853Z,1397361732.853 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2014-04-13T04:02:13.022Z,1397361733.022 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2014-04-13T04:02:13.024Z,1397361733.024 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2014-04-13T04:02:13.025Z,1397361733.025 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2014-04-13T04:02:13.131Z,1397361733.131 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2014-04-13T04:02:13.259Z,1397361733.259 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2014-04-13T04:02:13.355Z,1397361733.355 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2014-04-13T04:02:13.463Z,1397361733.463 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2014-04-13T04:02:13.645Z,1397361733.645 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2014-04-13T04:02:13.770Z,1397361733.770 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2014-04-13T04:02:13.856Z,1397361733.856 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2014-04-13T04:02:13.958Z,1397361733.958 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2014-04-13T04:02:14.059Z,1397361734.059 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2014-04-13T04:02:14.060Z,1397361734.060 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2014-04-13T04:02:14.393Z,1397361734.393 [AHRS_sp3003D] Loaded 2014-04-13T04:02:14.393Z,1397361734.393 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread. 2014-04-13T04:02:14.685Z,1397361734.685 [Batt_Ocean_Server] Loaded 2014-04-13T04:02:14.685Z,1397361734.685 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread. 2014-04-13T04:02:14.698Z,1397361734.698 [Depth_Keller] Loaded 2014-04-13T04:02:14.699Z,1397361734.699 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2014-04-13T04:02:14.704Z,1397361734.704 [DropWeight] Loaded 2014-04-13T04:02:14.704Z,1397361734.704 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2014-04-13T04:02:14.842Z,1397361734.842 [DVL_micro] Loaded 2014-04-13T04:02:14.842Z,1397361734.842 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2014-04-13T04:02:14.942Z,1397361734.942 [NAL9602] Loaded 2014-04-13T04:02:14.942Z,1397361734.942 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2014-04-13T04:02:14.993Z,1397361734.993 [Onboard] Loaded 2014-04-13T04:02:14.993Z,1397361734.993 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2014-04-13T04:02:15.000Z,1397361735.000 [Radio_Freewave] Loaded 2014-04-13T04:02:15.001Z,1397361735.001 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread. 2014-04-13T04:02:15.007Z,1397361735.007 [SCPI] Loaded 2014-04-13T04:02:15.007Z,1397361735.007 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread. 2014-04-13T04:02:15.008Z,1397361735.008 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2014-04-13T04:02:15.009Z,1397361735.009 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2014-04-13T04:02:15.169Z,1397361735.169 [InternalSim] Loaded 2014-04-13T04:02:15.169Z,1397361735.169 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread. 2014-04-13T04:02:15.170Z,1397361735.170 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2014-04-13T04:02:15.171Z,1397361735.171 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2014-04-13T04:02:15.405Z,1397361735.405 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2014-04-13T04:02:15.406Z,1397361735.406 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2014-04-13T04:02:15.411Z,1397361735.411 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator. 2014-04-13T04:02:15.416Z,1397361735.416 [AsyncPiEstimator] Loaded 2014-04-13T04:02:15.417Z,1397361735.417 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread. 2014-04-13T04:02:15.418Z,1397361735.418 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 4069E4E0 2014-04-13T04:02:15.419Z,1397361735.419 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2014-04-13T04:02:15.419Z,1397361735.419 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2014-04-13T04:02:15.496Z,1397361735.496 [DeadReckonUsingMultipleVelocitySources] Loaded 2014-04-13T04:02:15.497Z,1397361735.497 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2014-04-13T04:02:15.513Z,1397361735.513 [NavChart] Loaded 2014-04-13T04:02:15.513Z,1397361735.513 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2014-04-13T04:02:15.514Z,1397361735.514 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2014-04-13T04:02:15.515Z,1397361735.515 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2014-04-13T04:02:15.562Z,1397361735.562 [VerticalControl](DEBUG): Construct VerticalControl. 2014-04-13T04:02:15.671Z,1397361735.671 [VerticalControl] Loaded 2014-04-13T04:02:15.671Z,1397361735.671 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2014-04-13T04:02:15.672Z,1397361735.672 [HorizontalControl](DEBUG): Construct HorizontalControl. 2014-04-13T04:02:15.738Z,1397361735.738 [HorizontalControl] Loaded 2014-04-13T04:02:15.738Z,1397361735.738 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2014-04-13T04:02:15.739Z,1397361735.739 [SpeedControl](DEBUG): Construct SpeedControl. 2014-04-13T04:02:15.741Z,1397361735.741 [SpeedControl] Loaded 2014-04-13T04:02:15.741Z,1397361735.741 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2014-04-13T04:02:15.742Z,1397361735.742 [LoopControl](DEBUG): Construct LoopControl. 2014-04-13T04:02:15.742Z,1397361735.742 [LoopControl] Loaded 2014-04-13T04:02:15.742Z,1397361735.742 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2014-04-13T04:02:15.743Z,1397361735.743 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2014-04-13T04:02:15.743Z,1397361735.743 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2014-04-13T04:02:15.762Z,1397361735.762 [DepthRateCalculator] Loaded 2014-04-13T04:02:15.762Z,1397361735.762 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2014-04-13T04:02:15.767Z,1397361735.767 [PitchRateCalculator] Loaded 2014-04-13T04:02:15.768Z,1397361735.768 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2014-04-13T04:02:15.775Z,1397361735.775 [SpeedCalculator] Loaded 2014-04-13T04:02:15.775Z,1397361735.775 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2014-04-13T04:02:15.781Z,1397361735.781 [YawRateCalculator] Loaded 2014-04-13T04:02:15.781Z,1397361735.781 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2014-04-13T04:02:15.781Z,1397361735.781 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2014-04-13T04:02:15.782Z,1397361735.782 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2014-04-13T04:02:15.885Z,1397361735.885 [CTD_NeilBrown] Loaded 2014-04-13T04:02:15.885Z,1397361735.885 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2014-04-13T04:02:15.886Z,1397361735.886 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 407404E0 2014-04-13T04:02:15.901Z,1397361735.901 [PAR_Licor] Loaded 2014-04-13T04:02:15.901Z,1397361735.901 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2014-04-13T04:02:15.936Z,1397361735.936 [WetLabsBB2FL] Loaded 2014-04-13T04:02:15.936Z,1397361735.936 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2014-04-13T04:02:15.937Z,1397361735.937 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407704E0 2014-04-13T04:02:15.938Z,1397361735.938 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2014-04-13T04:02:15.938Z,1397361735.938 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2014-04-13T04:02:16.031Z,1397361736.031 [SBIT](DEBUG): Construct Startup Built In Test. 2014-04-13T04:02:16.043Z,1397361736.043 [SBIT] Loaded 2014-04-13T04:02:16.043Z,1397361736.043 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2014-04-13T04:02:16.044Z,1397361736.044 [IBIT](DEBUG): Construct Initiated Built In Test. 2014-04-13T04:02:16.056Z,1397361736.056 [IBIT] Loaded 2014-04-13T04:02:16.056Z,1397361736.056 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2014-04-13T04:02:16.058Z,1397361736.058 [CBIT](DEBUG): Construct CBIT Built In Test. 2014-04-13T04:02:16.126Z,1397361736.126 [CBIT] Loaded 2014-04-13T04:02:16.126Z,1397361736.126 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2014-04-13T04:02:16.126Z,1397361736.126 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2014-04-13T04:02:16.127Z,1397361736.127 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2014-04-13T04:02:16.166Z,1397361736.166 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2014-04-13T04:02:16.167Z,1397361736.167 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2014-04-13T04:02:16.263Z,1397361736.263 [BuoyancyServo] Loaded 2014-04-13T04:02:16.263Z,1397361736.263 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2014-04-13T04:02:16.275Z,1397361736.275 [ElevatorServo] Loaded 2014-04-13T04:02:16.275Z,1397361736.275 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2014-04-13T04:02:16.287Z,1397361736.287 [MassServo] Loaded 2014-04-13T04:02:16.287Z,1397361736.287 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2014-04-13T04:02:16.299Z,1397361736.299 [RudderServo] Loaded 2014-04-13T04:02:16.299Z,1397361736.299 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2014-04-13T04:02:16.311Z,1397361736.311 [ThrusterServo] Loaded 2014-04-13T04:02:16.311Z,1397361736.311 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2014-04-13T04:02:16.311Z,1397361736.311 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2014-04-13T04:02:16.312Z,1397361736.312 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2014-04-13T04:02:16.336Z,1397361736.336 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2014-04-13T04:02:16.338Z,1397361736.338 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2014-04-13T04:02:16.339Z,1397361736.339 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2014-04-13T04:02:16.345Z,1397361736.345 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2014-04-13T04:02:16.346Z,1397361736.346 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 4083E4E0 2014-04-13T04:02:16.351Z,1397361736.351 [Supervisor](DEBUG): Running supervisor. 2014-04-13T04:02:16.352Z,1397361736.352 [CommandLine](INFO): Thread ID is 955 2014-04-13T04:02:16.355Z,1397361736.355 [controlThread](INFO): Thread ID is 954 2014-04-13T04:02:16.355Z,1397361736.355 [controlThread](DEBUG): Initializing ControlThread 2014-04-13T04:02:16.356Z,1397361736.356 [CycleStarter](INFO): Thread ID is 953 2014-04-13T04:02:16.359Z,1397361736.359 [logger](INFO): Thread ID is 956 2014-04-13T04:02:16.379Z,1397361736.379 [AsyncPiEstimator](INFO): Thread ID is 1029 2014-04-13T04:02:16.379Z,1397361736.379 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator. 2014-04-13T04:02:16.407Z,1397361736.407 [CTD_NeilBrown](INFO): Thread ID is 1030 2014-04-13T04:02:16.408Z,1397361736.408 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown. 2014-04-13T04:02:16.411Z,1397361736.411 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4 2014-04-13T04:02:16.420Z,1397361736.420 [WetLabsBB2FL](INFO): Thread ID is 1031 2014-04-13T04:02:16.421Z,1397361736.421 [WetLabsBB2FL](INFO): Powering down 2014-04-13T04:02:16.443Z,1397361736.443 [NavChartDb](INFO): Thread ID is 1032 2014-04-13T04:02:16.446Z,1397361736.446 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources 2014-04-13T04:02:16.447Z,1397361736.447 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2014-04-13T04:02:16.447Z,1397361736.447 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2014-04-13T04:02:16.447Z,1397361736.447 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2014-04-13T04:02:16.447Z,1397361736.447 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2014-04-13T04:02:16.448Z,1397361736.448 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2014-04-13T04:02:16.448Z,1397361736.448 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2014-04-13T04:02:16.448Z,1397361736.448 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2014-04-13T04:02:16.449Z,1397361736.449 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2014-04-13T04:02:17.978Z,1397361737.978 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized 2014-04-13T04:02:18.008Z,1397361738.008 [InternalSim](DEBUG): InternalSim initializing... 2014-04-13T04:02:18.122Z,1397361738.122 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2014-04-13T04:02:18.123Z,1397361738.123 [NavChart](DEBUG): Initialize NavChart Navigation. 2014-04-13T04:02:18.123Z,1397361738.123 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2014-04-13T04:02:18.125Z,1397361738.125 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2014-04-13T04:02:18.126Z,1397361738.126 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2014-04-13T04:02:18.126Z,1397361738.126 [LoopControl](DEBUG): Initialize LoopControlComponent. 2014-04-13T04:02:18.126Z,1397361738.126 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2014-04-13T04:02:18.127Z,1397361738.127 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2014-04-13T04:02:18.127Z,1397361738.127 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2014-04-13T04:02:18.128Z,1397361738.128 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2014-04-13T04:02:18.129Z,1397361738.129 [SBIT](INFO): Initialize SBIT Component. 2014-04-13T04:02:18.133Z,1397361738.133 [SBIT](IMPORTANT): Tethys CM Info: $Rev:11196 2014-04-13T04:02:18.134Z,1397361738.134 [SBIT](IMPORTANT): Kernel Release:2.6.27.8 2014-04-13T04:02:18.134Z,1397361738.134 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014 2014-04-13T04:02:18.135Z,1397361738.135 [IBIT](INFO): Initialize IBIT Component. 2014-04-13T04:02:18.135Z,1397361738.135 [CBIT](DEBUG): Initialize CBIT Component. 2014-04-13T04:02:18.136Z,1397361738.136 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2014-04-13T04:02:18.179Z,1397361738.179 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2014-04-13T04:02:18.206Z,1397361738.206 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-13T04:02:18.226Z,1397361738.226 [MissionManager](DEBUG): 2014-04-13T04:02:18.227Z,1397361738.227 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2014-04-13T04:02:18.307Z,1397361738.307 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool 2014-04-13T04:02:18.321Z,1397361738.321 [Default:GPS:A.SetSpeed](DEBUG): Construct. 2014-04-13T04:02:18.325Z,1397361738.325 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-13T04:02:18.345Z,1397361738.345 [Default:Iridium:A.SetSpeed](DEBUG): Construct. 2014-04-13T04:02:18.348Z,1397361738.348 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-13T04:02:18.391Z,1397361738.391 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2014-04-13T04:02:18.419Z,1397361738.419 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Construct. 2014-04-13T04:02:18.423Z,1397361738.423 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-13T04:02:18.442Z,1397361738.442 [MissionManager](DEBUG): 400 400 Burn 300 Dropped drop weight due to communications timeout 5.0 1.0 5 2014-04-13T04:02:18.447Z,1397361738.447 [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-13T04:02:18.543Z,1397361738.543 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2014-04-13T04:02:18.616Z,1397361738.616 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar 2014-04-13T04:02:18.646Z,1397361738.646 [DVL_micro](INFO): Initializing 2014-04-13T04:02:18.750Z,1397361738.750 [Radio_Freewave](INFO): Powering up 2014-04-13T04:02:18.982Z,1397361738.982 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:19.117Z,1397361739.117 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2014-04-13T04:02:19.119Z,1397361739.119 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2014-04-13T04:02:19.135Z,1397361739.135 [ElevatorServo](DEBUG): Initializing EZServoServo. 2014-04-13T04:02:19.143Z,1397361739.143 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2014-04-13T04:02:19.149Z,1397361739.149 [MassServo](DEBUG): Initializing EZServoServo. 2014-04-13T04:02:19.155Z,1397361739.155 [MassServo](DEBUG): Initializing MassServo. 2014-04-13T04:02:19.161Z,1397361739.161 [RudderServo](DEBUG): Initializing EZServoServo. 2014-04-13T04:02:19.191Z,1397361739.191 [RudderServo](DEBUG): Initializing RudderServo. 2014-04-13T04:02:19.197Z,1397361739.197 [ThrusterServo](DEBUG): Initializing EZServoServo. 2014-04-13T04:02:19.203Z,1397361739.203 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2014-04-13T04:02:19.594Z,1397361739.594 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:20.023Z,1397361740.023 [NAL9602](INFO): Powering up NAL9602 2014-04-13T04:02:20.078Z,1397361740.078 [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-13T04:02:20.132Z,1397361740.132 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:20.955Z,1397361740.955 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:21.503Z,1397361741.503 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:21.000Z,1397361742.000 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:22.616Z,1397361742.616 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:23.073Z,1397361743.073 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:23.829Z,1397361743.829 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:24.634Z,1397361744.634 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:25.111Z,1397361745.111 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:25.605Z,1397361745.605 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:26.056Z,1397361746.056 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:26.559Z,1397361746.559 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:27.031Z,1397361747.031 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:27.520Z,1397361747.520 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:28.102Z,1397361748.102 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:28.683Z,1397361748.683 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:29.305Z,1397361749.305 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:29.908Z,1397361749.908 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:30.410Z,1397361750.410 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:30.937Z,1397361750.937 [NAL9602](INFO): NAL9602 initialized 2014-04-13T04:02:30.980Z,1397361750.980 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:31.424Z,1397361751.424 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:31.996Z,1397361751.996 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:32.454Z,1397361752.454 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:32.939Z,1397361752.939 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:33.445Z,1397361753.445 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:34.131Z,1397361754.131 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:34.179Z,1397361754.179 [SBIT](IMPORTANT): Beginning Startup BIT 2014-04-13T04:02:34.183Z,1397361754.183 [CBIT](IMPORTANT): Beginning GF scan 2014-04-13T04:02:34.629Z,1397361754.629 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:35.209Z,1397361755.209 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:35.707Z,1397361755.707 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:36.224Z,1397361756.224 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:36.821Z,1397361756.821 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:37.451Z,1397361757.451 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:38.007Z,1397361758.007 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:38.610Z,1397361758.610 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:39.245Z,1397361759.245 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:39.856Z,1397361759.856 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:40.331Z,1397361760.331 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:40.909Z,1397361760.909 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:41.348Z,1397361761.348 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:41.834Z,1397361761.834 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:42.313Z,1397361762.313 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:42.746Z,1397361762.746 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:43.195Z,1397361763.195 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:43.656Z,1397361763.656 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:44.301Z,1397361764.301 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:44.737Z,1397361764.737 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:45.216Z,1397361765.216 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:45.651Z,1397361765.651 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:46.083Z,1397361766.083 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:46.587Z,1397361766.587 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:47.088Z,1397361767.088 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:47.537Z,1397361767.537 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:47.980Z,1397361767.980 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:48.377Z,1397361768.377 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:48.781Z,1397361768.781 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=25207, MT Status=1, MTMSN=1745 2014-04-13T04:02:48.781Z,1397361768.781 [NAL9602](INFO): Data available in MT queue 2014-04-13T04:02:48.809Z,1397361768.809 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:49.447Z,1397361769.447 [NAL9602](INFO): Received command:! ls /mnt/mmc/LRAUV/Data 2014-04-13T04:02:49.516Z,1397361769.516 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:49.531Z,1397361769.531 [CommandLine](IMPORTANT): got command ! ls /mnt/mmc/LRAUV/Data 2014-04-13T04:02:50.003Z,1397361770.003 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:50.269Z,1397361770.269 [CommandLine](IMPORTANT): navchart running 2014-04-13T04:02:51.180Z,1397361771.180 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:51.734Z,1397361771.734 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:52.279Z,1397361772.279 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:52.824Z,1397361772.824 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:53.330Z,1397361773.330 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:53.915Z,1397361773.915 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:54.589Z,1397361774.589 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T04:02:55.074Z,1397361775.074 [NAL9602](IMPORTANT): GPS fix at: 1397361739.00 2014-04-13T04:02:55.113Z,1397361775.113 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T04:03:01.734Z,1397361781.734 [CBIT](IMPORTANT): No ground fault detected 2014-04-13T04:03:02.621Z,1397361782.621 [NAL9602](INFO): Powering down 2014-04-13T04:03:28.417Z,1397361808.417 [SBIT](IMPORTANT): SBIT PASSED 2014-04-13T04:03:28.888Z,1397361808.888 [MissionManager](IMPORTANT): Started mission Startup 2014-04-13T04:03:28.888Z,1397361808.888 [Startup] Running Loop=1 2014-04-13T04:03:28.889Z,1397361808.889 [Startup](INFO): Aggregate::initialize Startup 2014-04-13T04:03:28.889Z,1397361808.889 [Startup:A.GoToSurface] Running Loop=1 2014-04-13T04:03:28.889Z,1397361808.889 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T04:03:28.897Z,1397361808.897 [Startup:StartupSatComms] Running Loop=1 2014-04-13T04:03:28.898Z,1397361808.898 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms 2014-04-13T04:03:28.898Z,1397361808.898 [Startup:StartupSatComms:A] Running Loop=1 2014-04-13T04:03:29.309Z,1397361809.309 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2014-04-13T04:03:29.737Z,1397361809.737 [NAL9602](INFO): Powering up 2014-04-13T04:03:40.537Z,1397361820.537 [NAL9602](INFO): NAL9602 initialized 2014-04-13T04:03:58.470Z,1397361838.470 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=25208, MT Status=1, MTMSN=1746 2014-04-13T04:03:58.470Z,1397361838.470 [NAL9602](INFO): Data available in MT queue 2014-04-13T04:03:59.022Z,1397361839.022 [NAL9602](INFO): Received command:get Radio_Freewave.loadAtStartup 2014-04-13T04:03:59.714Z,1397361839.714 [CommandLine](IMPORTANT): got command get Radio_Freewave.loadAtStartup 2014-04-13T04:03:59.717Z,1397361839.717 [CommandLine](IMPORTANT): Radio_Freewave.loadAtStartup 1 bool 2014-04-13T04:04:07.677Z,1397361847.677 [NAL9602](IMPORTANT): GPS fix at: 1397361812.00 2014-04-13T04:04:07.701Z,1397361847.701 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T04:04:07.704Z,1397361847.704 [Startup:StartupSatComms:A] Stopped 2014-04-13T04:04:07.704Z,1397361847.704 [Startup:StartupSatComms:B] Running Loop=1 2014-04-13T04:04:08.237Z,1397361848.237 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2014-04-13T04:04:32.014Z,1397361872.014 [NAL9602](INFO): SBD MO Status=1, MOMSN=25209, MT Status=0, MTMSN=0 2014-04-13T04:04:32.065Z,1397361872.065 [NAL9602](INFO): Sent 45 bytes from file Logs/20140413T034807/Courier0028.lzma 2014-04-13T04:04:32.065Z,1397361872.065 [NAL9602](INFO): Packets left to send: 0 2014-04-13T04:04:32.067Z,1397361872.067 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T034807/Courier0028.lzma.parts/0000.sbd 2014-04-13T04:04:32.067Z,1397361872.067 [NAL9602](INFO): Completed sending Logs/20140413T034807/Courier0028.lzma 2014-04-13T04:04:49.187Z,1397361889.187 [NAL9602](INFO): SBD MO Status=1, MOMSN=25210, MT Status=0, MTMSN=0 2014-04-13T04:04:49.236Z,1397361889.236 [NAL9602](INFO): Sent 294 bytes from file Logs/20140413T040209/Courier0000.lzma 2014-04-13T04:04:49.236Z,1397361889.236 [NAL9602](INFO): Packets left to send: 0 2014-04-13T04:04:49.237Z,1397361889.237 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T040209/Courier0000.lzma.parts/0000.sbd 2014-04-13T04:04:49.238Z,1397361889.238 [NAL9602](INFO): Completed sending Logs/20140413T040209/Courier0000.lzma 2014-04-13T04:05:07.915Z,1397361907.915 [Startup:StartupSatComms:B](INFO): Timed out from 2014-04-13T04:04:07.7Z 2014-04-13T04:05:07.915Z,1397361907.915 [Startup:StartupSatComms:B] Stopped 2014-04-13T04:05:07.915Z,1397361907.915 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2014-04-13T04:05:07.915Z,1397361907.915 [Startup:StartupSatComms] Stopped 2014-04-13T04:05:07.915Z,1397361907.915 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms 2014-04-13T04:05:07.916Z,1397361907.916 [Startup](INFO): Completed Startup 2014-04-13T04:05:07.916Z,1397361907.916 [Startup] Stopped 2014-04-13T04:05:07.916Z,1397361907.916 [Startup](INFO): Aggregate::uninitialize Startup 2014-04-13T04:05:07.917Z,1397361907.917 [Startup:A.GoToSurface] Stopped 2014-04-13T04:05:07.917Z,1397361907.917 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T04:05:08.419Z,1397361908.419 [MissionManager](IMPORTANT): Started mission Default 2014-04-13T04:05:08.419Z,1397361908.419 [Default] Running Loop=1 2014-04-13T04:05:08.419Z,1397361908.419 [Default](INFO): Aggregate::initialize Default 2014-04-13T04:05:08.419Z,1397361908.419 [Default:Iridium] Running Loop=1 2014-04-13T04:05:08.419Z,1397361908.419 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2014-04-13T04:05:08.419Z,1397361908.419 [Default:Iridium:A.SetSpeed] Running Loop=1 2014-04-13T04:05:08.419Z,1397361908.419 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2014-04-13T04:05:08.419Z,1397361908.419 [Default:Iridium:B.GoToSurface] Running Loop=1 2014-04-13T04:05:08.420Z,1397361908.420 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T04:05:08.420Z,1397361908.420 [Default:CallIridium] Running Loop=1 2014-04-13T04:05:08.420Z,1397361908.420 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2014-04-13T04:05:08.420Z,1397361908.420 [Default:CallIridium:A] Running Loop=1 2014-04-13T04:05:08.422Z,1397361908.422 [Default:CallIridium:A] Stopped 2014-04-13T04:05:08.422Z,1397361908.422 [Default:CallIridium:B] Running Loop=1 2014-04-13T04:05:08.423Z,1397361908.423 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2014-04-13T04:05:08.428Z,1397361908.428 [Default:Iridium:B.GoToSurface] Stopped 2014-04-13T04:05:08.428Z,1397361908.428 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T04:05:08.428Z,1397361908.428 [Default:Iridium:Read_Iridium] Running Loop=1 2014-04-13T04:05:08.428Z,1397361908.428 [Default:Iridium:A.SetSpeed] Running Loop=1 2014-04-13T04:05:08.433Z,1397361908.433 [Default:GPS] Running Loop=1 2014-04-13T04:05:08.433Z,1397361908.433 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2014-04-13T04:05:08.434Z,1397361908.434 [Default:GPS:A.SetSpeed] Running Loop=1 2014-04-13T04:05:08.434Z,1397361908.434 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2014-04-13T04:05:08.434Z,1397361908.434 [Default:GPS:B.GoToSurface] Running Loop=1 2014-04-13T04:05:08.434Z,1397361908.434 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T04:05:08.439Z,1397361908.439 [Default:GPS:B.GoToSurface] Stopped 2014-04-13T04:05:08.439Z,1397361908.439 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T04:05:08.439Z,1397361908.439 [Default:GPS:Read_GPS] Running Loop=1 2014-04-13T04:05:08.439Z,1397361908.439 [Default:GPS:A.SetSpeed] Running Loop=1 2014-04-13T04:05:08.847Z,1397361908.847 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2014-04-13T04:05:08.850Z,1397361908.850 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2014-04-13T04:05:23.080Z,1397361923.080 [NAL9602](INFO): SBD MO Status=2, MOMSN=25211, MT Status=0, MTMSN=0 2014-04-13T04:05:23.080Z,1397361923.080 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2014-04-13T04:05:24.488Z,1397361924.488 [NAL9602](IMPORTANT): GPS fix at: 1397361889.00 2014-04-13T04:05:24.513Z,1397361924.513 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T04:05:24.517Z,1397361924.517 [Default:GPS:Read_GPS] Stopped 2014-04-13T04:05:24.517Z,1397361924.517 [Default:GPS:D] Running Loop=1 2014-04-13T04:05:24.908Z,1397361924.908 [Default:GPS:D] Stopped 2014-04-13T04:05:24.909Z,1397361924.909 [Default:GPS](INFO): Completed Default:GPS 2014-04-13T04:05:24.909Z,1397361924.909 [Default:GPS] Stopped 2014-04-13T04:05:24.909Z,1397361924.909 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2014-04-13T04:05:24.909Z,1397361924.909 [Default:GPS:A.SetSpeed] Stopped 2014-04-13T04:05:24.909Z,1397361924.909 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2014-04-13T04:05:42.896Z,1397361942.896 [NAL9602](INFO): SBD MO Status=1, MOMSN=25211, MT Status=0, MTMSN=0 2014-04-13T04:05:42.943Z,1397361942.943 [NAL9602](INFO): Sent 74 bytes from file Logs/20140413T040209/Courier0004.lzma 2014-04-13T04:05:42.943Z,1397361942.943 [NAL9602](INFO): Packets left to send: 0 2014-04-13T04:05:42.945Z,1397361942.945 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T040209/Courier0004.lzma.parts/0000.sbd 2014-04-13T04:05:42.945Z,1397361942.945 [NAL9602](INFO): Completed sending Logs/20140413T040209/Courier0004.lzma 2014-04-13T04:06:11.173Z,1397361971.173 [NAL9602](INFO): SBD MO Status=2, MOMSN=25212, MT Status=0, MTMSN=0 2014-04-13T04:06:11.173Z,1397361971.173 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2014-04-13T04:06:32.745Z,1397361992.745 [NAL9602](INFO): SBD MO Status=1, MOMSN=25212, MT Status=0, MTMSN=0 2014-04-13T04:06:32.800Z,1397361992.800 [NAL9602](INFO): Sent 145 bytes from file Logs/20140413T034807/Express0029.lzma 2014-04-13T04:06:32.801Z,1397361992.801 [NAL9602](INFO): Packets left to send: 0 2014-04-13T04:06:32.802Z,1397361992.802 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T034807/Express0029.lzma.parts/0000.sbd 2014-04-13T04:06:32.802Z,1397361992.802 [NAL9602](INFO): Completed sending Logs/20140413T034807/Express0029.lzma 2014-04-13T04:06:43.300Z,1397362003.300 [NAL9602](INFO): SBD MO Status=1, MOMSN=25213, MT Status=0, MTMSN=0 2014-04-13T04:06:43.349Z,1397362003.349 [NAL9602](INFO): Sent 332 bytes from file Logs/20140413T040209/Express0001.lzma 2014-04-13T04:06:43.349Z,1397362003.349 [NAL9602](INFO): Packets left to send: 2 2014-04-13T04:06:43.350Z,1397362003.350 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T040209/Express0001.lzma.parts/0002.sbd 2014-04-13T04:06:49.125Z,1397362009.125 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 41 of 46 2014-04-13T04:06:49.125Z,1397362009.125 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 32.0 34.3 31.9 30.2 63.2 341.8 448.8 231.8 7 9 7 6 -514.6 146.8 292.7 1 557.4 31.3 245.6 1 -417 236 320 2 476 -60 320 2 -7.40 -2.83 202.2 6 0.005 35.0 1489 66 2014-04-13T04:06:58.416Z,1397362018.416 [NAL9602](INFO): SBD MO Status=1, MOMSN=25214, MT Status=0, MTMSN=0 2014-04-13T04:06:58.476Z,1397362018.476 [NAL9602](INFO): Sent 332 bytes from file Logs/20140413T040209/Express0001.lzma 2014-04-13T04:06:58.476Z,1397362018.476 [NAL9602](INFO): Packets left to send: 1 2014-04-13T04:06:58.477Z,1397362018.477 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T040209/Express0001.lzma.parts/0001.sbd 2014-04-13T04:07:08.207Z,1397362028.207 [NAL9602](INFO): SBD MO Status=1, MOMSN=25215, MT Status=0, MTMSN=0 2014-04-13T04:07:08.255Z,1397362028.255 [NAL9602](INFO): Sent 107 bytes from file Logs/20140413T040209/Express0001.lzma 2014-04-13T04:07:08.255Z,1397362028.255 [NAL9602](INFO): Packets left to send: 0 2014-04-13T04:07:08.257Z,1397362028.257 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T040209/Express0001.lzma.parts/0000.sbd 2014-04-13T04:07:08.258Z,1397362028.258 [NAL9602](INFO): Completed sending Logs/20140413T040209/Express0001.lzma 2014-04-13T04:07:19.208Z,1397362039.208 [NAL9602](INFO): SBD MO Status=1, MOMSN=25216, MT Status=0, MTMSN=0 2014-04-13T04:07:19.256Z,1397362039.256 [NAL9602](INFO): Sent 251 bytes from file Logs/20140413T040209/Express0005.lzma 2014-04-13T04:07:19.256Z,1397362039.256 [NAL9602](INFO): Packets left to send: 0 2014-04-13T04:07:19.258Z,1397362039.258 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T040209/Express0005.lzma.parts/0000.sbd 2014-04-13T04:07:19.258Z,1397362039.258 [NAL9602](INFO): Completed sending Logs/20140413T040209/Express0005.lzma 2014-04-13T04:07:30.562Z,1397362050.562 [NAL9602](INFO): SBD MO Status=0, MOMSN=25217, MT Status=0, MTMSN=0 2014-04-13T04:07:41.402Z,1397362061.402 [NAL9602](INFO): SBD MO Status=1, MOMSN=25218, MT Status=0, MTMSN=0 2014-04-13T04:07:41.451Z,1397362061.451 [NAL9602](INFO): Sent 75 bytes from file Logs/20140413T040209/Courier0008.lzma 2014-04-13T04:07:41.451Z,1397362061.451 [NAL9602](INFO): Packets left to send: 0 2014-04-13T04:07:41.452Z,1397362061.452 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T040209/Courier0008.lzma.parts/0000.sbd 2014-04-13T04:07:41.453Z,1397362061.453 [NAL9602](INFO): Completed sending Logs/20140413T040209/Courier0008.lzma 2014-04-13T04:07:52.448Z,1397362072.448 [NAL9602](INFO): SBD MO Status=1, MOMSN=25219, MT Status=0, MTMSN=0 2014-04-13T04:07:52.500Z,1397362072.500 [NAL9602](INFO): Sent 98 bytes from file Logs/20140413T040209/Express0009.lzma 2014-04-13T04:07:52.500Z,1397362072.500 [NAL9602](INFO): Packets left to send: 0 2014-04-13T04:07:52.502Z,1397362072.502 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T040209/Express0009.lzma.parts/0000.sbd 2014-04-13T04:07:52.502Z,1397362072.502 [NAL9602](INFO): Completed sending Logs/20140413T040209/Express0009.lzma 2014-04-13T04:08:03.750Z,1397362083.750 [NAL9602](INFO): SBD MO Status=0, MOMSN=25220, MT Status=0, MTMSN=0 2014-04-13T04:08:03.841Z,1397362083.841 [Default:Iridium:Read_Iridium] Stopped 2014-04-13T04:08:03.841Z,1397362083.841 [Default:Iridium](INFO): Completed Default:Iridium 2014-04-13T04:08:03.841Z,1397362083.841 [Default:Iridium] Stopped 2014-04-13T04:08:03.841Z,1397362083.841 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2014-04-13T04:08:03.841Z,1397362083.841 [Default:Iridium:A.SetSpeed] Stopped 2014-04-13T04:08:03.841Z,1397362083.841 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2014-04-13T04:08:03.841Z,1397362083.841 [Default:WaitAtTheSurface] Running Loop=1 2014-04-13T04:08:03.842Z,1397362083.842 [Default:WaitAtTheSurface](INFO): Aggregate::initialize Default:WaitAtTheSurface 2014-04-13T04:08:03.842Z,1397362083.842 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Running Loop=1 2014-04-13T04:08:03.842Z,1397362083.842 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Initialize. 2014-04-13T04:08:03.842Z,1397362083.842 [Default:WaitAtTheSurface:B.GoToSurface] Running Loop=1 2014-04-13T04:08:03.842Z,1397362083.842 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T04:08:04.265Z,1397362084.265 [Default:WaitAtTheSurface:B.GoToSurface] Running Loop=1 2014-04-13T04:08:04.287Z,1397362084.287 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Running Loop=1 2014-04-13T04:08:04.300Z,1397362084.300 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2014-04-13T04:08:04.300Z,1397362084.300 [Default:CallIridium:B] Stopped 2014-04-13T04:08:04.300Z,1397362084.300 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2014-04-13T04:08:04.300Z,1397362084.300 [Default:CallIridium](INFO): Completed Default:CallIridium 2014-04-13T04:08:04.300Z,1397362084.300 [Default:CallIridium] Stopped 2014-04-13T04:08:04.300Z,1397362084.300 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2014-04-13T04:08:14.446Z,1397362094.446 [NAL9602](INFO): Powering down 2014-04-13T04:13:04.459Z,1397362384.459 [Default:CallIridium] Running Loop=1 2014-04-13T04:13:04.459Z,1397362384.459 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2014-04-13T04:13:04.459Z,1397362384.459 [Default:CallIridium:A] Running Loop=1 2014-04-13T04:13:04.460Z,1397362384.460 [Default:CallIridium:A] Stopped 2014-04-13T04:13:04.460Z,1397362384.460 [Default:CallIridium:B] Running Loop=1 2014-04-13T04:13:04.460Z,1397362384.460 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2014-04-13T04:13:09.441Z,1397362389.441 [Default:Iridium] Running Loop=1 2014-04-13T04:13:09.441Z,1397362389.441 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2014-04-13T04:13:09.441Z,1397362389.441 [Default:Iridium:A.SetSpeed] Running Loop=1 2014-04-13T04:13:09.441Z,1397362389.441 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2014-04-13T04:13:09.441Z,1397362389.441 [Default:Iridium:B.GoToSurface] Running Loop=1 2014-04-13T04:13:09.441Z,1397362389.441 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T04:13:09.442Z,1397362389.442 [Default:Iridium:B.GoToSurface] Stopped 2014-04-13T04:13:09.442Z,1397362389.442 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T04:13:09.442Z,1397362389.442 [Default:Iridium:Read_Iridium] Running Loop=1 2014-04-13T04:13:09.443Z,1397362389.443 [Default:GPS] Running Loop=1 2014-04-13T04:13:09.443Z,1397362389.443 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2014-04-13T04:13:09.443Z,1397362389.443 [Default:GPS:A.SetSpeed] Running Loop=1 2014-04-13T04:13:09.443Z,1397362389.443 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2014-04-13T04:13:09.443Z,1397362389.443 [Default:GPS:B.GoToSurface] Running Loop=1 2014-04-13T04:13:09.443Z,1397362389.443 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T04:13:09.444Z,1397362389.444 [Default:GPS:B.GoToSurface] Stopped 2014-04-13T04:13:09.444Z,1397362389.444 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T04:13:09.444Z,1397362389.444 [Default:GPS:Read_GPS] Running Loop=1 2014-04-13T04:13:10.955Z,1397362390.955 [NAL9602](INFO): Powering up 2014-04-13T04:13:21.750Z,1397362401.750 [NAL9602](INFO): NAL9602 initialized 2014-04-13T04:13:46.402Z,1397362426.402 [NAL9602](INFO): SBD MO Status=2, MOMSN=25221, MT Status=2, MTMSN=0 2014-04-13T04:13:46.402Z,1397362426.402 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2014-04-13T04:14:18.001Z,1397362458.001 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=25221, MT Status=1, MTMSN=1747 2014-04-13T04:14:18.050Z,1397362458.050 [NAL9602](INFO): Sent 45 bytes from file Logs/20140413T040209/Courier0012.lzma 2014-04-13T04:14:18.050Z,1397362458.050 [NAL9602](INFO): Packets left to send: 0 2014-04-13T04:14:18.052Z,1397362458.052 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T040209/Courier0012.lzma.parts/0000.sbd 2014-04-13T04:14:18.053Z,1397362458.053 [NAL9602](INFO): Completed sending Logs/20140413T040209/Courier0012.lzma 2014-04-13T04:14:18.831Z,1397362458.831 [NAL9602](INFO): Received command:sched asap "load Science/science_to.xml;set science_to.MaxDepth 25.0 meter;set science_to.YoYoMaxDepth 20.0 meter;set science_to.Wpt1Lat 33.608 degree;set science_to.Wpt1Lon -118.019 degree;set science_to.Wpt2Lat 33.585 degree" 3ridp 1 3 2014-04-13T04:14:18.892Z,1397362458.892 [CommandLine](IMPORTANT): got command schedule asap "load Science/science_to.xml;set science_to.MaxDepth 25.0 meter;set science_to.YoYoMaxDepth 20.0 meter;set science_to.Wpt1Lat 33.608 degree;set science_to.Wpt1Lon -118.019 degree;set science_to.Wpt2Lat 33.585 degree" 3ridp 1 3.000000 2014-04-13T04:14:18.893Z,1397362458.893 [CommandLine](IMPORTANT): Scheduling command #1 of 3 with id=3ridp 2014-04-13T04:14:18.894Z,1397362458.894 [CommandLine](IMPORTANT): Scheduled #1 (#1 of 3 with id='3ridp'): "load Science/science_to.xml;set science_to.MaxDepth 25.0 meter;set science_to.YoYoMaxDepth 20.0 meter;set science_to.Wpt1Lat 33.608 degree;set science_to.Wpt1Lon -118.019 degree;set science_to.Wpt2Lat 33.585 degree" ASAP 2014-04-13T04:14:20.323Z,1397362460.323 [NAL9602](IMPORTANT): GPS fix at: 1397362425.00 2014-04-13T04:14:20.336Z,1397362460.336 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T04:14:20.341Z,1397362460.341 [Default:GPS:Read_GPS] Stopped 2014-04-13T04:14:20.341Z,1397362460.341 [Default:GPS:D] Running Loop=1 2014-04-13T04:14:20.820Z,1397362460.820 [Default:GPS:D] Stopped 2014-04-13T04:14:20.821Z,1397362460.821 [Default:GPS](INFO): Completed Default:GPS 2014-04-13T04:14:20.821Z,1397362460.821 [Default:GPS] Stopped 2014-04-13T04:14:20.821Z,1397362460.821 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2014-04-13T04:14:20.821Z,1397362460.821 [Default:GPS:A.SetSpeed] Stopped 2014-04-13T04:14:20.821Z,1397362460.821 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2014-04-13T04:14:39.944Z,1397362479.944 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=25222, MT Status=1, MTMSN=1748 2014-04-13T04:14:39.996Z,1397362479.996 [NAL9602](INFO): Sent 62 bytes from file Logs/20140413T040209/Express0013.lzma 2014-04-13T04:14:39.996Z,1397362479.996 [NAL9602](INFO): Packets left to send: 0 2014-04-13T04:14:39.997Z,1397362479.997 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T040209/Express0013.lzma.parts/0000.sbd 2014-04-13T04:14:39.998Z,1397362479.998 [NAL9602](INFO): Completed sending Logs/20140413T040209/Express0013.lzma 2014-04-13T04:14:40.769Z,1397362480.769 [NAL9602](INFO): Received command:sched asap "set science_to.Wpt2Lon -117.983 degree;set science_to.Wpt3Lat 33.564 degree;set science_to.Wpt3Lon -117.999 degree;set science_to.Wpt4Lat 33.606 degree;set science_to.Wpt4Lon -118.076 degree;set science_to.NeedCommsTime 30 minute" 3ridp 2 3 2014-04-13T04:14:40.831Z,1397362480.831 [CommandLine](IMPORTANT): got command schedule asap "set science_to.Wpt2Lon -117.983 degree;set science_to.Wpt3Lat 33.564 degree;set science_to.Wpt3Lon -117.999 degree;set science_to.Wpt4Lat 33.606 degree;set science_to.Wpt4Lon -118.076 degree;set science_to.NeedCommsTime 30 minute" 3ridp 2 3.000000 2014-04-13T04:14:40.831Z,1397362480.831 [CommandLine](IMPORTANT): Scheduling command #2 of 3 with id=3ridp 2014-04-13T04:14:40.832Z,1397362480.832 [CommandLine](IMPORTANT): Scheduled #2 (#2 of 3 with id='3ridp'): "set science_to.Wpt2Lon -117.983 degree;set science_to.Wpt3Lat 33.564 degree;set science_to.Wpt3Lon -117.999 degree;set science_to.Wpt4Lat 33.606 degree;set science_to.Wpt4Lon -118.076 degree;set science_to.NeedCommsTime 30 minute" ASAP 2014-04-13T04:14:54.690Z,1397362494.690 [NAL9602](INFO): SBD MO Status=0, MOMSN=25223, MT Status=0, MTMSN=0 2014-04-13T04:15:12.305Z,1397362512.305 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=25224, MT Status=1, MTMSN=1749 2014-04-13T04:15:12.354Z,1397362512.354 [NAL9602](INFO): Sent 74 bytes from file Logs/20140413T040209/Courier0016.lzma 2014-04-13T04:15:12.354Z,1397362512.354 [NAL9602](INFO): Packets left to send: 0 2014-04-13T04:15:12.356Z,1397362512.356 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T040209/Courier0016.lzma.parts/0000.sbd 2014-04-13T04:15:12.356Z,1397362512.356 [NAL9602](INFO): Completed sending Logs/20140413T040209/Courier0016.lzma 2014-04-13T04:15:12.951Z,1397362512.951 [NAL9602](INFO): Received command:sched asap "set science_to.Timeout 2 hour;run " 3ridp 3 3 2014-04-13T04:15:12.984Z,1397362512.984 [CommandLine](IMPORTANT): got command schedule asap "set science_to.Timeout 2 hour;run " 3ridp 3 3.000000 2014-04-13T04:15:12.985Z,1397362512.985 [CommandLine](IMPORTANT): Scheduling command #3 of 3 with id=3ridp 2014-04-13T04:15:12.985Z,1397362512.985 [CommandLine](IMPORTANT): Scheduled #3 (#3 of 3 with id='3ridp'): "set science_to.Timeout 2 hour;run " ASAP 2014-04-13T04:15:13.013Z,1397362513.013 [CommandLine](IMPORTANT): got command load ./Missions/Science/science_to.xml 2014-04-13T04:15:13.014Z,1397362513.014 [MissionManager](INFO): Loading Mission: ./Missions/Science/science_to.xml 2014-04-13T04:15:13.217Z,1397362513.217 [MissionManager](INFO): DefineArg science_to.MinAltitude = 10.000000 m 2014-04-13T04:15:13.224Z,1397362513.224 [MissionManager](INFO): DefineArg science_to.MaxDepth = 105.000000 m 2014-04-13T04:15:13.227Z,1397362513.227 [MissionManager](INFO): DefineArg science_to.MinOffshore = 2000.000000 m 2014-04-13T04:15:13.230Z,1397362513.230 [MissionManager](INFO): DefineArg science_to.YoYoMinDepth = 3.000000 m 2014-04-13T04:15:13.233Z,1397362513.233 [MissionManager](INFO): DefineArg science_to.YoYoMaxDepth = 100.000000 m 2014-04-13T04:15:13.236Z,1397362513.236 [MissionManager](INFO): DefineArg science_to.YoYoUpPitch = 20.000000 arcdeg 2014-04-13T04:15:13.240Z,1397362513.240 [MissionManager](INFO): DefineArg science_to.YoYoDownPitch = -20.000000 arcdeg 2014-04-13T04:15:13.242Z,1397362513.242 [MissionManager](INFO): DefineArg science_to.Wpt1Lat = 0.000000 arcdeg 2014-04-13T04:15:13.246Z,1397362513.246 [MissionManager](INFO): DefineArg science_to.Wpt1Lon = 0.000000 arcdeg 2014-04-13T04:15:13.249Z,1397362513.249 [MissionManager](INFO): DefineArg science_to.Wpt2Lat = 0.000000 arcdeg 2014-04-13T04:15:13.253Z,1397362513.253 [MissionManager](INFO): DefineArg science_to.Wpt2Lon = 0.000000 arcdeg 2014-04-13T04:15:13.256Z,1397362513.256 [MissionManager](INFO): DefineArg science_to.Wpt3Lat = 0.000000 arcdeg 2014-04-13T04:15:13.259Z,1397362513.259 [MissionManager](INFO): DefineArg science_to.Wpt3Lon = 0.000000 arcdeg 2014-04-13T04:15:13.262Z,1397362513.262 [MissionManager](INFO): DefineArg science_to.Wpt4Lat = 0.000000 arcdeg 2014-04-13T04:15:13.265Z,1397362513.265 [MissionManager](INFO): DefineArg science_to.Wpt4Lon = 0.000000 arcdeg 2014-04-13T04:15:13.269Z,1397362513.269 [MissionManager](INFO): DefineArg science_to.NeedCommsTime = 120.000000 min 2014-04-13T04:15:13.288Z,1397362513.288 [MissionManager](INFO): DefineArg science_to.Speed = 1.000000 m/s 2014-04-13T04:15:13.293Z,1397362513.293 [MissionManager](INFO): DefineArg science_to.Timeout = 36.000000 h 2014-04-13T04:15:13.297Z,1397362513.297 [MissionManager](INFO): DefineArg science_to.BuoyancyNeutral = 0.000300 n/a 2014-04-13T04:15:13.301Z,1397362513.301 [MissionManager](INFO): DefineArg science_to.MassDefault = 0.000000 n/a 2014-04-13T04:15:13.312Z,1397362513.312 [MissionManager](INFO): DefineArg science_to.ZeroDeg = 0.000000 arcdeg 2014-04-13T04:15:13.315Z,1397362513.315 [science_to:AltEnvWrapper:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope. 2014-04-13T04:15:13.330Z,1397362513.330 [science_to:B.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2014-04-13T04:15:13.341Z,1397362513.341 [science_to:OffshoreWrapper:A.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope. 2014-04-13T04:15:13.348Z,1397362513.348 [science_to:D.Pitch](DEBUG): Construct. 2014-04-13T04:15:13.353Z,1397362513.353 [MissionManager](INFO): Inserting Stack: Missions/Insert/Surface.xml 2014-04-13T04:15:13.402Z,1397362513.402 [MissionManager](INFO): DefineArg science_to:SURFACECOMMS.SurfaceDepthRate = nan m/s 2014-04-13T04:15:13.405Z,1397362513.405 [MissionManager](INFO): DefineArg science_to:SURFACECOMMS.SurfacePitch = 20.000000 arcdeg 2014-04-13T04:15:13.416Z,1397362513.416 [MissionManager](INFO): DefineArg science_to:SURFACECOMMS.SurfaceSpeed = 1.000000 m/s 2014-04-13T04:15:13.425Z,1397362513.425 [MissionManager](INFO): DefineArg science_to:SURFACECOMMS.IridiumTimeout = 30.000000 min 2014-04-13T04:15:13.428Z,1397362513.428 [MissionManager](INFO): DefineArg science_to:SURFACECOMMS.UnpackSplitAtSurface = 0 bool 2014-04-13T04:15:13.429Z,1397362513.429 [science_to:SURFACECOMMS:A.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-13T04:15:13.466Z,1397362513.466 [MissionManager](INFO): RedefineArg science_to:SURFACECOMMS.SurfacePitch = value:20.000000 arcdeg 2014-04-13T04:15:13.484Z,1397362513.484 [MissionManager](INFO): RedefineArg science_to:SURFACECOMMS.SurfaceSpeed = reader:science_to.Speed 2014-04-13T04:15:13.494Z,1397362513.494 [MissionManager](INFO): Inserting Stack: Missions/Insert/Science.xml 2014-04-13T04:15:13.642Z,1397362513.642 [MissionManager](INFO): DefineArg science_to:Science.SampleISUS = 0 bool 2014-04-13T04:15:13.645Z,1397362513.645 [MissionManager](INFO): DefineArg science_to:Science.SampleISUSmaxPitch = 60.000000 arcdeg 2014-04-13T04:15:13.649Z,1397362513.649 [MissionManager](INFO): DefineArg science_to:Science.SampleISUSminPitch = -60.000000 arcdeg 2014-04-13T04:15:13.651Z,1397362513.651 [MissionManager](INFO): DefineArg science_to:Science.PeakDetectChlActive = 0 bool 2014-04-13T04:15:13.654Z,1397362513.654 [MissionManager](INFO): DefineArg science_to:Science.PeakDetectNO3Active = 0 bool 2014-04-13T04:15:13.657Z,1397362513.657 [MissionManager](INFO): DefineArg science_to:Science.UpwardDerivativeOfTemperatureActive = 0 bool 2014-04-13T04:15:13.659Z,1397362513.659 [MissionManager](INFO): DefineArg science_to:Science.ComputeWaterCurrent = 0 bool 2014-04-13T04:15:13.664Z,1397362513.664 [MissionManager](INFO): DefineArg science_to:Science.ComputeWaterCurrentMinDepth = 2.000000 m 2014-04-13T04:15:13.667Z,1397362513.667 [MissionManager](INFO): DefineArg science_to:Science.ComputeWaterCurrentMaxDepth = 5.000000 m 2014-04-13T04:15:13.670Z,1397362513.670 [MissionManager](INFO): DefineArg science_to:Science.EnabledAanderaaO2 = 0.000000 n/a 2014-04-13T04:15:13.698Z,1397362513.698 [MissionManager](INFO): DefineArg science_to:Science.EnabledNeilBrown = 1.000000 n/a 2014-04-13T04:15:13.701Z,1397362513.701 [MissionManager](INFO): DefineArg science_to:Science.EnabledTurbulence_NPS = 0.000000 n/a 2014-04-13T04:15:13.705Z,1397362513.705 [MissionManager](INFO): DefineArg science_to:Science.EnabledWetLabsBB2FL = 1.000000 n/a 2014-04-13T04:15:13.720Z,1397362513.720 [MissionManager](INFO): DefineArg science_to:Science.EnabledDVL = 1.000000 n/a 2014-04-13T04:15:13.723Z,1397362513.723 [MissionManager](INFO): DefineArg science_to:Science.EnabledISUS = 0.000000 n/a 2014-04-13T04:15:13.726Z,1397362513.726 [MissionManager](INFO): DefineOutput science_to:Science.PeakChl = 0.000000 ug/l 2014-04-13T04:15:13.730Z,1397362513.730 [MissionManager](INFO): DefineOutput science_to:Science.PeakChlDepth = 0.000000 m 2014-04-13T04:15:13.737Z,1397362513.737 [MissionManager](INFO): DefineOutput science_to:Science.PeakChlLatitude = nan arcdeg 2014-04-13T04:15:13.740Z,1397362513.740 [MissionManager](INFO): DefineOutput science_to:Science.PeakChlLongitude = nan arcdeg 2014-04-13T04:15:13.744Z,1397362513.744 [MissionManager](INFO): DefineOutput science_to:Science.PeakNO3 = 0.000000 umol/l 2014-04-13T04:15:13.747Z,1397362513.747 [MissionManager](INFO): DefineOutput science_to:Science.PeakNO3Depth = 0.000000 m 2014-04-13T04:15:13.750Z,1397362513.750 [MissionManager](INFO): DefineOutput science_to:Science.PeakNO3Latitude = nan arcdeg 2014-04-13T04:15:13.753Z,1397362513.753 [MissionManager](INFO): DefineOutput science_to:Science.PeakNO3Longitude = nan arcdeg 2014-04-13T04:15:13.793Z,1397362513.793 [science_to:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2014-04-13T04:15:13.816Z,1397362513.816 [science_to:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2014-04-13T04:15:13.826Z,1397362513.826 [MissionManager](INFO): RedefineArg science_to:Science.SampleISUS = value:1 bool 2014-04-13T04:15:13.836Z,1397362513.836 [MissionManager](INFO): RedefineArg science_to:Science.PeakDetectChlActive = value:1 bool 2014-04-13T04:15:13.837Z,1397362513.837 [science_to:H.Buoyancy](DEBUG): Construct Buoyancy. 2014-04-13T04:15:13.840Z,1397362513.840 [science_to:I.SetSpeed](DEBUG): Construct. 2014-04-13T04:15:13.843Z,1397362513.843 [science_to:J.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2014-04-13T04:15:13.853Z,1397362513.853 [science_to:K.YoYo](DEBUG): Construct YoYo. 2014-04-13T04:15:13.863Z,1397362513.863 [science_to:Wpt1:A.Waypoint](DEBUG): Construct Waypoint. 2014-04-13T04:15:13.870Z,1397362513.870 [science_to:Wpt2:A.Waypoint](DEBUG): Construct Waypoint. 2014-04-13T04:15:13.930Z,1397362513.930 [science_to:Wpt3:A.Waypoint](DEBUG): Construct Waypoint. 2014-04-13T04:15:13.942Z,1397362513.942 [science_to:Wpt4:A.Waypoint](DEBUG): Construct Waypoint. 2014-04-13T04:15:14.025Z,1397362514.025 [MissionManager](DEBUG): Vehicle yo-yo's to the specified waypoint, with science turned on. Minimum height above the sea floor for the entire mission. 10.0 Maximum depth for the entire mission. 105.0 Minimum offshore distance for the entire mission. 2000.0 Minimum depth while performing the YoYo behavior. 3.0 Maximum depth while performing the YoYo behavior. 100.0 Vehicle up pitch while performing the YoYo behavior. 20.0 Vehicle down pitch while performing the YoYo behavior. -20.0 Latitude of waypoint 1. If zero, waypoint is skipped. 0 Longitude of waypoint 1. If zero, waypoint is skipped. 0 Latitude of waypoint 2. If zero, waypoint is skipped. 0 Longitude of waypoint 2. If zero, waypoint is skipped. 0 Latitude of waypoint 3. If zero, waypoint is skipped. 0 Longitude of waypoint 3. If zero, waypoint is skipped. 0 Latitude of waypoint 4. If zero, waypoint is skipped. 0 Longitude of waypoint 4. If zero, waypoint is skipped. 0 Elapsed time after previous surface communications when vehicle will begin to ascend for additional surface communications, if the vehicle has a positive pitch. If the vehicle has a negative pitch, it will wait up to 10 minutes more to begin ascent. 120 Speed while performing the YoYo behavior. 1 Maximum length of mission 36 Buoyancy bladder position while performing the YoYo behavior. Defaults to buoyancyNeutral setting in the Config/Control.cfg file. Set to NaN cc for active buoyancy Static setting for mass during the mission. Set to NaN mm for active mass position Constant value. Do not change. 0 0 Safety behavior that keeps vehicle off sea floor Safety behavior that keeps vehicle from going too deep 0 Safety behavior that keeps vehicle away from the shore 20 0 10 If we're executing here or below, lets' get science data! 2014-04-13T04:15:14.026Z,1397362514.026 [CommandLine](IMPORTANT): Loaded ./Missions/Science/science_to.xml 2014-04-13T04:15:20.804Z,1397362520.804 [CommandLine](IMPORTANT): got command set science_to.MaxDepth 25.000000 meter 2014-04-13T04:15:20.805Z,1397362520.805 [CommandLine](IMPORTANT): got command set science_to.YoYoMaxDepth 20.000000 meter 2014-04-13T04:15:20.805Z,1397362520.805 [CommandLine](IMPORTANT): got command set science_to.Wpt1Lat 33.608002 degree 2014-04-13T04:15:20.806Z,1397362520.806 [CommandLine](IMPORTANT): got command set science_to.Wpt1Lon -118.018997 degree 2014-04-13T04:15:20.807Z,1397362520.807 [CommandLine](IMPORTANT): got command set science_to.Wpt2Lat 33.584999 degree 2014-04-13T04:15:28.830Z,1397362528.830 [CommandLine](IMPORTANT): got command set science_to.Wpt2Lon -117.983002 degree 2014-04-13T04:15:28.831Z,1397362528.831 [CommandLine](IMPORTANT): got command set science_to.Wpt3Lat 33.563999 degree 2014-04-13T04:15:28.831Z,1397362528.831 [CommandLine](IMPORTANT): got command set science_to.Wpt3Lon -117.999001 degree 2014-04-13T04:15:28.832Z,1397362528.832 [CommandLine](IMPORTANT): got command set science_to.Wpt4Lat 33.605999 degree 2014-04-13T04:15:28.833Z,1397362528.833 [CommandLine](IMPORTANT): got command set science_to.Wpt4Lon -118.075996 degree 2014-04-13T04:15:28.833Z,1397362528.833 [CommandLine](IMPORTANT): got command set science_to.NeedCommsTime 30.000000 minute 2014-04-13T04:15:30.164Z,1397362530.164 [CommandLine](IMPORTANT): got command set science_to.Timeout 2.000000 hour 2014-04-13T04:15:30.164Z,1397362530.164 [CommandLine](IMPORTANT): got command run 2014-04-13T04:15:30.167Z,1397362530.167 [CommandLine](IMPORTANT): Running 2014-04-13T04:15:30.341Z,1397362530.341 [Default] Stopped 2014-04-13T04:15:30.341Z,1397362530.341 [Default](INFO): Aggregate::uninitialize Default 2014-04-13T04:15:30.341Z,1397362530.341 [Default:Iridium] Stopped 2014-04-13T04:15:30.341Z,1397362530.341 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2014-04-13T04:15:30.341Z,1397362530.341 [Default:Iridium:A.SetSpeed] Stopped 2014-04-13T04:15:30.341Z,1397362530.341 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2014-04-13T04:15:30.342Z,1397362530.342 [Default:Iridium:Read_Iridium] Stopped 2014-04-13T04:15:30.342Z,1397362530.342 [Default:CallIridium] Stopped 2014-04-13T04:15:30.342Z,1397362530.342 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2014-04-13T04:15:30.342Z,1397362530.342 [Default:CallIridium:B] Stopped 2014-04-13T04:15:30.342Z,1397362530.342 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2014-04-13T04:15:30.342Z,1397362530.342 [Default:WaitAtTheSurface] Stopped 2014-04-13T04:15:30.342Z,1397362530.342 [Default:WaitAtTheSurface](INFO): Aggregate::uninitialize Default:WaitAtTheSurface 2014-04-13T04:15:30.342Z,1397362530.342 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Stopped 2014-04-13T04:15:30.342Z,1397362530.342 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Uninitialize. 2014-04-13T04:15:30.342Z,1397362530.342 [Default:WaitAtTheSurface:B.GoToSurface] Stopped 2014-04-13T04:15:30.342Z,1397362530.342 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T04:15:30.343Z,1397362530.343 [MissionManager](IMPORTANT): Started mission science_to 2014-04-13T04:15:30.343Z,1397362530.343 [science_to] Running Loop=1 2014-04-13T04:15:30.343Z,1397362530.343 [science_to](INFO): Aggregate::initialize science_to 2014-04-13T04:15:30.343Z,1397362530.343 [science_to:B.DepthEnvelope] Running Loop=1 2014-04-13T04:15:30.343Z,1397362530.343 [science_to:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent. 2014-04-13T04:15:30.343Z,1397362530.343 [science_to:D.Pitch] Running Loop=1 2014-04-13T04:15:30.343Z,1397362530.343 [science_to:D.Pitch](DEBUG): Initialize. 2014-04-13T04:15:30.344Z,1397362530.344 [science_to:Science] Running Loop=1 2014-04-13T04:15:30.344Z,1397362530.344 [science_to:Science](INFO): Aggregate::initialize science_to:Science 2014-04-13T04:15:30.344Z,1397362530.344 [science_to:Science:A] Running Loop=1 2014-04-13T04:15:30.344Z,1397362530.344 [science_to:Science:B] Running Loop=1 2014-04-13T04:15:30.344Z,1397362530.344 [science_to:Science:C] Running Loop=1 2014-04-13T04:15:30.344Z,1397362530.344 [science_to:Science:D] Running Loop=1 2014-04-13T04:15:30.344Z,1397362530.344 [science_to:Science:E] Running Loop=1 2014-04-13T04:15:30.344Z,1397362530.344 [science_to:Science:F] Running Loop=1 2014-04-13T04:15:30.344Z,1397362530.344 [science_to:Science:G] Running Loop=1 2014-04-13T04:15:30.344Z,1397362530.344 [science_to:Science:PeakDetectChl] Running Loop=1 2014-04-13T04:15:30.344Z,1397362530.344 [science_to:Science:PeakDetectChl](INFO): Aggregate::initialize science_to:Science:PeakDetectChl 2014-04-13T04:15:30.345Z,1397362530.345 [science_to:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1 2014-04-13T04:15:30.345Z,1397362530.345 [science_to:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize. 2014-04-13T04:15:30.346Z,1397362530.346 [science_to:Science:PeakDetectNO3] Running Loop=1 2014-04-13T04:15:30.347Z,1397362530.347 [science_to:Science:PeakDetectNO3](INFO): Aggregate::initialize science_to:Science:PeakDetectNO3 2014-04-13T04:15:30.347Z,1397362530.347 [science_to:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1 2014-04-13T04:15:30.347Z,1397362530.347 [science_to:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize. 2014-04-13T04:15:30.348Z,1397362530.348 [science_to:H.Buoyancy] Running Loop=1 2014-04-13T04:15:30.348Z,1397362530.348 [science_to:H.Buoyancy](DEBUG): Initialize Buoyancy Component. 2014-04-13T04:15:30.349Z,1397362530.349 [science_to:I.SetSpeed] Running Loop=1 2014-04-13T04:15:30.349Z,1397362530.349 [science_to:I.SetSpeed](DEBUG): Initialize. 2014-04-13T04:15:30.349Z,1397362530.349 [science_to:J.DepthEnvelope] Running Loop=1 2014-04-13T04:15:30.349Z,1397362530.349 [science_to:J.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent. 2014-04-13T04:15:30.349Z,1397362530.349 [science_to:K.YoYo] Running Loop=1 2014-04-13T04:15:30.350Z,1397362530.350 [science_to:K.YoYo](DEBUG): Initialize YoYoComponent. 2014-04-13T04:15:30.350Z,1397362530.350 [science_to:SURFACECOMMS] Running Loop=1 2014-04-13T04:15:30.350Z,1397362530.350 [science_to:SURFACECOMMS](INFO): Aggregate::initialize science_to:SURFACECOMMS 2014-04-13T04:15:30.350Z,1397362530.350 [science_to:SURFACECOMMS:A.GoToSurface] Running Loop=1 2014-04-13T04:15:30.350Z,1397362530.350 [science_to:SURFACECOMMS:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T04:15:30.351Z,1397362530.351 [science_to:K.YoYo] Running Loop=1 2014-04-13T04:15:30.356Z,1397362530.356 [science_to:J.DepthEnvelope] Running Loop=1 2014-04-13T04:15:30.362Z,1397362530.362 [science_to:I.SetSpeed] Running Loop=1 2014-04-13T04:15:30.367Z,1397362530.367 [science_to:H.Buoyancy] Running Loop=1 2014-04-13T04:15:30.392Z,1397362530.392 [science_to:Science] Running Loop=1 2014-04-13T04:15:30.396Z,1397362530.396 [science_to:Science:PeakDetectNO3] Stopped 2014-04-13T04:15:30.396Z,1397362530.396 [science_to:Science:PeakDetectNO3](INFO): Aggregate::uninitialize science_to:Science:PeakDetectNO3 2014-04-13T04:15:30.396Z,1397362530.396 [science_to:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped 2014-04-13T04:15:30.396Z,1397362530.396 [science_to:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2014-04-13T04:15:30.396Z,1397362530.396 [science_to:Science:PeakDetectChl] Running Loop=1 2014-04-13T04:15:30.408Z,1397362530.408 [science_to:Science:G] Running Loop=1 2014-04-13T04:15:30.409Z,1397362530.409 [science_to:Science:G](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water 2014-04-13T04:15:30.411Z,1397362530.411 [science_to:Science:F] Stopped 2014-04-13T04:15:30.411Z,1397362530.411 [science_to:Science:E] Stopped 2014-04-13T04:15:30.411Z,1397362530.411 [science_to:Science:D] Running Loop=1 2014-04-13T04:15:30.412Z,1397362530.412 [science_to:Science:D](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature 2014-04-13T04:15:30.412Z,1397362530.412 [science_to:Science:D](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity 2014-04-13T04:15:30.414Z,1397362530.414 [science_to:Science:C] Stopped 2014-04-13T04:15:30.414Z,1397362530.414 [science_to:Science:B] Stopped 2014-04-13T04:15:30.414Z,1397362530.414 [science_to:Science:A] Stopped 2014-04-13T04:15:30.425Z,1397362530.425 [science_to:SURFACECOMMS:B] Running Loop=1 2014-04-13T04:15:30.426Z,1397362530.426 [science_to:SURFACECOMMS:B](INFO): Aggregate::initialize science_to:SURFACECOMMS:B 2014-04-13T04:15:30.426Z,1397362530.426 [science_to:SURFACECOMMS:B:A] Running Loop=1 2014-04-13T04:15:30.426Z,1397362530.426 [science_to:D.Pitch] Running Loop=1 2014-04-13T04:15:30.431Z,1397362530.431 [science_to:OffshoreWrapper] Running Loop=1 2014-04-13T04:15:30.431Z,1397362530.431 [science_to:OffshoreWrapper](INFO): Aggregate::initialize science_to:OffshoreWrapper 2014-04-13T04:15:30.431Z,1397362530.431 [science_to:OffshoreWrapper:A.OffshoreEnvelope] Running Loop=1 2014-04-13T04:15:30.431Z,1397362530.431 [science_to:OffshoreWrapper:A.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent. 2014-04-13T04:15:30.431Z,1397362530.431 [science_to:OffshoreWrapper:A.OffshoreEnvelope] Running Loop=1 2014-04-13T04:15:30.436Z,1397362530.436 [science_to:B.DepthEnvelope] Running Loop=1 2014-04-13T04:15:30.441Z,1397362530.441 [science_to:AltEnvWrapper] Running Loop=1 2014-04-13T04:15:30.441Z,1397362530.441 [science_to:AltEnvWrapper](INFO): Aggregate::initialize science_to:AltEnvWrapper 2014-04-13T04:15:30.441Z,1397362530.441 [science_to:AltEnvWrapper:A.AltitudeEnvelope] Running Loop=1 2014-04-13T04:15:30.441Z,1397362530.441 [science_to:AltEnvWrapper:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent. 2014-04-13T04:15:30.442Z,1397362530.442 [science_to:AltEnvWrapper:A.AltitudeEnvelope] Running Loop=1 2014-04-13T04:15:30.567Z,1397362530.567 [WetLabsBB2FL](INFO): Opening uart, block timeout 10ths=4 2014-04-13T04:15:30.568Z,1397362530.568 [WetLabsBB2FL](INFO): Powering up 2014-04-13T04:15:30.679Z,1397362530.679 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4 2014-04-13T04:15:30.866Z,1397362530.866 [science_to:SURFACECOMMS:B] Stopped 2014-04-13T04:15:30.867Z,1397362530.867 [science_to:SURFACECOMMS:B](INFO): Aggregate::uninitialize science_to:SURFACECOMMS:B 2014-04-13T04:15:30.867Z,1397362530.867 [science_to:SURFACECOMMS:B:A] Stopped 2014-04-13T04:15:30.867Z,1397362530.867 [science_to:SURFACECOMMS:C] Running Loop=1 2014-04-13T04:15:30.867Z,1397362530.867 [science_to:SURFACECOMMS:C](INFO): Aggregate::initialize science_to:SURFACECOMMS:C 2014-04-13T04:15:30.867Z,1397362530.867 [science_to:SURFACECOMMS:C:A] Running Loop=1 2014-04-13T04:15:31.337Z,1397362531.337 [science_to:K.YoYo] Preempted 2014-04-13T04:15:31.337Z,1397362531.337 [science_to:J.DepthEnvelope] Preempted 2014-04-13T04:15:31.337Z,1397362531.337 [science_to:I.SetSpeed] Preempted 2014-04-13T04:15:31.337Z,1397362531.337 [science_to:H.Buoyancy] Preempted 2014-04-13T04:15:31.337Z,1397362531.337 [science_to:Science] Preempted 2014-04-13T04:15:31.337Z,1397362531.337 [science_to:Science:D] Preempted 2014-04-13T04:15:31.337Z,1397362531.337 [science_to:Science:G] Preempted 2014-04-13T04:15:31.337Z,1397362531.337 [science_to:Science:PeakDetectChl] Preempted 2014-04-13T04:15:31.339Z,1397362531.339 [science_to:SURFACECOMMS:C:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2014-04-13T04:15:31.824Z,1397362531.824 [WetLabsBB2FL](INFO): Powering down 2014-04-13T04:15:31.856Z,1397362531.856 [NAL9602](INFO): SBD MO Status=1, MOMSN=25225, MT Status=0, MTMSN=0 2014-04-13T04:15:31.908Z,1397362531.908 [NAL9602](INFO): Sent 332 bytes from file Logs/20140413T040209/Express0017.lzma 2014-04-13T04:15:31.908Z,1397362531.908 [NAL9602](INFO): Packets left to send: 1 2014-04-13T04:15:31.910Z,1397362531.910 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T040209/Express0017.lzma.parts/0001.sbd 2014-04-13T04:15:33.988Z,1397362533.988 [NAL9602](IMPORTANT): GPS fix at: 1397362498.00 2014-04-13T04:15:34.032Z,1397362534.032 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T04:15:34.036Z,1397362534.036 [science_to:SURFACECOMMS:C:A] Stopped 2014-04-13T04:15:34.036Z,1397362534.036 [science_to:SURFACECOMMS:C:B] Running Loop=1 2014-04-13T04:15:34.439Z,1397362534.439 [science_to:SURFACECOMMS:C:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2014-04-13T04:15:46.262Z,1397362546.262 [NAL9602](INFO): SBD MO Status=1, MOMSN=25226, MT Status=0, MTMSN=0 2014-04-13T04:15:46.322Z,1397362546.322 [NAL9602](INFO): Sent 45 bytes from file Logs/20140413T040209/Courier0020.lzma 2014-04-13T04:15:46.323Z,1397362546.323 [NAL9602](INFO): Packets left to send: 0 2014-04-13T04:15:46.324Z,1397362546.324 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T040209/Courier0020.lzma.parts/0000.sbd 2014-04-13T04:15:46.325Z,1397362546.325 [NAL9602](INFO): Completed sending Logs/20140413T040209/Courier0020.lzma 2014-04-13T04:15:54.701Z,1397362554.701 [NAL9602](INFO): SBD MO Status=1, MOMSN=25227, MT Status=0, MTMSN=0 2014-04-13T04:15:54.756Z,1397362554.756 [NAL9602](INFO): Sent 25 bytes from file Logs/20140413T040209/Courier0024.lzma 2014-04-13T04:15:54.756Z,1397362554.756 [NAL9602](INFO): Packets left to send: 0 2014-04-13T04:15:54.757Z,1397362554.757 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T040209/Courier0024.lzma.parts/0000.sbd 2014-04-13T04:15:54.758Z,1397362554.758 [NAL9602](INFO): Completed sending Logs/20140413T040209/Courier0024.lzma 2014-04-13T04:16:05.736Z,1397362565.736 [NAL9602](INFO): SBD MO Status=1, MOMSN=25228, MT Status=0, MTMSN=0 2014-04-13T04:16:05.785Z,1397362565.785 [NAL9602](INFO): Sent 234 bytes from file Logs/20140413T040209/Express0017.lzma 2014-04-13T04:16:05.785Z,1397362565.785 [NAL9602](INFO): Packets left to send: 0 2014-04-13T04:16:05.786Z,1397362565.786 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T040209/Express0017.lzma.parts/0000.sbd 2014-04-13T04:16:05.786Z,1397362565.786 [NAL9602](INFO): Completed sending Logs/20140413T040209/Express0017.lzma 2014-04-13T04:16:25.799Z,1397362585.799 [NAL9602](INFO): SBD MO Status=1, MOMSN=25229, MT Status=0, MTMSN=0 2014-04-13T04:16:25.852Z,1397362585.852 [NAL9602](INFO): Sent 332 bytes from file Logs/20140413T040209/Express0021.lzma 2014-04-13T04:16:25.852Z,1397362585.852 [NAL9602](INFO): Packets left to send: 1 2014-04-13T04:16:25.854Z,1397362585.854 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T040209/Express0021.lzma.parts/0001.sbd 2014-04-13T04:16:35.475Z,1397362595.475 [NAL9602](INFO): SBD MO Status=1, MOMSN=25230, MT Status=0, MTMSN=0 2014-04-13T04:16:35.535Z,1397362595.535 [NAL9602](INFO): Sent 146 bytes from file Logs/20140413T040209/Express0021.lzma 2014-04-13T04:16:35.535Z,1397362595.535 [NAL9602](INFO): Packets left to send: 0 2014-04-13T04:16:35.536Z,1397362595.536 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T040209/Express0021.lzma.parts/0000.sbd 2014-04-13T04:16:35.536Z,1397362595.536 [NAL9602](INFO): Completed sending Logs/20140413T040209/Express0021.lzma 2014-04-13T04:16:46.781Z,1397362606.781 [NAL9602](INFO): SBD MO Status=1, MOMSN=25231, MT Status=0, MTMSN=0 2014-04-13T04:16:46.828Z,1397362606.828 [NAL9602](INFO): Sent 245 bytes from file Logs/20140413T040209/Express0025.lzma 2014-04-13T04:16:46.829Z,1397362606.829 [NAL9602](INFO): Packets left to send: 0 2014-04-13T04:16:46.830Z,1397362606.830 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T040209/Express0025.lzma.parts/0000.sbd 2014-04-13T04:16:46.831Z,1397362606.831 [NAL9602](INFO): Completed sending Logs/20140413T040209/Express0025.lzma 2014-04-13T04:16:49.547Z,1397362609.547 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 2 of 46 2014-04-13T04:16:49.547Z,1397362609.547 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 33.5 32.1 32.8 33.4 410.1 465.3 423.0 338.2 300 399 373 187 8 8 8 8 -17.2 169.6 97.7 -68.5 457.8 1 -97 282 339 2 262 -142 339 2 6.77 -1.09 222.5 32.1 14.5 0.00489 126 2014-04-13T04:16:54.008Z,1397362614.008 [NAL9602](INFO): SBD MO Status=0, MOMSN=25232, MT Status=0, MTMSN=0 2014-04-13T04:16:54.090Z,1397362614.090 [science_to:SURFACECOMMS:C:B] Stopped 2014-04-13T04:16:54.090Z,1397362614.090 [science_to:SURFACECOMMS:C:C] Running Loop=1 2014-04-13T04:16:54.502Z,1397362614.502 [science_to:SURFACECOMMS:C:C](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2014-04-13T04:16:56.695Z,1397362616.695 [NAL9602](IMPORTANT): GPS fix at: 1397362581.00 2014-04-13T04:16:56.708Z,1397362616.708 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T04:16:56.712Z,1397362616.712 [science_to:SURFACECOMMS:C:C] Stopped 2014-04-13T04:16:56.712Z,1397362616.712 [science_to:SURFACECOMMS:C](INFO): Completed science_to:SURFACECOMMS:C 2014-04-13T04:16:56.712Z,1397362616.712 [science_to:SURFACECOMMS:C] Stopped 2014-04-13T04:16:56.712Z,1397362616.712 [science_to:SURFACECOMMS:C](INFO): Aggregate::uninitialize science_to:SURFACECOMMS:C 2014-04-13T04:16:56.713Z,1397362616.713 [science_to:SURFACECOMMS](INFO): Completed science_to:SURFACECOMMS 2014-04-13T04:16:56.713Z,1397362616.713 [science_to:SURFACECOMMS] Stopped 2014-04-13T04:16:56.713Z,1397362616.713 [science_to:SURFACECOMMS](INFO): Aggregate::uninitialize science_to:SURFACECOMMS 2014-04-13T04:16:56.714Z,1397362616.714 [science_to:SURFACECOMMS:A.GoToSurface] Stopped 2014-04-13T04:16:56.714Z,1397362616.714 [science_to:SURFACECOMMS:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T04:16:56.714Z,1397362616.714 [science_to:Wpt1] Running Loop=1 2014-04-13T04:16:56.714Z,1397362616.714 [science_to:Wpt1](INFO): Aggregate::initialize science_to:Wpt1 2014-04-13T04:16:56.714Z,1397362616.714 [science_to:Wpt1:A.Waypoint] Running Loop=1 2014-04-13T04:16:56.714Z,1397362616.714 [science_to:Wpt1:A.Waypoint](DEBUG): Initialize WaypointComponent. 2014-04-13T04:16:57.179Z,1397362617.179 [science_to:K.YoYo] Running Loop=1 2014-04-13T04:16:57.180Z,1397362617.180 [science_to:J.DepthEnvelope] Running Loop=1 2014-04-13T04:16:57.181Z,1397362617.181 [science_to:I.SetSpeed] Running Loop=1 2014-04-13T04:16:57.181Z,1397362617.181 [science_to:H.Buoyancy] Running Loop=1 2014-04-13T04:16:57.181Z,1397362617.181 [science_to:Science] Running Loop=1 2014-04-13T04:16:57.182Z,1397362617.182 [science_to:Science:PeakDetectChl] Running Loop=1 2014-04-13T04:16:57.183Z,1397362617.183 [science_to:Science:G] Running Loop=1 2014-04-13T04:16:57.183Z,1397362617.183 [science_to:Science:D] Running Loop=1 2014-04-13T04:16:57.274Z,1397362617.274 [WetLabsBB2FL](INFO): Opening uart, block timeout 10ths=4 2014-04-13T04:16:57.274Z,1397362617.274 [WetLabsBB2FL](INFO): Powering up 2014-04-13T04:16:57.472Z,1397362617.472 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4 2014-04-13T04:17:03.582Z,1397362623.582 [NAL9602](INFO): Powering down 2014-04-13T04:17:06.169Z,1397362626.169 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 2 of 46 2014-04-13T04:17:06.169Z,1397362626.169 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 32.0 31.7 32.3 32.6 32.8 317.7 512.4 201.2 68 377 470 239 7 7 8 8 -640.1 155.5 286.9 1 488.8 459.1 257.9 1 -536 184 311 2 449 346 311 2 0.05 -2.58 236.6 31.7 14.5 0.005 35.0 1489 118 2014-04-13T04:17:11.748Z,1397362631.748 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T04:17:11.749Z,1397362631.749 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 31.4 33.9 34.6 32.0 -255.3 118.4 424.0 80.2 -277 164 381 12 7 8 9 7 -878.2 202.9 75.5 2 542.6 7192 -878 202 75 2 542 719 75 2 -6.50 -6.76 246.0 31.4 14.6 0.005 35.0 1489 86 2014-04-13T04:17:20.016Z,1397362640.016 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T04:17:20.016Z,1397362640.016 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 33.0 32.8 31.7 31.5 86.1 626.3 829.8 273.7 31 571 632 1 7 -992.6 470.6 489.6 1 532.7 974.2 462.2 1 -802 531 379 2 553 786 379 2 -4.18 0.48 268.4 31.5 14.5 0.005 35.0 1489 114 2014-04-13T04:17:21.160Z,1397362641.160 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:112 Calculated:99 2014-04-13T04:17:21.160Z,1397362641.160 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 33.4 34.9 33.1 31.6 249.4 379.9 589.9 197.2 36 290 400 188 8 9 8 7 -454.4 243.8 381.5 490.8 340.5 1 -485 136 246 2 67 500 246 2 -8.97 0.16 278.0 31.6 14.5 0.005 35.0 1489 112 2014-04-13T04:17:22.230Z,1397362642.230 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T04:17:22.230Z,1397362642.230 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 32.1 33.3 33.8 32.4 -536.7 -466.3 -326.9 -357.7 -476 -484 -377 -362 7 8 8 7 -280.0 -144.9 -455.1 1 -270.1 179.4 -448.7-162 -458 2 -204 47 -458 2 -2.39 -0.01 296.1 32.1 14.5 0.005 35.0 1489 108 2014-04-13T04:17:23.314Z,1397362643.314 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T04:17:23.314Z,1397362643.314 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 33.9 39.5 33.4 30.1 -357.0 146.0 270.5 -263.1 -296 102 266 -196 8 11 8 6 -750.1 397.7 -33.5 2 96.6 843.5 -33.5 2 -750 397 -33 2 33 2 -20.78 -1.20 291.4 30.1 14.6 0.005 35.0 1489 85 2014-04-13T04:17:26.976Z,1397362646.976 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:98 Calculated:112 2014-04-13T04:17:26.976Z,1397362646.976 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 31.7 32.9 33.9 32.0 -511.3 -384.5 -334.4 -391.2 -426 -398 -301 -310 7 8 8 7 -236.1 .2 1 -155.3 141.4 -450.4 1 -166 -117 -386 2 -203 13 -386 2 0.52 -3.42 321.2 31.7 14.6 0.005 35.0 1489 98 2014-04-13T04:17:39.102Z,1397362659.102 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T04:17:39.102Z,1397362659.102 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 0 1 29.6 33.9 0 34.2 210.2 310.6 0 291.1 127 155 328 320 6 8 25 9 -242.0 26.0 324.5 1 -327.6 -82.6 224.6 1 -268 -220 250 2 -177 -298 250 2 -1.46 -19.46 1 14.6 0.005 35.0 1489 120 2014-04-13T04:17:41.610Z,1397362661.610 [Radio_Freewave](INFO): Powering down 2014-04-13T04:17:46.595Z,1397362666.595 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 44 of 46 2014-04-13T04:17:46.595Z,1397362666.595 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 28.0 31.9 40.7 33.5 -360.3 -303.7 16.3 -88.4 -339 -156 -6 32 6 8 12 8 -502.6 -287.3 -198.5 1 155.0 -442.9 -392.9 1 -444 -250107 -498 -126 2 1.41 -24.02 72.7 28.0 14.6 0.005 35.0 1489 121 2014-04-13T04:17:47.756Z,1397362667.756 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:73 Calculated:77 2014-04-13T04:17:47.757Z,1397362667.757 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 27.8 3132.3 -162.6 -127.0 141.5 72.5 -224 -114 73 80 6 8 11 8 -405.9 -266.3 -20.4 1 193.5 -410.3 -173.9 1 -396 -258 -49 2 185 -435 -49 2 2.15 -20.92 79.9 27.8 14.6 0.005 35.0 1489 73 2014-04-13T04:18:07.149Z,1397362687.149 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T04:18:07.149Z,1397362687.149 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 24.0 31.1 37.2 26.3 -181.1 71.6 302.1 84.7 -284 -33 216 94 4 8 11 6 -644.9 -17.5 74.8 1 -141.8 -598.5 -667 -169 -1 2 -22 -688 -1 2 -10.03 -25.51 73.9 24.0 14.6 0.005 35.0 1489 105 2014-04-13T04:18:42.750Z,1397362722.750 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T04:18:42.750Z,1397362722.750 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 14.7 18.1 21.2 17.1 -267.3 64.0 375.2 44.0 -175 130 404 90 2 4 4 3 -857.5 26.7 58.2 1 -336.9 -743.6 -270.1 1 -772 53 121 2 -357 -687 121 221.92 66.5 14.7 14.5 0.005 35.0 1489 112 2014-04-13T04:18:43.951Z,1397362723.951 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T04:18:43.951Z,1397362723.951 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 14.4 17.9 20.3 15.8 -234.7 122.8 364.8 30.3 -336 142 456 71 2 3 4 2 -800.1 123.5 76.4 1 -415.2 -654.0 -247.5 1 -1057 94 8 -926 89 2 -7.42 -22.15 65.9 14.4 14.4 0.005 35.0 1489 66 2014-04-13T04:19:05.146Z,1397362745.146 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:73 Calculated:83 2014-04-13T04:19:05.146Z,1397362745.146 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 17.2 15.3 12.6 1.4 56.0 337.2 -81.1 -370 61 383 -113 4 3 1 2 -809.6 183.0 11.5 1 -377.1 -678.1 295.1 1 -1005 232 -10 2 -473 -916 -10 2 -5.36 21.87 75.7 12.6 14.0 0.005 35.0 1489 73 2014-04-13T04:19:22.307Z,1397362762.307 [CTD_NeilBrown](ERROR): Bad response: ,33.8473 2014-04-13T04:19:29.396Z,1397362769.396 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T04:19:29.397Z,1397362769.397 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 28.9 24.6 20.1 22.1 -340.9 67.5 387.6 -25.4 -400 -59 426 -18 8 5 4 4 -972.3 124.0 23.9 1 -331.6 -848.4 362.6 1 -1102 -54 -13 2 -173 -1089 -13 2 .50 78.1 20.1 13.4 0.005 35.0 1489 122 2014-04-13T04:19:31.903Z,1397362771.903 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:90 Calculated:94 2014-04-13T04:19:31.905Z,1397362771.905 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 30.0 26.1 20.9 22.8 -275.4 76.7 368.38 4 386 38 8 6 4 4 -859.1 101.8 45.8 1 -290.9 -732.5 359.4 1 -926 -45 32 2 -149 -915 32 2 -7.88 22.71 77.9 20.9 13.3 0.005 35.0 1489 90 2014-04-13T04:19:34.554Z,1397362774.554 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:107 Calculated:100 2014-04-13T04:19:34.554Z,1397362774.554 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 30.2 26.3 21.7 24.6 -278.8 86.3 428.6 56.1 -378 35 486 87 8 6 41 40.3 78.8 1 -245.8 -803.9 438.6 1 -1153 -69 62 2 -181 -1140 62 2 -5.46 23.10 77.5 21.7 13.3 0.005 35.0 1489 107 2014-04-13T04:19:45.751Z,1397362785.751 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T04:19:45.752Z,1397362785.752 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 31.0 31.1 25.8 26.9 -164.4 95.8 328.8 93.7 -182 18 368 174 7 7 5 5 -658.2 2.8 95.4 1 -209.2 -562.2 287.0 1 -734 2 -18 -762 101 2 -9.00 17.48 72.8 25.8 13.1 0.005 35.0 1489 110 2014-04-13T04:19:46.977Z,1397362786.977 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:90 Calculated:73 2014-04-13T04:19:46.978Z,1397362786.978 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 34.0 30.9 26.0 27.3 -183.09.8 191.9 -200 -17 379 195 9 8 5 6 -804.5 -143.5 138.3 1 -158.9 -712.9 391.7 1 -772 -282 96 2 -7 -822 96 2 -8.72 17.33 69.4 26.0 13.0 0.005 35.0 1489 90 2014-04-13T04:19:53.499Z,1397362793.499 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T04:19:53.499Z,1397362793.499 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 34.3 35.3 28.2 29.3 -341.1 22.0 455.8 197.5 -336 -123 447 127 9 10 6 7 -1063.6 -234.2 90.1 1 -225.4 -983.3 420.4 1 -1045 -333 31 2 -114 -1091 31 2 -9.93 .3 28.2 13.0 0.005 35.0 1489 80 2014-04-13T04:19:57.453Z,1397362797.453 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 2 of 46 2014-04-13T04:19:57.453Z,1397362797.453 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0001 28.6 33.0 33.4 28.9 -191.3 51.7 385.7 163.6 -206 -22 451 249 6 8 8 6 -770.1 -149.3 110.4 1 -385.8 -691.9 -1.5 1 -876 -361 127 2 -275 -907 127 2 -10.01 -10.06 50.7 28.6 13.0 0.005 35.0 1489 100 2014-04-13T04:20:10.110Z,1397362810.110 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:92 Calculated:64 2014-04-13T04:20:10.110Z,1397362810.110 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 25.2 30.6 32.5 26.5 -202.2 38.3 231.1 -11.8 -248 -40 170 86 5 8 8 5 -59 14.9 1 -471.4 -300.9 -162.3 1 -557 -168 -8 2 -333 -477 -8 2 -8.33 -16.76 38.3 25.2 13.1 0.005 35.0 1489 92 2014-04-13T04:20:12.778Z,1397362812.778 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:81 Calculated:73 2014-04-13T04:20:12.778Z,1397362812.778 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 24.7 29.1 31.1 26.4 -385.1 -61.6 247.0 -59.9 -457 -124 212 -13 5 7 8 5 -843.6 -2.3 -70.0 1 -607.4 -57.8 1 -892 -148 -103 2 -607 -670 -103 2 -5.87 -15.90 38.4 24.7 13.1 0.005 35.0 1489 81 2014-04-13T04:21:01.752Z,1397362861.752 [CTD_NeilBrown](ERROR): Bad response: 16.20 2014-04-13T04:21:11.580Z,1397362871.580 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 4 of 46 2014-04-13T04:21:11.581Z,1397362871.581 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 12.6 11.6 11.3 -349.4 71.3 308.7 -77.0 -376 39 307 15 1 1 1 2 -878.3 197.9 -12.5 1 -567.8 -698.6 12.4 1 -911 32 -4 2 -434 -802 -4 2 -7.05 3.21 63.6 11.3 13.1 0.005 35.0 1489 123 2014-04-13T04:22:36.567Z,1397362956.567 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:123 Calculated:120 2014-04-13T04:22:36.568Z,1397362956.568 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 22.6 26.6 28.6 24.1 -350.6 -25.6 240.5 -74.6 -369 -72 268 -9 4 6 7 5 -.4 -56.7 1 -603.0 -436.3 -275.5 1 -850 -84 -49 2 -603 -604 -49 2 -6.69 -15.72 39.4 22.6 12.9 0.005 35.0 1489 123 2014-04-13T04:23:14.544Z,1397362994.544 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:115 Calculated:96 2014-04-13T04:23:14.544Z,1397362994.544 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 13.1 16.4 18.6 14.7 -284.3 205.-34.4 -192 97 394 -65 1 3 4 2 -904.5 319.5 75.4 1 -708.3 -576.9 -302.3 1 -782 216 63 2 -590 -557 63 2 -6.10 -21.93 58.8 13.1 13.1 0.005 35.0 1489 115 2014-04-13T04:23:39.233Z,1397363019.233 [DVL_micro](ERROR): No DVL communication! Re-initializing 2014-04-13T04:23:39.233Z,1397363019.233 [DVL_micro] Communications Fault, FailCount= 1 2014-04-13T04:23:39.233Z,1397363019.233 [DVL_micro](ERROR): Communications Fault 2014-04-13T04:23:39.336Z,1397363019.336 [CBIT](ERROR): Communications Fault in component: DVL_micro 2014-04-13T04:23:39.865Z,1397363019.865 [DVL_micro](INFO): uninitialize:Powering down 2014-04-13T04:23:40.331Z,1397363020.331 [DVL_micro](FAULT): LCB fault: Software Overcurrent. 2014-04-13T04:23:40.331Z,1397363020.331 [DVL_micro] Hardware Fault, FailCount= 1 2014-04-13T04:23:40.331Z,1397363020.331 [DVL_micro](ERROR): Hardware Fault 2014-04-13T04:23:40.994Z,1397363020.994 [CBIT](INFO): Clearing failed state for component DVL_micro 2014-04-13T04:23:40.994Z,1397363020.994 [DVL_micro] No Fault, FailCount= 1 2014-04-13T04:23:41.395Z,1397363021.395 [DVL_micro](INFO): Initializing 2014-04-13T04:24:12.599Z,1397363052.599 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 2 of 46 2014-04-13T04:24:12.599Z,1397363052.599 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 .0 28.7 23.7 25.4 -234.2 -23.5 322.4 83.7 -364 -74 407 86 8 7 4 5 -742.9 -143.1 40.0 1 -6.1 -696.9 297.0 1 -1029 -213 14 2 22 -1050 14 2 -7.31 18.96 79.5 23.7 12.5 0.005 35.0 1489 84 2014-04-13T04:24:37.256Z,1397363077.256 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 2 of 46 2014-04-13T04:24:37.256Z,1397363077.256 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0001 25.4 33.0 36.3 27.7 -386.5 -130.2 177.7 -59.3 -352 -168 86 -29 5 9 10 6 -753.0 -94.6 -107.4 1 -410.0 -543.5 -352.2 1 -584 -185 -124 2 -316 -525 -124 2 -10.37 -21.09 41.3 25.4 12.6 0.005 35.0 1489 82 2014-04-13T04:25:19.051Z,1397363119.051 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T04:25:19.051Z,1397363119.051 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 15.7 18.6 21.3 17.3 -243.4 115.4 332.5 -14.9 -334 132 402 15 2 4 4 3 -768.6 173.9 51.1 1 -556.0 -513.9 -224. 156 58 2 -686 -719 58 2 -5.13 -19.50 55.4 15.7 13.1 0.005 35.0 1489 100 2014-04-13T04:25:30.475Z,1397363130.475 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T04:25:30.475Z,1397363130.475 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 13.0 16.3 18.1 14.0 -276.2 87.4 402.6 47.4 -128 29 346 160 1 3 4 2 -906.0 53.4 70.4 1 -478.2 -728.1 -264.3 174 109 2 -173 -632 109 2 -8.86 -20.75 59.2 13.0 13.2 0.005 35.0 1489 96 2014-04-13T04:25:38.410Z,1397363138.410 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:75 Calculated:78 2014-04-13T04:25:38.410Z,1397363138.410 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 11.0 12.9 13.8 11.4 -245.5 127.6 383.360 107 359 0 1 1 2 1 -840.0 89.0 88.1 1 -524.7 -653.6 -137.1 1 -959 142 28 2 -641 -728 28 2 -8.08 -14.41 57.1 11.0 13.1 0.005 35.0 1489 75 2014-04-13T04:25:57.191Z,1397363157.191 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 24 of 46 2014-04-13T04:25:57.191Z,1397363157.191 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 19.5 18.1 15.2 15.8 -276.7 103.2 385.4 -5.1 -346 7 384 4 4 4 2 2 -883.7 144.5 55..1 -773.6 312.4 1 -974 4 13 2 -194 -954 13 2 -8.34 18.56 78.7 15.2 12.9 0.005 35.0 1489 101 2014-04-13T04:26:24.365Z,1397363184.365 [CTD_NeilBrown](ERROR): Bad response: 40.56277 2014-04-13T04:26:37.806Z,1397363197.806 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:117 Calculated:119 2014-04-13T04:26:37.806Z,1397363197.806 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 34.9 32.4 26.9 28.2 -149.6 4.7 292.6 -252 13 483 225 10 8 6 6 -1020.1 -91.8 264.6 1 -242.7 -851.1 579.3 1 -981 -282 126 2 -27 -1020 126 2 -8.69 18.12 72.4 26.9 12.7 0.005 35.0 1489 117 2014-04-13T04:26:44.043Z,1397363204.043 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:114 Calculated:101 2014-04-13T04:26:44.043Z,1397363204.043 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 28.1 32.6 32.1 28.0 -235.7 -76.0 240.3 90.7 -271 -54 331 128 6 8 8 6 -63.5 5.2 1 -147.5 -654.3 -57.0 1 -803 -242 36 2 -226 -808 36 2 -10.25 -9.21 57.5 28.0 12.7 0.005 35.0 1489 114 2014-04-13T04:26:53.789Z,1397363213.789 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:100 Calculated:103 2014-04-13T04:26:53.790Z,1397363213.790 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 25.4 31.5 35.7 27.3 -185.8 54.5 328.0 73.30 171 46 5 8 10 6 -685.7 -24.8 72.7 1 -502.1 -445.4 -160.0 1 -583 -101 -21 2 -391 -444 -21 2 -9.83 -19.73 38.8 25.4 12.8 0.005 35.0 1489 100 2014-04-13T04:26:58.746Z,1397363218.746 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:127 Calculated:123 2014-04-13T04:26:58.746Z,1397363218.746 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 24.2 28.2 30.3 25.5 59.0 233.3 -0.8 -346 -147 258 31 5 6 8 5 -710.3 -77.7 -33.8 1 -484.8 -482.7 -208.9 1 -806 -237 -55 2 -497 -677 -55 2 -5.82 -15.04 37.3 24.2 12.9 0.005 35.0 1489 127 2014-04-13T04:27:29.150Z,1397363249.150 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:123 Calculated:99 2014-04-13T04:27:29.150Z,1397363249.150 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 16.6 19.9 21.9 18.1 -350.6 74.8 282.9 -102.6 347 2 2 4 4 3 -845.5 237.0 -25.8 1 -651.2 -504.1 -305.9 1 -900 58 18 2 -584 -688 18 2 -5.02 -17.96 53.4 16.6 13.2 0.005 35.0 1489 123 2014-04-13T04:27:57.401Z,1397363277.401 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 44 of 46 2014-04-13T04:27:57.401Z,1397363277.401 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 12.6 12.2 10.7 10.9 -425.3 -29.9 312.8 -135.8 -353 39 130 73 1 1 1 2 -985.1 141.3 -75.1 1 -522.3 -847.6 69.6 1 -644 -45 -30 2 -215 -609 -30 2 -7.34 9.42 66.5 10.7 13.1 0.005 3575 2014-04-13T04:28:33.137Z,1397363313.137 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 44 of 46 2014-04-13T04:28:33.138Z,1397363313.138 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 26.6 24.1 20.3 21.5 -238.2 151.8 427.0 51.3 -355 38 339 100 6 5 4 4 -887.8 134.1 105.6 1 -342.7 -754.5 361.3 1 -926 -82 32 2 -123 -921 32 2 -8.17 18.48 77.3 20.3 12.6 0.00489 109 2014-04-13T04:29:30.596Z,1397363370.596 [AHRS_sp3003D](ERROR): readPitchRollBin UART error: serial timeout 2014-04-13T04:29:30.761Z,1397363370.761 [AHRS_sp3003D](FAULT): Read Heading/Pitch/Roll Failure. 2014-04-13T04:29:30.761Z,1397363370.761 [AHRS_sp3003D] Communications Fault, FailCount= 1 2014-04-13T04:29:30.761Z,1397363370.761 [AHRS_sp3003D](ERROR): Communications Fault 2014-04-13T04:29:31.049Z,1397363371.049 [CBIT](ERROR): Communications Fault in component: AHRS_sp3003D 2014-04-13T04:29:31.095Z,1397363371.095 [AHRS_sp3003D](INFO): Powering down 2014-04-13T04:29:32.510Z,1397363372.510 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D 2014-04-13T04:29:32.510Z,1397363372.510 [AHRS_sp3003D] No Fault, FailCount= 1 2014-04-13T04:29:32.676Z,1397363372.676 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2014-04-13T04:31:25.186Z,1397363485.186 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout 2014-04-13T04:31:25.314Z,1397363485.314 [AHRS_sp3003D](ERROR): readAccelVecBin UART error: serial timeout 2014-04-13T04:31:25.314Z,1397363485.314 [AHRS_sp3003D](ERROR): readAccelVecBin got 0xAEFFA0 2014-04-13T04:31:25.314Z,1397363485.314 [AHRS_sp3003D](FAULT): Read Heading/Pitch/Roll Failure. 2014-04-13T04:31:25.315Z,1397363485.315 [AHRS_sp3003D] Communications Fault, FailCount= 1 2014-04-13T04:31:25.315Z,1397363485.315 [AHRS_sp3003D](ERROR): Communications Fault 2014-04-13T04:31:25.627Z,1397363485.627 [CBIT](ERROR): Communications Fault in component: AHRS_sp3003D 2014-04-13T04:31:25.679Z,1397363485.679 [AHRS_sp3003D](INFO): Powering down 2014-04-13T04:31:27.041Z,1397363487.041 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D 2014-04-13T04:31:27.041Z,1397363487.041 [AHRS_sp3003D] No Fault, FailCount= 1 2014-04-13T04:31:27.269Z,1397363487.269 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2014-04-13T04:31:58.242Z,1397363518.242 [CTD_NeilBrown](ERROR): Bad response: 1.36896 2014-04-13T04:32:30.369Z,1397363550.369 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 4 of 46 2014-04-13T04:32:30.369Z,1397363550.369 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 16 17.1 14.2 15.3 -260.5 122.0 393.5 -16.6 -375 45 368 -45 4 3 2 2 -872.9 185.0 64.2 1 -81.6 299.0 1 -991 120 -1 2 -250 -966 -2 17.56 82.4 14.2 12.6 0.005 35.0 1489 113 2014-04-13T04:32:48.218Z,1397363568.218 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:90 Calculated:79 2014-04-13T04:32:48.218Z,1397363568.218 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 25.8 23.0.3 -319.5 46.0 361.4 24.1 -372 -22 426 -19 6 5 3 4 -908.8 29.2 30.2 1 -241.0 -817.3 318.7 1 -1065 -4 3 2 -232 -1039 3 2 -7.87 18.91 77.2 19.0 12.4 0.005 35.0 1489 90 2014-04-13T04:33:14.565Z,1397363594.565 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 2 of 46 2014-04-13T04:33:14.566Z,1397363594.566 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 15.8 31.1 33.4 26.9 -154.0 65.0 307.4 92.9 -164 -18 260 35 5 8 9 6 -615.8 -37.2 83.9 1 -326.3 -523.4 -84.4 1 -565 -70 30 2 -270 -502 30 2 -8.52 -15.99 54.6 25.8 12.3 0.005 35.0 1489 93 2014-04-13T04:34:16.283Z,1397363656.283 [ThrusterServo](FAULT): Invalid EZ Servo response:"" 2014-04-13T04:34:16.283Z,1397363656.283 [ThrusterServo] Communications Fault, FailCount= 1 2014-04-13T04:34:16.283Z,1397363656.283 [ThrusterServo](ERROR): Communications Fault 2014-04-13T04:34:16.286Z,1397363656.286 [CBIT](ERROR): Communications Fault in component: ThrusterServo 2014-04-13T04:34:16.848Z,1397363656.848 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2014-04-13T04:34:16.849Z,1397363656.849 [ThrusterServo](INFO): Powering down 2014-04-13T04:34:17.926Z,1397363657.926 [ThrusterServo](DEBUG): Initializing EZServoServo. 2014-04-13T04:34:18.051Z,1397363658.051 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2014-04-13T04:34:18.054Z,1397363658.054 [CBIT](INFO): Clearing failed state for component ThrusterServo 2014-04-13T04:34:18.054Z,1397363658.054 [ThrusterServo] No Fault, FailCount= 1 2014-04-13T04:34:21.977Z,1397363661.977 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:67 Calculated:88 2014-04-13T04:34:21.978Z,1397363661.978 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 11.4 10.8 9.7 10.0 -254.7 34.2 245.9 -55.2 -296 -13 197 -106 1 2 1 119.3 -8.0 1 -398.4 -538.8 108.1 1 -658 124 -58 2 -398 -538 -58 2 -5.58 11.01 64.2 9.7 12.7 0.005 35.0 1489 67 2014-04-13T04:34:26.007Z,1397363666.007 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 4 of 46 2014-04-13T04:34:26.007Z,1397363666.007 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X 1 1 10.2 12.9 10.2 11.9 189.8 -0.9 152.4 -72.0 -257 -233 128 14 1 2 1 1 49.9 94.9 72.6 1 -62.8 108.6 32.2 1 -513 -329 -93 2 106 -601 -93 2 -4.95 28.01 67.4 10.2 12.6 0.005 35.0 1489 74 2014-04-13T04:34:27.465Z,1397363667.465 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:108 Calculated:119 2014-04-13T04:34:27.466Z,1397363667.466 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 1 1 1 0 6 12.6 0 25.4 215.5 -66.9 -129 -11 319 -113 6 2 1 2 -630.6 123.2 -22.4 1 -335.5 -472.7 278.1 1 -597 136 17 2 -348 -504 17 2 -5.32 29.34 68.2 10.6 12.6 0.005 35.0 1489 108 2014-04-13T04:34:32.254Z,1397363672.254 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 2 of 46 2014-04-13T04:34:32.255Z,1397363672.255 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 16.8 14.4 11.9 13.4 -304.7 40.7 307.5 -20.5 -278 -7 178 -49 3 2 1 2 -817.1 81.7 6.2 1 -331.9 -685.3 307.5 1 -608 56 -42 2 -249 -558 -42 2 -4.09 22.12 71.2 11.9 12.6 0.005 35.0 1489 102 2014-04-13T04:35:19.406Z,1397363719.406 [CTD_NeilBrown](ERROR): Bad response: 2.13 2014-04-13T04:35:31.118Z,1397363731.118 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:78 Calculated:93 2014-04-13T04:35:31.118Z,1397363731.118 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 24.4 30.3 34.2 25.9 -275.9 -16.3 277.7 4.2 -318 -118 1 7 9 5 -738.9 -27.4 -2.8 1 -458.3 -518.3 -261.0 1 -559 -106 -100 2 -324 -467 -100 2 -9.36 -20.84 44.4 24.4 12.4 0.005 35.0 1489 78 2014-04-13T04:36:36.840Z,1397363796.840 [DVL_micro](ERROR): NQ1 sentence equals NULL. 2014-04-13T04:36:36.842Z,1397363796.842 [DVL_micro](ERROR): Failed to parse DVL response:89 75 2014-04-13T04:36:47.535Z,1397363807.535 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T04:36:47.536Z,1397363807.536 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 17.9 15.2 12.7 14.3 -269.3 147.5 395.4 14.0 -188 -6 321 10 4 3 1 2 -887.1 178.2 77.5 1 -357.8 -748.7 369.0 1 -679 -21 36 2 -116 -669 36 2 -5.06 20.63.7 12.6 0.005 35.0 1489 121 2014-04-13T04:36:49.954Z,1397363809.954 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T04:36:49.955Z,1397363809.955 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 18.1 16.2 13.8 14.5 -240.0 95.2 400.1 41.1 -276 34 502 51 4 3 2 2 -854.3 72.2 79.9 1 -250.7 -759.7 318.3 1 -1038 -22 83 2 -181 -1022 83 2 -6.94 17.11 78.7 6 0.005 35.0 1489 105 2014-04-13T04:37:09.449Z,1397363829.449 [CTD_NeilBrown](ERROR): Bad response: 8.866 2014-04-13T04:38:02.127Z,1397363882.127 [DVL_micro](ERROR): No DVL communication! Re-initializing 2014-04-13T04:38:02.127Z,1397363882.127 [DVL_micro] Communications Fault, FailCount= 1 2014-04-13T04:38:02.127Z,1397363882.127 [DVL_micro](ERROR): Communications Fault 2014-04-13T04:38:02.236Z,1397363882.236 [CBIT](ERROR): Communications Fault in component: DVL_micro 2014-04-13T04:38:02.706Z,1397363882.706 [DVL_micro](INFO): uninitialize:Powering down 2014-04-13T04:38:03.233Z,1397363883.233 [DVL_micro](FAULT): LCB fault: Software Overcurrent. 2014-04-13T04:38:03.233Z,1397363883.233 [DVL_micro] Hardware Fault, FailCount= 1 2014-04-13T04:38:03.233Z,1397363883.233 [DVL_micro](ERROR): Hardware Fault 2014-04-13T04:38:03.931Z,1397363883.931 [CBIT](INFO): Clearing failed state for component DVL_micro 2014-04-13T04:38:03.931Z,1397363883.931 [DVL_micro] No Fault, FailCount= 1 2014-04-13T04:38:04.398Z,1397363884.398 [DVL_micro](INFO): Initializing 2014-04-13T04:38:48.683Z,1397363928.683 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T04:38:48.684Z,1397363928.684 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 1 1 1 0 13.0 10.3 12.6 0 -38.5 233.1 -136.3 -318 -65 348 -13 5 2 1 2 -855.5 130.5 -94.3 1 -431.4 -670.6 349.1 1 -888 -69 -13 2 -279 -846 .62 30.81 67.3 10.3 12.7 0.005 35.0 1489 89 2014-04-13T04:38:48.711Z,1397363928.711 [science_to:Wpt1:A.Waypoint](INFO): Reached Waypoint: 33.608000,-118.019003 2014-04-13T04:38:48.712Z,1397363928.712 [science_to:Wpt1:A.Waypoint] Stopped 2014-04-13T04:38:48.712Z,1397363928.712 [science_to:Wpt1:A.Waypoint](DEBUG): Uninitialize WaypointComponent. 2014-04-13T04:38:48.712Z,1397363928.712 [science_to:Wpt1](INFO): Completed science_to:Wpt1 2014-04-13T04:38:48.712Z,1397363928.712 [science_to:Wpt1] Stopped 2014-04-13T04:38:48.712Z,1397363928.712 [science_to:Wpt1](INFO): Aggregate::uninitialize science_to:Wpt1 2014-04-13T04:38:48.713Z,1397363928.713 [science_to:Wpt2] Running Loop=1 2014-04-13T04:38:48.713Z,1397363928.713 [science_to:Wpt2](INFO): Aggregate::initialize science_to:Wpt2 2014-04-13T04:38:48.713Z,1397363928.713 [science_to:Wpt2:A.Waypoint] Running Loop=1 2014-04-13T04:38:48.713Z,1397363928.713 [science_to:Wpt2:A.Waypoint](DEBUG): Initialize WaypointComponent. 2014-04-13T04:39:12.838Z,1397363952.838 [DVL_micro](ERROR): No DVL communication! Re-initializing 2014-04-13T04:39:12.838Z,1397363952.838 [DVL_micro] Communications Fault, FailCount= 1 2014-04-13T04:39:12.838Z,1397363952.838 [DVL_micro](ERROR): Communications Fault 2014-04-13T04:39:13.067Z,1397363953.067 [CBIT](ERROR): Communications Fault in component: DVL_micro 2014-04-13T04:39:13.680Z,1397363953.680 [DVL_micro](INFO): uninitialize:Powering down 2014-04-13T04:39:14.139Z,1397363954.139 [DVL_micro](FAULT): LCB fault: Software Overcurrent. 2014-04-13T04:39:14.139Z,1397363954.139 [DVL_micro] Hardware Fault, FailCount= 1 2014-04-13T04:39:14.139Z,1397363954.139 [DVL_micro](ERROR): Hardware Fault 2014-04-13T04:39:14.784Z,1397363954.784 [CBIT](INFO): Clearing failed state for component DVL_micro 2014-04-13T04:39:14.784Z,1397363954.784 [DVL_micro] No Fault, FailCount= 1 2014-04-13T04:39:15.167Z,1397363955.167 [DVL_micro](INFO): Initializing 2014-04-13T04:39:55.834Z,1397363995.834 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T04:39:55.834Z,1397363995.834 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 23.7 30.5 34.0 25.6 -298.3 -51.1 383.8 145.4 -332 -24 381 230 4 8 9 5 -910.4 -262.3 48.5 1 342.2 -848.7 -250.3 1 -951 -339 68 2 404 2 -10.86 -22.18 94.0 23.7 12.6 0.005 35.0 1489 118 2014-04-13T04:40:55.271Z,1397364055.271 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:86 Calculated:89 2014-04-13T04:40:55.271Z,1397364055.271 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 10.5 10.3 9.2 9.1 -277.0 -0.6 254.7 27.6 -431 -55 251 -24 2 2 1 1 -709.6 -37.6 1.3 1 417.6 -5.7 1 -910 -41 -69 2 545 -729 -69 2 -8.42 8.84 124.2 9.1 12.9 0.005 35.0 1489 86 2014-04-13T04:40:56.561Z,1397364056.561 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T04:40:56.561Z,1397364056.561 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 11.9 11.0 9.1 9.7 -311.0 11.2 245.5 -23.5 -437 -7 272 -29 1 1 1 1 -742.7 46.3 -21.0 1 351.6 -626.9 194.1 1 -946 29 -54 21 -54 2 -7.39 17.23 123.9 9.1 12.9 0.005 35.0 1489 118 2014-04-13T04:41:02.077Z,1397364062.077 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:109 Calculated:123 2014-04-13T04:41:02.078Z,1397364062.078 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 1 1 1 0 14.6 11.2 13.8 0 34.2 313.2 -9.2 -432 114 367 -77 6 3 2 2 -802.7 57.9 13.5 1 371.7 38.9 1 -1066 254 -7 2 476 -987 -7 2 -2.32 32.39 129.2 11.2 12.9 0.005 35.0 1489 109 2014-04-13T04:41:50.305Z,1397364110.305 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 29 of 46 2014-04-13T04:41:50.306Z,1397364110.306 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 31.5 30.1 26.1 26.3 -555.3 -292.5 90.6 -164.5 -634 -292 216 -184 8 7 5 5 -862.0 -170.8 -248.5 1 689.0 -596.0 -63. 70 2014-04-13T04:43:21.742Z,1397364201.742 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:92 Calculated:72 2014-04-13T04:43:21.742Z,1397364201.742 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 20.3 19.3 3 -206.8 130.7 390.1 45.9 -411 33 363 -43 4 4 2 3 -796.6 113.2 97.0 1 421.3 -625.5 296.8 1 -1033 101 -15 2 661 -799 -15 2 -9.61 16.34 135.2 15.7 12.6 0.005 35.0 1489 92 2014-04-13T04:43:28.216Z,1397364208.216 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:79 Calculated:71 2014-04-13T04:43:28.217Z,1397364208.217 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 22.8 20.5 17.2 18.2 -357.6 36.0 387.9 -29.9 -389 27 418 -55 5 4 3 3 -995.0 88.0 9.8 1 563.5322.5 1 -1077 109 0 2 657 -860 0 2 -6.95 19.01 133.2 17.2 12.5 0.005 35.0 1489 79 2014-04-13T04:43:31.152Z,1397364211.152 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T04:43:31.154Z,1397364211.154 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 24.6 21.9 17.9 20.0 -252.8 59.8 369.3 7.5 -392 66 385 -15 6 4 3 4 -830.3 69.8 49.5 1 463.0 -615.3 322.1 1 -1037 108 11 2 611 2 -6.48 19.99 133.8 17.9 12.4 0.005 35.0 1489 106 2014-04-13T04:43:34.709Z,1397364214.709 [AHRS_sp3003D](ERROR): readPitchRollBin UART error: serial timeout 2014-04-13T04:43:34.709Z,1397364214.709 [AHRS_sp3003D](ERROR): readPitchRollBin got 0xAEFFA0 2014-04-13T04:43:34.861Z,1397364214.861 [AHRS_sp3003D](FAULT): Read Heading/Pitch/Roll Failure. 2014-04-13T04:43:34.861Z,1397364214.861 [AHRS_sp3003D] Communications Fault, FailCount= 1 2014-04-13T04:43:34.861Z,1397364214.861 [AHRS_sp3003D](ERROR): Communications Fault 2014-04-13T04:43:35.127Z,1397364215.127 [CBIT](ERROR): Communications Fault in component: AHRS_sp3003D 2014-04-13T04:43:35.170Z,1397364215.170 [AHRS_sp3003D](INFO): Powering down 2014-04-13T04:43:36.582Z,1397364216.582 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D 2014-04-13T04:43:36.582Z,1397364216.582 [AHRS_sp3003D] No Fault, FailCount= 1 2014-04-13T04:43:36.745Z,1397364216.745 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2014-04-13T04:43:41.132Z,1397364221.132 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T04:43:41.132Z,1397364221.132 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 27.5 25.4 21.3 22.7 -332.6 -23.1 324.1 30.4 -457 -60 390 12 7 6 4 4 -876.5 -71.4 -0.4 1 596.2 -586.3 272.4 1 -1130 -96 -31 2 827 -775 -31 2 -8.46 17.42 132.2.4 0.005 35.0 1489 90 2014-04-13T04:43:49.933Z,1397364229.933 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:90 Calculated:74 2014-04-13T04:43:49.933Z,1397364229.933 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 30.7 28.0 23.6 25.1 -351.0 -113.7 256.3 10.7 -457 -127 292 89 8 7 4 5 -86.0 -53.3 1 622.8 -503.3 214.6 1 -999 -288 -54 2 862 -582 -54 2 -7.58 17.46 129.9 23.6 12.4 0.005 35.0 1489 90 2014-04-13T04:44:12.546Z,1397364252.546 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T04:44:12.547Z,1397364252.547 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 24.2 29.7 33.0 25.8 -325.5 -124.9 297.6 85.0 -340 -140 165 166 4 7 9 5 -831.6 -280.1 -18.3 1 404.7 -732.6 -264.5-408 -40 2 495 -613 -40 2 -8.93 -20.49 97.7 24.2 12.6 0.005 35.0 1489 95 2014-04-13T04:44:30.610Z,1397364270.610 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T04:44:30.611Z,1397364270.611 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 19.5 23.2 26.4 21.2 -294.6 44.7 334.7 28.1 -358 -62 386 269 4 5 6 4 -839.9 22.2 30.4 1 165.5 -790.0 -235.6 1 -993 -441 63 72 63 2 -6.19 -18.17 102.6 19.5 12.8 0.005 35.0 1489 113 2014-04-13T04:45:18.672Z,1397364318.672 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 2 of 46 2014-04-13T04:45:18.672Z,1397364318.672 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 16.5 13.7 11.3 12.7 -222.3 107.1 342.6 54.7 -468 38 373 -64 3 2 2 2 -753.9 69.9 76.1 1 386.6 -552.2 353.1 1 -1122 136 -32 2 654 -921 -32 2 -4.06 22.46 132.3 11.3 12.7 0.005 35.0 1489 107 2014-04-13T04:45:30.509Z,1397364330.509 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:75 Calculated:94 2014-04-13T04:45:30.509Z,1397364330.509 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 19.0 17.5.7 -248.4 64.0 350.3 58.9 -393 62 278 25 4 3 2 2 -799.0 6.8 60.6 1 520.6 -540.8 280.5 1 -895 49 -7 2 612 -655 -7 2 -7.63 16.27 136.2 14.8 12.5 0.005 35.0 1489 75 2014-04-13T04:46:17.868Z,1397364377.868 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 44 of 46 2014-04-13T04:46:17.868Z,1397364377.868 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 26.3 32.4 34.3 27.7 -289.8 12.8 452.4 137.9 -257 19 560 243 5 8 9 6 -990.6 -167.0 84.5 1 545. -195.7 1 -1090 -299 152 2 704 -884 158 -17.72 113.2 26.3 12.3 0.005 35.0 1489 75 2014-04-13T04:47:06.797Z,1397364426.797 [science_to:NeedComms] Running Loop=1 2014-04-13T04:47:06.797Z,1397364426.797 [science_to:NeedComms](INFO): Aggregate::initialize science_to:NeedComms 2014-04-13T04:47:06.797Z,1397364426.797 [science_to:NeedComms:A] Running Loop=1 2014-04-13T04:47:06.798Z,1397364426.798 [science_to:NeedComms:A](INFO): Aggregate::initialize science_to:NeedComms:A 2014-04-13T04:47:07.276Z,1397364427.276 [science_to:SURFACECOMMS] Running Loop=1 2014-04-13T04:47:07.277Z,1397364427.277 [science_to:SURFACECOMMS](INFO): Aggregate::initialize science_to:SURFACECOMMS 2014-04-13T04:47:07.277Z,1397364427.277 [science_to:SURFACECOMMS:A.GoToSurface] Running Loop=1 2014-04-13T04:47:07.277Z,1397364427.277 [science_to:SURFACECOMMS:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T04:47:12.415Z,1397364432.415 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:93 Calculated:68 2014-04-13T04:47:12.415Z,1397364432.415 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 12.5 14.7.8 -311.7 49.7 382.8 27.2 -273 149 381 -15 1 2 2 1 -926.9 30.0 39.9 1 458.0 -789.5 -168.8 1 -872 218 65 2 269 -858 65 2 -7.05 -12.70 121.5 12.5 12.8 0.005 35.0 1489 93 2014-04-13T04:47:35.036Z,1397364455.036 [DVL_micro](ERROR): No DVL communication! Re-initializing 2014-04-13T04:47:35.036Z,1397364455.036 [DVL_micro] Communications Fault, FailCount= 1 2014-04-13T04:47:35.036Z,1397364455.036 [DVL_micro](ERROR): Communications Fault 2014-04-13T04:47:35.204Z,1397364455.204 [CBIT](ERROR): Communications Fault in component: DVL_micro 2014-04-13T04:47:35.655Z,1397364455.655 [DVL_micro](INFO): uninitialize:Powering down 2014-04-13T04:47:36.241Z,1397364456.241 [DVL_micro](FAULT): LCB fault: Software Overcurrent. 2014-04-13T04:47:36.241Z,1397364456.241 [DVL_micro] Hardware Fault, FailCount= 1 2014-04-13T04:47:36.241Z,1397364456.241 [DVL_micro](ERROR): Hardware Fault 2014-04-13T04:47:36.812Z,1397364456.812 [CBIT](INFO): Clearing failed state for component DVL_micro 2014-04-13T04:47:36.812Z,1397364456.812 [DVL_micro] No Fault, FailCount= 1 2014-04-13T04:47:37.353Z,1397364457.353 [DVL_micro](INFO): Initializing 2014-04-13T04:48:14.897Z,1397364494.897 [CTD_NeilBrown](ERROR): Salinity reading out of range: 10.719700 psu 2014-04-13T04:48:15.081Z,1397364495.081 [Radio_Freewave](INFO): Powering up 2014-04-13T04:48:15.102Z,1397364495.102 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2.454300 psu 2014-04-13T04:48:15.202Z,1397364495.202 [science_to:SURFACECOMMS:B] Running Loop=1 2014-04-13T04:48:15.202Z,1397364495.202 [science_to:SURFACECOMMS:B](INFO): Aggregate::initialize science_to:SURFACECOMMS:B 2014-04-13T04:48:15.202Z,1397364495.202 [science_to:SURFACECOMMS:B:A] Running Loop=1 2014-04-13T04:48:15.347Z,1397364495.347 [CTD_NeilBrown](ERROR): Salinity reading out of range: 14.268800 psu 2014-04-13T04:48:15.888Z,1397364495.888 [science_to:SURFACECOMMS:B] Stopped 2014-04-13T04:48:15.888Z,1397364495.888 [science_to:SURFACECOMMS:B](INFO): Aggregate::uninitialize science_to:SURFACECOMMS:B 2014-04-13T04:48:15.888Z,1397364495.888 [science_to:SURFACECOMMS:B:A] Stopped 2014-04-13T04:48:15.888Z,1397364495.888 [science_to:SURFACECOMMS:C] Running Loop=1 2014-04-13T04:48:15.888Z,1397364495.888 [science_to:SURFACECOMMS:C](INFO): Aggregate::initialize science_to:SURFACECOMMS:C 2014-04-13T04:48:15.889Z,1397364495.889 [science_to:SURFACECOMMS:C:A] Running Loop=1 2014-04-13T04:48:16.466Z,1397364496.466 [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-13T04:48:16.583Z,1397364496.583 [science_to:K.YoYo] Preempted 2014-04-13T04:48:16.583Z,1397364496.583 [science_to:J.DepthEnvelope] Preempted 2014-04-13T04:48:16.583Z,1397364496.583 [science_to:I.SetSpeed] Preempted 2014-04-13T04:48:16.583Z,1397364496.583 [science_to:H.Buoyancy] Preempted 2014-04-13T04:48:16.583Z,1397364496.583 [science_to:Science] Preempted 2014-04-13T04:48:16.583Z,1397364496.583 [science_to:Science:D] Preempted 2014-04-13T04:48:16.583Z,1397364496.583 [science_to:Science:G] Preempted 2014-04-13T04:48:16.584Z,1397364496.584 [science_to:Science:PeakDetectChl] Preempted 2014-04-13T04:48:16.601Z,1397364496.601 [WetLabsBB2FL](INFO): Powering down 2014-04-13T04:48:17.249Z,1397364497.249 [NAL9602](INFO): Powering up 2014-04-13T04:48:27.884Z,1397364507.884 [NAL9602](INFO): NAL9602 initialized 2014-04-13T04:48:42.398Z,1397364522.398 [DVL_micro](ERROR): No DVL communication! Re-initializing 2014-04-13T04:48:42.398Z,1397364522.398 [DVL_micro] Communications Fault, FailCount= 1 2014-04-13T04:48:42.399Z,1397364522.399 [DVL_micro](ERROR): Communications Fault 2014-04-13T04:48:42.466Z,1397364522.466 [CBIT](ERROR): Communications Fault in component: DVL_micro 2014-04-13T04:48:42.839Z,1397364522.839 [DVL_micro](INFO): uninitialize:Powering down 2014-04-13T04:48:43.269Z,1397364523.269 [DVL_micro](FAULT): LCB fault: Software Overcurrent. 2014-04-13T04:48:43.269Z,1397364523.269 [DVL_micro] Hardware Fault, FailCount= 1 2014-04-13T04:48:43.269Z,1397364523.269 [DVL_micro](ERROR): Hardware Fault 2014-04-13T04:48:43.793Z,1397364523.793 [CBIT](INFO): Clearing failed state for component DVL_micro 2014-04-13T04:48:43.793Z,1397364523.793 [DVL_micro] No Fault, FailCount= 1 2014-04-13T04:48:44.293Z,1397364524.293 [DVL_micro](INFO): Initializing 2014-04-13T04:48:55.878Z,1397364535.878 [NAL9602](INFO): SBD MO Status=0, MOMSN=25233, MT Status=0, MTMSN=0 2014-04-13T04:48:55.878Z,1397364535.878 [NAL9602](INFO): No messages in MT queue 2014-04-13T04:49:57.658Z,1397364597.658 [NAL9602](IMPORTANT): GPS fix at: 1397364562.00 2014-04-13T04:49:57.680Z,1397364597.680 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T04:49:57.680Z,1397364597.680 [DeadReckonUsingMultipleVelocitySources](DEBUG): horizontalPathLengthSinceLastFix_ = 1549.95, recording fix residuals... 2014-04-13T04:49:57.686Z,1397364597.686 [science_to:SURFACECOMMS:C:A] Stopped 2014-04-13T04:49:57.686Z,1397364597.686 [science_to:SURFACECOMMS:C:B] Running Loop=1 2014-04-13T04:50:23.512Z,1397364623.512 [NAL9602](INFO): SBD MO Status=2, MOMSN=25234, MT Status=2, MTMSN=0 2014-04-13T04:50:23.512Z,1397364623.512 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2014-04-13T04:50:55.272Z,1397364655.272 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=25234, MT Status=1, MTMSN=1750 2014-04-13T04:50:55.324Z,1397364655.324 [NAL9602](INFO): Sent 75 bytes from file Logs/20140413T040209/Courier0028.lzma 2014-04-13T04:50:55.324Z,1397364655.324 [NAL9602](INFO): Packets left to send: 0 2014-04-13T04:50:55.327Z,1397364655.327 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T040209/Courier0028.lzma.parts/0000.sbd 2014-04-13T04:50:55.327Z,1397364655.327 [NAL9602](INFO): Completed sending Logs/20140413T040209/Courier0028.lzma 2014-04-13T04:50:55.889Z,1397364655.889 [NAL9602](INFO): Received command:stop 2014-04-13T04:50:55.958Z,1397364655.958 [CommandLine](IMPORTANT): got command stop 2014-04-13T04:50:56.394Z,1397364656.394 [science_to] Stopped 2014-04-13T04:50:56.394Z,1397364656.394 [science_to](INFO): Aggregate::uninitialize science_to 2014-04-13T04:50:56.394Z,1397364656.394 [science_to:AltEnvWrapper] Stopped 2014-04-13T04:50:56.394Z,1397364656.394 [science_to:AltEnvWrapper](INFO): Aggregate::uninitialize science_to:AltEnvWrapper 2014-04-13T04:50:56.394Z,1397364656.394 [science_to:AltEnvWrapper:A.AltitudeEnvelope] Stopped 2014-04-13T04:50:56.394Z,1397364656.394 [science_to:AltEnvWrapper:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent. 2014-04-13T04:50:56.394Z,1397364656.394 [science_to:B.DepthEnvelope] Stopped 2014-04-13T04:50:56.394Z,1397364656.394 [science_to:B.DepthEnvelope](DEBUG): Uninitialize. 2014-04-13T04:50:56.394Z,1397364656.394 [science_to:OffshoreWrapper] Stopped 2014-04-13T04:50:56.394Z,1397364656.394 [science_to:OffshoreWrapper](INFO): Aggregate::uninitialize science_to:OffshoreWrapper 2014-04-13T04:50:56.395Z,1397364656.395 [science_to:OffshoreWrapper:A.OffshoreEnvelope] Stopped 2014-04-13T04:50:56.395Z,1397364656.395 [science_to:OffshoreWrapper:A.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent. 2014-04-13T04:50:56.395Z,1397364656.395 [science_to:D.Pitch] Stopped 2014-04-13T04:50:56.395Z,1397364656.395 [science_to:SURFACECOMMS] Stopped 2014-04-13T04:50:56.395Z,1397364656.395 [science_to:SURFACECOMMS](INFO): Aggregate::uninitialize science_to:SURFACECOMMS 2014-04-13T04:50:56.395Z,1397364656.395 [science_to:SURFACECOMMS:A.GoToSurface] Stopped 2014-04-13T04:50:56.395Z,1397364656.395 [science_to:SURFACECOMMS:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T04:50:56.395Z,1397364656.395 [science_to:SURFACECOMMS:C] Stopped 2014-04-13T04:50:56.395Z,1397364656.395 [science_to:SURFACECOMMS:C](INFO): Aggregate::uninitialize science_to:SURFACECOMMS:C 2014-04-13T04:50:56.395Z,1397364656.395 [science_to:SURFACECOMMS:C:B] Stopped 2014-04-13T04:50:56.395Z,1397364656.395 [science_to:NeedComms] Stopped 2014-04-13T04:50:56.396Z,1397364656.396 [science_to:NeedComms](INFO): Aggregate::uninitialize science_to:NeedComms 2014-04-13T04:50:56.396Z,1397364656.396 [science_to:NeedComms:A] Stopped 2014-04-13T04:50:56.396Z,1397364656.396 [science_to:NeedComms:A](INFO): Aggregate::uninitialize science_to:NeedComms:A 2014-04-13T04:50:56.396Z,1397364656.396 [science_to:Science] Stopped 2014-04-13T04:50:56.396Z,1397364656.396 [science_to:Science](INFO): Aggregate::uninitialize science_to:Science 2014-04-13T04:50:56.396Z,1397364656.396 [science_to:Science:D] Stopped 2014-04-13T04:50:56.396Z,1397364656.396 [science_to:Science:G] Stopped 2014-04-13T04:50:56.396Z,1397364656.396 [science_to:Science:PeakDetectChl] Stopped 2014-04-13T04:50:56.396Z,1397364656.396 [science_to:Science:PeakDetectChl](INFO): Aggregate::uninitialize science_to:Science:PeakDetectChl 2014-04-13T04:50:56.397Z,1397364656.397 [science_to:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped 2014-04-13T04:50:56.397Z,1397364656.397 [science_to:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2014-04-13T04:50:56.397Z,1397364656.397 [science_to:H.Buoyancy] Stopped 2014-04-13T04:50:56.397Z,1397364656.397 [science_to:H.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2014-04-13T04:50:56.397Z,1397364656.397 [science_to:I.SetSpeed] Stopped 2014-04-13T04:50:56.397Z,1397364656.397 [science_to:I.SetSpeed](DEBUG): Uninitialize. 2014-04-13T04:50:56.397Z,1397364656.397 [science_to:J.DepthEnvelope] Stopped 2014-04-13T04:50:56.397Z,1397364656.397 [science_to:J.DepthEnvelope](DEBUG): Uninitialize. 2014-04-13T04:50:56.397Z,1397364656.397 [science_to:K.YoYo] Stopped 2014-04-13T04:50:56.397Z,1397364656.397 [science_to:K.YoYo](DEBUG): Uninitialize YoYoComponent. 2014-04-13T04:50:56.398Z,1397364656.398 [science_to:Wpt2] Stopped 2014-04-13T04:50:56.398Z,1397364656.398 [science_to:Wpt2](INFO): Aggregate::uninitialize science_to:Wpt2 2014-04-13T04:50:56.398Z,1397364656.398 [science_to:Wpt2:A.Waypoint] Stopped 2014-04-13T04:50:56.398Z,1397364656.398 [science_to:Wpt2:A.Waypoint](DEBUG): Uninitialize WaypointComponent. 2014-04-13T04:50:56.885Z,1397364656.885 [MissionManager](IMPORTANT): Started mission Default 2014-04-13T04:50:56.885Z,1397364656.885 [Default] Running Loop=1 2014-04-13T04:50:56.885Z,1397364656.885 [Default](INFO): Aggregate::initialize Default 2014-04-13T04:50:56.886Z,1397364656.886 [Default:Iridium] Running Loop=1 2014-04-13T04:50:56.886Z,1397364656.886 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2014-04-13T04:50:56.886Z,1397364656.886 [Default:Iridium:A.SetSpeed] Running Loop=1 2014-04-13T04:50:56.886Z,1397364656.886 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2014-04-13T04:50:56.887Z,1397364656.887 [Default:Iridium:B.GoToSurface] Running Loop=1 2014-04-13T04:50:56.887Z,1397364656.887 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T04:50:56.887Z,1397364656.887 [Default:CallIridium] Running Loop=1 2014-04-13T04:50:56.887Z,1397364656.887 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2014-04-13T04:50:56.888Z,1397364656.888 [Default:CallIridium:A] Running Loop=1 2014-04-13T04:50:56.888Z,1397364656.888 [Default:CallIridium:A] Stopped 2014-04-13T04:50:56.888Z,1397364656.888 [Default:CallIridium:B] Running Loop=1 2014-04-13T04:50:56.888Z,1397364656.888 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2014-04-13T04:50:56.889Z,1397364656.889 [Default:Iridium:B.GoToSurface] Stopped 2014-04-13T04:50:56.889Z,1397364656.889 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T04:50:56.889Z,1397364656.889 [Default:Iridium:Read_Iridium] Running Loop=1 2014-04-13T04:50:57.337Z,1397364657.337 [Default:GPS] Running Loop=1 2014-04-13T04:50:57.337Z,1397364657.337 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2014-04-13T04:50:57.337Z,1397364657.337 [Default:GPS:A.SetSpeed] Running Loop=1 2014-04-13T04:50:57.337Z,1397364657.337 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2014-04-13T04:50:57.337Z,1397364657.337 [Default:GPS:B.GoToSurface] Running Loop=1 2014-04-13T04:50:57.337Z,1397364657.337 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T04:50:57.338Z,1397364657.338 [Default:GPS:B.GoToSurface] Stopped 2014-04-13T04:50:57.338Z,1397364657.338 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T04:50:57.338Z,1397364657.338 [Default:GPS:Read_GPS] Running Loop=1 2014-04-13T04:51:00.498Z,1397364660.498 [NAL9602](IMPORTANT): GPS fix at: 1397364625.00 2014-04-13T04:51:00.511Z,1397364660.511 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T04:51:00.515Z,1397364660.515 [Default:GPS:Read_GPS] Stopped 2014-04-13T04:51:00.515Z,1397364660.515 [Default:GPS:D] Running Loop=1 2014-04-13T04:51:00.974Z,1397364660.974 [Default:GPS:D] Stopped 2014-04-13T04:51:00.974Z,1397364660.974 [Default:GPS](INFO): Completed Default:GPS 2014-04-13T04:51:00.974Z,1397364660.974 [Default:GPS] Stopped 2014-04-13T04:51:00.974Z,1397364660.974 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2014-04-13T04:51:00.974Z,1397364660.974 [Default:GPS:A.SetSpeed] Stopped 2014-04-13T04:51:00.975Z,1397364660.975 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2014-04-13T04:51:19.573Z,1397364679.573 [NAL9602](INFO): SBD MO Status=1, MOMSN=25235, MT Status=0, MTMSN=0 2014-04-13T04:51:19.626Z,1397364679.626 [NAL9602](INFO): Sent 45 bytes from file Logs/20140413T040209/Courier0032.lzma 2014-04-13T04:51:19.626Z,1397364679.626 [NAL9602](INFO): Packets left to send: 0 2014-04-13T04:51:19.628Z,1397364679.628 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T040209/Courier0032.lzma.parts/0000.sbd 2014-04-13T04:51:19.628Z,1397364679.628 [NAL9602](INFO): Completed sending Logs/20140413T040209/Courier0032.lzma 2014-04-13T04:51:32.118Z,1397364692.118 [NAL9602](INFO): SBD MO Status=1, MOMSN=25236, MT Status=0, MTMSN=0 2014-04-13T04:51:32.174Z,1397364692.174 [NAL9602](INFO): Sent 332 bytes from file Logs/20140413T040209/Express0029.lzma 2014-04-13T04:51:32.174Z,1397364692.174 [NAL9602](INFO): Packets left to send: 3 2014-04-13T04:51:32.175Z,1397364692.175 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T040209/Express0029.lzma.parts/0003.sbd 2014-04-13T04:51:45.575Z,1397364705.575 [NAL9602](INFO): SBD MO Status=1, MOMSN=25237, MT Status=0, MTMSN=0 2014-04-13T04:51:45.626Z,1397364705.626 [NAL9602](INFO): Sent 332 bytes from file Logs/20140413T040209/Express0029.lzma 2014-04-13T04:51:45.627Z,1397364705.627 [NAL9602](INFO): Packets left to send: 2 2014-04-13T04:51:45.628Z,1397364705.628 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T040209/Express0029.lzma.parts/0002.sbd 2014-04-13T04:52:00.077Z,1397364720.077 [NAL9602](INFO): SBD MO Status=1, MOMSN=25238, MT Status=0, MTMSN=0 2014-04-13T04:52:00.129Z,1397364720.129 [NAL9602](INFO): Sent 332 bytes from file Logs/20140413T040209/Express0029.lzma 2014-04-13T04:52:00.129Z,1397364720.129 [NAL9602](INFO): Packets left to send: 1 2014-04-13T04:52:00.130Z,1397364720.130 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T040209/Express0029.lzma.parts/0001.sbd 2014-04-13T04:52:11.498Z,1397364731.498 [NAL9602](INFO): SBD MO Status=1, MOMSN=25239, MT Status=0, MTMSN=0 2014-04-13T04:52:11.547Z,1397364731.547 [NAL9602](INFO): Sent 192 bytes from file Logs/20140413T040209/Express0029.lzma 2014-04-13T04:52:11.547Z,1397364731.547 [NAL9602](INFO): Packets left to send: 0 2014-04-13T04:52:11.548Z,1397364731.548 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T040209/Express0029.lzma.parts/0000.sbd 2014-04-13T04:52:11.548Z,1397364731.548 [NAL9602](INFO): Completed sending Logs/20140413T040209/Express0029.lzma 2014-04-13T04:52:20.184Z,1397364740.184 [NAL9602](INFO): SBD MO Status=1, MOMSN=25240, MT Status=0, MTMSN=0 2014-04-13T04:52:20.240Z,1397364740.240 [NAL9602](INFO): Sent 121 bytes from file Logs/20140413T040209/Express0033.lzma 2014-04-13T04:52:20.240Z,1397364740.240 [NAL9602](INFO): Packets left to send: 0 2014-04-13T04:52:20.242Z,1397364740.242 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T040209/Express0033.lzma.parts/0000.sbd 2014-04-13T04:52:20.242Z,1397364740.242 [NAL9602](INFO): Completed sending Logs/20140413T040209/Express0033.lzma 2014-04-13T04:52:25.099Z,1397364745.099 [NAL9602](INFO): SBD MO Status=0, MOMSN=25241, MT Status=0, MTMSN=0 2014-04-13T04:52:36.483Z,1397364756.483 [NAL9602](INFO): SBD MO Status=1, MOMSN=25242, MT Status=0, MTMSN=0 2014-04-13T04:52:36.529Z,1397364756.529 [NAL9602](INFO): Sent 45 bytes from file Logs/20140413T040209/Courier0036.lzma 2014-04-13T04:52:36.530Z,1397364756.530 [NAL9602](INFO): Packets left to send: 0 2014-04-13T04:52:36.531Z,1397364756.531 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T040209/Courier0036.lzma.parts/0000.sbd 2014-04-13T04:52:36.532Z,1397364756.532 [NAL9602](INFO): Completed sending Logs/20140413T040209/Courier0036.lzma 2014-04-13T04:52:46.256Z,1397364766.256 [NAL9602](INFO): SBD MO Status=1, MOMSN=25243, MT Status=0, MTMSN=0 2014-04-13T04:52:46.304Z,1397364766.304 [NAL9602](INFO): Sent 168 bytes from file Logs/20140413T040209/Express0037.lzma 2014-04-13T04:52:46.305Z,1397364766.305 [NAL9602](INFO): Packets left to send: 0 2014-04-13T04:52:46.306Z,1397364766.306 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T040209/Express0037.lzma.parts/0000.sbd 2014-04-13T04:52:46.307Z,1397364766.307 [NAL9602](INFO): Completed sending Logs/20140413T040209/Express0037.lzma 2014-04-13T04:52:57.183Z,1397364777.183 [NAL9602](INFO): SBD MO Status=0, MOMSN=25244, MT Status=0, MTMSN=0 2014-04-13T04:52:57.280Z,1397364777.280 [Default:Iridium:Read_Iridium] Stopped 2014-04-13T04:52:57.280Z,1397364777.280 [Default:Iridium](INFO): Completed Default:Iridium 2014-04-13T04:52:57.280Z,1397364777.280 [Default:Iridium] Stopped 2014-04-13T04:52:57.281Z,1397364777.281 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2014-04-13T04:52:57.281Z,1397364777.281 [Default:Iridium:A.SetSpeed] Stopped 2014-04-13T04:52:57.281Z,1397364777.281 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2014-04-13T04:52:57.281Z,1397364777.281 [Default:WaitAtTheSurface] Running Loop=1 2014-04-13T04:52:57.281Z,1397364777.281 [Default:WaitAtTheSurface](INFO): Aggregate::initialize Default:WaitAtTheSurface 2014-04-13T04:52:57.281Z,1397364777.281 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Running Loop=1 2014-04-13T04:52:57.281Z,1397364777.281 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Initialize. 2014-04-13T04:52:57.282Z,1397364777.282 [Default:WaitAtTheSurface:B.GoToSurface] Running Loop=1 2014-04-13T04:52:57.282Z,1397364777.282 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T04:52:57.685Z,1397364777.685 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2014-04-13T04:52:57.685Z,1397364777.685 [Default:CallIridium:B] Stopped 2014-04-13T04:52:57.686Z,1397364777.686 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2014-04-13T04:52:57.686Z,1397364777.686 [Default:CallIridium](INFO): Completed Default:CallIridium 2014-04-13T04:52:57.686Z,1397364777.686 [Default:CallIridium] Stopped 2014-04-13T04:52:57.686Z,1397364777.686 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2014-04-13T04:53:07.916Z,1397364787.916 [NAL9602](INFO): Powering down 2014-04-13T04:57:57.908Z,1397365077.908 [Default:CallIridium] Running Loop=1 2014-04-13T04:57:57.909Z,1397365077.909 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2014-04-13T04:57:57.909Z,1397365077.909 [Default:CallIridium:A] Running Loop=1 2014-04-13T04:57:57.910Z,1397365077.910 [Default:CallIridium:A] Stopped 2014-04-13T04:57:57.910Z,1397365077.910 [Default:CallIridium:B] Running Loop=1 2014-04-13T04:57:57.910Z,1397365077.910 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2014-04-13T04:58:02.985Z,1397365082.985 [Default:Iridium] Running Loop=1 2014-04-13T04:58:02.985Z,1397365082.985 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2014-04-13T04:58:02.985Z,1397365082.985 [Default:Iridium:A.SetSpeed] Running Loop=1 2014-04-13T04:58:02.985Z,1397365082.985 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2014-04-13T04:58:02.986Z,1397365082.986 [Default:Iridium:B.GoToSurface] Running Loop=1 2014-04-13T04:58:02.986Z,1397365082.986 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T04:58:02.987Z,1397365082.987 [Default:Iridium:B.GoToSurface] Stopped 2014-04-13T04:58:02.987Z,1397365082.987 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T04:58:02.987Z,1397365082.987 [Default:Iridium:Read_Iridium] Running Loop=1 2014-04-13T04:58:02.987Z,1397365082.987 [Default:GPS] Running Loop=1 2014-04-13T04:58:02.987Z,1397365082.987 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2014-04-13T04:58:02.987Z,1397365082.987 [Default:GPS:A.SetSpeed] Running Loop=1 2014-04-13T04:58:02.988Z,1397365082.988 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2014-04-13T04:58:02.988Z,1397365082.988 [Default:GPS:B.GoToSurface] Running Loop=1 2014-04-13T04:58:02.988Z,1397365082.988 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T04:58:02.989Z,1397365082.989 [Default:GPS:B.GoToSurface] Stopped 2014-04-13T04:58:02.989Z,1397365082.989 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T04:58:02.989Z,1397365082.989 [Default:GPS:Read_GPS] Running Loop=1 2014-04-13T04:58:05.478Z,1397365085.478 [NAL9602](INFO): Powering up 2014-04-13T04:58:15.354Z,1397365095.354 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T04:58:15.354Z,1397365095.354 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 30.9 31.4 31.8 30.517.7 32.6 -109.4 -5 115 77 -94 7 7 7 7 -209.0 169.6 -49.4 1 260.1 53.5 -66.2 1 -109 278 25 2 284 -95 25 2 -13 230.1 30.5 14.6 0.005 35.0 1489 113 2014-04-13T04:58:16.309Z,1397365096.309 [NAL9602](INFO): NAL9602 initialized 2014-04-13T04:58:42.255Z,1397365122.255 [NAL9602](INFO): SBD MO Status=1, MOMSN=25245, MT Status=0, MTMSN=0 2014-04-13T04:58:42.308Z,1397365122.308 [NAL9602](INFO): Sent 45 bytes from file Logs/20140413T040209/Courier0040.lzma 2014-04-13T04:58:42.309Z,1397365122.309 [NAL9602](INFO): Packets left to send: 0 2014-04-13T04:58:42.311Z,1397365122.311 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T040209/Courier0040.lzma.parts/0000.sbd 2014-04-13T04:58:42.311Z,1397365122.311 [NAL9602](INFO): Completed sending Logs/20140413T040209/Courier0040.lzma 2014-04-13T04:58:55.438Z,1397365135.438 [NAL9602](INFO): SBD MO Status=1, MOMSN=25246, MT Status=0, MTMSN=0 2014-04-13T04:58:55.489Z,1397365135.489 [NAL9602](INFO): Sent 332 bytes from file Logs/20140413T040209/Express0041.lzma 2014-04-13T04:58:55.489Z,1397365135.489 [NAL9602](INFO): Packets left to send: 1 2014-04-13T04:58:55.491Z,1397365135.491 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T040209/Express0041.lzma.parts/0001.sbd 2014-04-13T04:59:06.790Z,1397365146.790 [NAL9602](INFO): SBD MO Status=1, MOMSN=25247, MT Status=0, MTMSN=0 2014-04-13T04:59:06.843Z,1397365146.843 [NAL9602](INFO): Sent 3 bytes from file Logs/20140413T040209/Express0041.lzma 2014-04-13T04:59:06.843Z,1397365146.843 [NAL9602](INFO): Packets left to send: 0 2014-04-13T04:59:06.844Z,1397365146.844 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T040209/Express0041.lzma.parts/0000.sbd 2014-04-13T04:59:06.845Z,1397365146.845 [NAL9602](INFO): Completed sending Logs/20140413T040209/Express0041.lzma 2014-04-13T04:59:11.730Z,1397365151.730 [NAL9602](INFO): SBD MO Status=0, MOMSN=25248, MT Status=0, MTMSN=0 2014-04-13T04:59:11.836Z,1397365151.836 [Default:Iridium:Read_Iridium] Stopped 2014-04-13T04:59:11.837Z,1397365151.837 [Default:Iridium](INFO): Completed Default:Iridium 2014-04-13T04:59:11.837Z,1397365151.837 [Default:Iridium] Stopped 2014-04-13T04:59:11.837Z,1397365151.837 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2014-04-13T04:59:11.837Z,1397365151.837 [Default:Iridium:A.SetSpeed] Stopped 2014-04-13T04:59:11.837Z,1397365151.837 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2014-04-13T04:59:12.269Z,1397365152.269 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2014-04-13T04:59:12.269Z,1397365152.269 [Default:CallIridium:B] Stopped 2014-04-13T04:59:12.270Z,1397365152.270 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2014-04-13T04:59:12.270Z,1397365152.270 [Default:CallIridium](INFO): Completed Default:CallIridium 2014-04-13T04:59:12.270Z,1397365152.270 [Default:CallIridium] Stopped 2014-04-13T04:59:12.270Z,1397365152.270 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2014-04-13T04:59:28.128Z,1397365168.128 [NAL9602](IMPORTANT): GPS fix at: 1397365133.00 2014-04-13T04:59:28.142Z,1397365168.142 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T04:59:28.146Z,1397365168.146 [Default:GPS:Read_GPS] Stopped 2014-04-13T04:59:28.146Z,1397365168.146 [Default:GPS:D] Running Loop=1 2014-04-13T04:59:28.614Z,1397365168.614 [Default:GPS:D] Stopped 2014-04-13T04:59:28.614Z,1397365168.614 [Default:GPS](INFO): Completed Default:GPS 2014-04-13T04:59:28.614Z,1397365168.614 [Default:GPS] Stopped 2014-04-13T04:59:28.614Z,1397365168.614 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2014-04-13T04:59:28.614Z,1397365168.614 [Default:GPS:A.SetSpeed] Stopped 2014-04-13T04:59:28.614Z,1397365168.614 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2014-04-13T04:59:49.298Z,1397365189.298 [NAL9602](INFO): Powering down 2014-04-13T05:04:14.386Z,1397365454.386 [Default:CallIridium] Running Loop=1 2014-04-13T05:04:14.386Z,1397365454.386 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2014-04-13T05:04:14.407Z,1397365454.407 [Default:CallIridium:A] Running Loop=1 2014-04-13T05:04:14.413Z,1397365454.413 [Default:CallIridium:A] Stopped 2014-04-13T05:04:14.414Z,1397365454.414 [Default:CallIridium:B] Running Loop=1 2014-04-13T05:04:14.414Z,1397365454.414 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2014-04-13T05:04:19.265Z,1397365459.265 [Default:Iridium] Running Loop=1 2014-04-13T05:04:19.265Z,1397365459.265 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2014-04-13T05:04:19.266Z,1397365459.266 [Default:Iridium:A.SetSpeed] Running Loop=1 2014-04-13T05:04:19.266Z,1397365459.266 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2014-04-13T05:04:19.272Z,1397365459.272 [Default:Iridium:B.GoToSurface] Running Loop=1 2014-04-13T05:04:19.272Z,1397365459.272 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T05:04:19.273Z,1397365459.273 [Default:Iridium:B.GoToSurface] Stopped 2014-04-13T05:04:19.273Z,1397365459.273 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T05:04:19.274Z,1397365459.274 [Default:Iridium:Read_Iridium] Running Loop=1 2014-04-13T05:04:19.274Z,1397365459.274 [Default:GPS] Running Loop=1 2014-04-13T05:04:19.274Z,1397365459.274 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2014-04-13T05:04:19.274Z,1397365459.274 [Default:GPS:A.SetSpeed] Running Loop=1 2014-04-13T05:04:19.274Z,1397365459.274 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2014-04-13T05:04:19.275Z,1397365459.275 [Default:GPS:B.GoToSurface] Running Loop=1 2014-04-13T05:04:19.275Z,1397365459.275 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T05:04:19.275Z,1397365459.275 [Default:GPS:B.GoToSurface] Stopped 2014-04-13T05:04:19.275Z,1397365459.275 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T05:04:19.276Z,1397365459.276 [Default:GPS:Read_GPS] Running Loop=1 2014-04-13T05:04:21.774Z,1397365461.774 [NAL9602](INFO): Powering up 2014-04-13T05:04:32.555Z,1397365472.555 [NAL9602](INFO): NAL9602 initialized 2014-04-13T05:04:49.722Z,1397365489.722 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:122 Calculated:110 2014-04-13T05:04:49.722Z,1397365489.722 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 33.1 34.7 31.80.6 320.5 356.6 226.4 280 440 455 273 8 9 7 6 -248.2 125.6 289.6 1 224.9 -182.2 278.4 1 -233 222 390 2 205 -249 390 2 -5.68 0.62 173.1 29.7 14.7 0.005 35.0 1489 122 2014-04-13T05:04:50.664Z,1397365490.664 [NAL9602](INFO): SBD MO Status=1, MOMSN=25249, MT Status=0, MTMSN=0 2014-04-13T05:04:50.714Z,1397365490.714 [NAL9602](INFO): Sent 45 bytes from file Logs/20140413T040209/Courier0044.lzma 2014-04-13T05:04:50.714Z,1397365490.714 [NAL9602](INFO): Packets left to send: 0 2014-04-13T05:04:50.716Z,1397365490.716 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T040209/Courier0044.lzma.parts/0000.sbd 2014-04-13T05:04:50.716Z,1397365490.716 [NAL9602](INFO): Completed sending Logs/20140413T040209/Courier0044.lzma 2014-04-13T05:04:57.285Z,1397365497.285 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T05:04:57.286Z,1397365497.286 [DVL_micro](ERROR