2014-04-21T04:32:20.235Z,1398054740.235 [Supervisor](DEBUG): Initializing supervisor. 2014-04-21T04:32:20.237Z,1398054740.237 [SyncHandler](DEBUG): Created PCaller Thread at 4033C4E0 2014-04-21T04:32:20.238Z,1398054740.238 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2014-04-21T04:32:20.239Z,1398054740.239 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036C4E0 2014-04-21T04:32:20.242Z,1398054740.242 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2014-04-21T04:32:20.253Z,1398054740.253 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2014-04-21T04:32:20.254Z,1398054740.254 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039C4E0 2014-04-21T04:32:20.255Z,1398054740.255 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2014-04-21T04:32:20.256Z,1398054740.256 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CC4E0 2014-04-21T04:32:20.258Z,1398054740.258 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2014-04-21T04:32:20.259Z,1398054740.259 [Supervisor](INFO): Looking for Config files in directory: Config/ 2014-04-21T04:32:20.263Z,1398054740.263 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2014-04-21T04:32:20.603Z,1398054740.603 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2014-04-21T04:32:20.604Z,1398054740.604 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2014-04-21T04:32:20.866Z,1398054740.866 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2014-04-21T04:32:20.866Z,1398054740.866 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2014-04-21T04:32:20.953Z,1398054740.953 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2014-04-21T04:32:20.956Z,1398054740.956 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2014-04-21T04:32:21.145Z,1398054741.145 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2014-04-21T04:32:21.146Z,1398054741.146 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2014-04-21T04:32:21.302Z,1398054741.302 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2014-04-21T04:32:21.304Z,1398054741.304 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2014-04-21T04:32:21.592Z,1398054741.592 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2014-04-21T04:32:21.593Z,1398054741.593 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2014-04-21T04:32:21.772Z,1398054741.772 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2014-04-21T04:32:21.774Z,1398054741.774 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2014-04-21T04:32:22.100Z,1398054742.100 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2014-04-21T04:32:22.102Z,1398054742.102 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2014-04-21T04:32:22.211Z,1398054742.211 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2014-04-21T04:32:22.212Z,1398054742.212 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2014-04-21T04:32:22.687Z,1398054742.687 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2014-04-21T04:32:22.688Z,1398054742.688 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2014-04-21T04:32:22.797Z,1398054742.797 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2014-04-21T04:32:22.798Z,1398054742.798 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2014-04-21T04:32:22.885Z,1398054742.885 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2014-04-21T04:32:22.996Z,1398054742.996 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2014-04-21T04:32:23.053Z,1398054743.053 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2014-04-21T04:32:24.277Z,1398054744.277 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2014-04-21T04:32:24.277Z,1398054744.277 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2014-04-21T04:32:25.134Z,1398054745.134 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2014-04-21T04:32:25.136Z,1398054745.136 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2014-04-21T04:32:25.140Z,1398054745.140 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2014-04-21T04:32:25.247Z,1398054745.247 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2014-04-21T04:32:25.375Z,1398054745.375 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2014-04-21T04:32:25.471Z,1398054745.471 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2014-04-21T04:32:25.565Z,1398054745.565 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2014-04-21T04:32:25.717Z,1398054745.717 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2014-04-21T04:32:25.834Z,1398054745.834 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2014-04-21T04:32:25.921Z,1398054745.921 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2014-04-21T04:32:26.025Z,1398054746.025 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2014-04-21T04:32:26.126Z,1398054746.126 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg 2014-04-21T04:32:26.223Z,1398054746.223 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg 2014-04-21T04:32:26.313Z,1398054746.313 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Estimation.cfg 2014-04-21T04:32:26.410Z,1398054746.410 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2014-04-21T04:32:26.417Z,1398054746.417 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2014-04-21T04:32:27.099Z,1398054747.099 [AHRS_sp3003D] Loaded 2014-04-21T04:32:27.100Z,1398054747.100 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread. 2014-04-21T04:32:27.384Z,1398054747.384 [Batt_Ocean_Server] Loaded 2014-04-21T04:32:27.385Z,1398054747.385 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread. 2014-04-21T04:32:27.398Z,1398054747.398 [Depth_Keller] Loaded 2014-04-21T04:32:27.398Z,1398054747.398 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2014-04-21T04:32:27.403Z,1398054747.403 [DropWeight] Loaded 2014-04-21T04:32:27.403Z,1398054747.403 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2014-04-21T04:32:27.540Z,1398054747.540 [DVL_micro] Loaded 2014-04-21T04:32:27.540Z,1398054747.540 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2014-04-21T04:32:27.638Z,1398054747.638 [NAL9602] Loaded 2014-04-21T04:32:27.638Z,1398054747.638 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2014-04-21T04:32:27.688Z,1398054747.688 [Onboard] Loaded 2014-04-21T04:32:27.689Z,1398054747.689 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2014-04-21T04:32:27.696Z,1398054747.696 [Radio_Freewave] Loaded 2014-04-21T04:32:27.696Z,1398054747.696 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread. 2014-04-21T04:32:27.702Z,1398054747.702 [SCPI] Loaded 2014-04-21T04:32:27.703Z,1398054747.703 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread. 2014-04-21T04:32:27.703Z,1398054747.703 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2014-04-21T04:32:27.704Z,1398054747.704 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2014-04-21T04:32:27.893Z,1398054747.893 [InternalSim] Loaded 2014-04-21T04:32:27.893Z,1398054747.893 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread. 2014-04-21T04:32:27.894Z,1398054747.894 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2014-04-21T04:32:27.894Z,1398054747.894 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2014-04-21T04:32:28.170Z,1398054748.170 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2014-04-21T04:32:28.171Z,1398054748.171 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2014-04-21T04:32:28.180Z,1398054748.180 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator. 2014-04-21T04:32:28.185Z,1398054748.185 [AsyncPiEstimator] Loaded 2014-04-21T04:32:28.185Z,1398054748.185 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread. 2014-04-21T04:32:28.187Z,1398054748.187 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406A24E0 2014-04-21T04:32:28.188Z,1398054748.188 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2014-04-21T04:32:28.188Z,1398054748.188 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2014-04-21T04:32:28.374Z,1398054748.374 [DeadReckonUsingMultipleVelocitySources] Loaded 2014-04-21T04:32:28.375Z,1398054748.375 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2014-04-21T04:32:28.391Z,1398054748.391 [NavChart] Loaded 2014-04-21T04:32:28.391Z,1398054748.391 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2014-04-21T04:32:28.395Z,1398054748.395 [UniversalFixResidualReporter] Loaded 2014-04-21T04:32:28.396Z,1398054748.396 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2014-04-21T04:32:28.396Z,1398054748.396 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2014-04-21T04:32:28.397Z,1398054748.397 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2014-04-21T04:32:28.462Z,1398054748.462 [VerticalControl](DEBUG): Construct VerticalControl. 2014-04-21T04:32:28.570Z,1398054748.570 [VerticalControl] Loaded 2014-04-21T04:32:28.571Z,1398054748.571 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2014-04-21T04:32:28.571Z,1398054748.571 [HorizontalControl](DEBUG): Construct HorizontalControl. 2014-04-21T04:32:28.636Z,1398054748.636 [HorizontalControl] Loaded 2014-04-21T04:32:28.637Z,1398054748.637 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2014-04-21T04:32:28.637Z,1398054748.637 [SpeedControl](DEBUG): Construct SpeedControl. 2014-04-21T04:32:28.639Z,1398054748.639 [SpeedControl] Loaded 2014-04-21T04:32:28.639Z,1398054748.639 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2014-04-21T04:32:28.640Z,1398054748.640 [LoopControl](DEBUG): Construct LoopControl. 2014-04-21T04:32:28.641Z,1398054748.641 [LoopControl] Loaded 2014-04-21T04:32:28.641Z,1398054748.641 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2014-04-21T04:32:28.641Z,1398054748.641 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2014-04-21T04:32:28.642Z,1398054748.642 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2014-04-21T04:32:28.670Z,1398054748.670 [DepthRateCalculator] Loaded 2014-04-21T04:32:28.670Z,1398054748.670 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2014-04-21T04:32:28.676Z,1398054748.676 [PitchRateCalculator] Loaded 2014-04-21T04:32:28.676Z,1398054748.676 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2014-04-21T04:32:28.684Z,1398054748.684 [SpeedCalculator] Loaded 2014-04-21T04:32:28.684Z,1398054748.684 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2014-04-21T04:32:28.700Z,1398054748.700 [TempGradientCalculator] Loaded 2014-04-21T04:32:28.700Z,1398054748.700 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2014-04-21T04:32:28.705Z,1398054748.705 [YawRateCalculator] Loaded 2014-04-21T04:32:28.705Z,1398054748.705 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2014-04-21T04:32:28.706Z,1398054748.706 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2014-04-21T04:32:28.707Z,1398054748.707 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2014-04-21T04:32:28.831Z,1398054748.831 [CTD_NeilBrown] Loaded 2014-04-21T04:32:28.831Z,1398054748.831 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2014-04-21T04:32:28.832Z,1398054748.832 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 407444E0 2014-04-21T04:32:28.845Z,1398054748.845 [ISUS] Loaded 2014-04-21T04:32:28.845Z,1398054748.845 [ComponentRegistry](DEBUG): SyncComponent "ISUS" handled in the control thread. 2014-04-21T04:32:28.859Z,1398054748.859 [PAR_Licor] Loaded 2014-04-21T04:32:28.860Z,1398054748.860 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2014-04-21T04:32:28.895Z,1398054748.895 [WetLabsBB2FL] Loaded 2014-04-21T04:32:28.895Z,1398054748.895 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2014-04-21T04:32:28.896Z,1398054748.896 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407744E0 2014-04-21T04:32:28.897Z,1398054748.897 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2014-04-21T04:32:28.899Z,1398054748.899 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2014-04-21T04:32:29.012Z,1398054749.012 [SBIT](DEBUG): Construct Startup Built In Test. 2014-04-21T04:32:29.023Z,1398054749.023 [SBIT] Loaded 2014-04-21T04:32:29.024Z,1398054749.024 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2014-04-21T04:32:29.025Z,1398054749.025 [IBIT](DEBUG): Construct Initiated Built In Test. 2014-04-21T04:32:29.037Z,1398054749.037 [IBIT] Loaded 2014-04-21T04:32:29.037Z,1398054749.037 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2014-04-21T04:32:29.039Z,1398054749.039 [CBIT](DEBUG): Construct CBIT Built In Test. 2014-04-21T04:32:29.106Z,1398054749.106 [CBIT] Loaded 2014-04-21T04:32:29.106Z,1398054749.106 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2014-04-21T04:32:29.107Z,1398054749.107 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2014-04-21T04:32:29.109Z,1398054749.109 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2014-04-21T04:32:29.176Z,1398054749.176 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2014-04-21T04:32:29.177Z,1398054749.177 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2014-04-21T04:32:29.295Z,1398054749.295 [BuoyancyServo] Loaded 2014-04-21T04:32:29.295Z,1398054749.295 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2014-04-21T04:32:29.307Z,1398054749.307 [ElevatorServo] Loaded 2014-04-21T04:32:29.308Z,1398054749.308 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2014-04-21T04:32:29.319Z,1398054749.319 [MassServo] Loaded 2014-04-21T04:32:29.319Z,1398054749.319 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2014-04-21T04:32:29.331Z,1398054749.331 [RudderServo] Loaded 2014-04-21T04:32:29.331Z,1398054749.331 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2014-04-21T04:32:29.342Z,1398054749.342 [ThrusterServo] Loaded 2014-04-21T04:32:29.343Z,1398054749.343 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2014-04-21T04:32:29.343Z,1398054749.343 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2014-04-21T04:32:29.344Z,1398054749.344 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2014-04-21T04:32:29.381Z,1398054749.381 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2014-04-21T04:32:29.383Z,1398054749.383 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2014-04-21T04:32:29.384Z,1398054749.384 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2014-04-21T04:32:29.390Z,1398054749.390 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2014-04-21T04:32:29.392Z,1398054749.392 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 408424E0 2014-04-21T04:32:29.396Z,1398054749.396 [Supervisor](DEBUG): Running supervisor. 2014-04-21T04:32:29.397Z,1398054749.397 [CommandLine](INFO): Thread ID is 773 2014-04-21T04:32:29.400Z,1398054749.400 [controlThread](INFO): Thread ID is 772 2014-04-21T04:32:29.400Z,1398054749.400 [controlThread](DEBUG): Initializing ControlThread 2014-04-21T04:32:29.401Z,1398054749.401 [CycleStarter](INFO): Thread ID is 771 2014-04-21T04:32:29.404Z,1398054749.404 [logger](INFO): Thread ID is 774 2014-04-21T04:32:29.423Z,1398054749.423 [AsyncPiEstimator](INFO): Thread ID is 856 2014-04-21T04:32:29.423Z,1398054749.423 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator. 2014-04-21T04:32:29.451Z,1398054749.451 [CTD_NeilBrown](INFO): Thread ID is 857 2014-04-21T04:32:29.451Z,1398054749.451 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown. 2014-04-21T04:32:29.454Z,1398054749.454 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4 2014-04-21T04:32:29.464Z,1398054749.464 [WetLabsBB2FL](INFO): Thread ID is 858 2014-04-21T04:32:29.465Z,1398054749.465 [WetLabsBB2FL](INFO): Powering down 2014-04-21T04:32:29.493Z,1398054749.493 [NavChartDb](INFO): Thread ID is 859 2014-04-21T04:32:29.504Z,1398054749.504 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources 2014-04-21T04:32:29.507Z,1398054749.507 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2014-04-21T04:32:29.507Z,1398054749.507 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2014-04-21T04:32:29.507Z,1398054749.507 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2014-04-21T04:32:29.507Z,1398054749.507 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2014-04-21T04:32:29.508Z,1398054749.508 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2014-04-21T04:32:29.508Z,1398054749.508 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2014-04-21T04:32:29.508Z,1398054749.508 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2014-04-21T04:32:29.508Z,1398054749.508 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2014-04-21T04:32:30.872Z,1398054750.872 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized 2014-04-21T04:32:30.903Z,1398054750.903 [InternalSim](DEBUG): InternalSim initializing... 2014-04-21T04:32:31.201Z,1398054751.201 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2014-04-21T04:32:31.201Z,1398054751.201 [NavChart](DEBUG): Initialize NavChart Navigation. 2014-04-21T04:32:31.202Z,1398054751.202 [UniversalFixResidualReporter](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2014-04-21T04:32:31.202Z,1398054751.202 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2014-04-21T04:32:31.204Z,1398054751.204 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2014-04-21T04:32:31.221Z,1398054751.221 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2014-04-21T04:32:31.221Z,1398054751.221 [LoopControl](DEBUG): Initialize LoopControlComponent. 2014-04-21T04:32:31.222Z,1398054751.222 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2014-04-21T04:32:31.222Z,1398054751.222 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2014-04-21T04:32:31.222Z,1398054751.222 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2014-04-21T04:32:31.223Z,1398054751.223 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2014-04-21T04:32:31.223Z,1398054751.223 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2014-04-21T04:32:31.237Z,1398054751.237 [SBIT](INFO): Initialize SBIT Component. 2014-04-21T04:32:31.237Z,1398054751.237 [SBIT](IMPORTANT): Tethys CM Info: $Rev:11231 2014-04-21T04:32:31.238Z,1398054751.238 [SBIT](IMPORTANT): Kernel Release:2.6.27.8 2014-04-21T04:32:31.238Z,1398054751.238 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014 2014-04-21T04:32:31.239Z,1398054751.239 [IBIT](INFO): Initialize IBIT Component. 2014-04-21T04:32:31.239Z,1398054751.239 [CBIT](DEBUG): Initialize CBIT Component. 2014-04-21T04:32:31.240Z,1398054751.240 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2014-04-21T04:32:31.267Z,1398054751.267 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2014-04-21T04:32:31.292Z,1398054751.292 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-21T04:32:31.325Z,1398054751.325 [MissionManager](DEBUG): 2014-04-21T04:32:31.326Z,1398054751.326 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2014-04-21T04:32:31.397Z,1398054751.397 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool 2014-04-21T04:32:31.399Z,1398054751.399 [Default:GPS:A.SetSpeed](DEBUG): Construct. 2014-04-21T04:32:31.422Z,1398054751.422 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-21T04:32:31.449Z,1398054751.449 [Default:Iridium:A.SetSpeed](DEBUG): Construct. 2014-04-21T04:32:31.452Z,1398054751.452 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-21T04:32:31.475Z,1398054751.475 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2014-04-21T04:32:31.518Z,1398054751.518 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Construct. 2014-04-21T04:32:31.521Z,1398054751.521 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-21T04:32:31.537Z,1398054751.537 [MissionManager](DEBUG): 400 400 Burn 300 Dropped drop weight due to communications timeout 5.0 1.0 5 2014-04-21T04:32:31.558Z,1398054751.558 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,Radio_Freewave,SCPI,ISUS,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2014-04-21T04:32:31.642Z,1398054751.642 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2014-04-21T04:32:31.817Z,1398054751.817 [DVL_micro](INFO): Initializing 2014-04-21T04:32:31.914Z,1398054751.914 [Radio_Freewave](INFO): Powering up 2014-04-21T04:32:32.348Z,1398054752.348 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2014-04-21T04:32:32.355Z,1398054752.355 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2014-04-21T04:32:32.369Z,1398054752.369 [ElevatorServo](DEBUG): Initializing EZServoServo. 2014-04-21T04:32:32.375Z,1398054752.375 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2014-04-21T04:32:32.389Z,1398054752.389 [MassServo](DEBUG): Initializing EZServoServo. 2014-04-21T04:32:32.395Z,1398054752.395 [MassServo](DEBUG): Initializing MassServo. 2014-04-21T04:32:32.417Z,1398054752.417 [RudderServo](DEBUG): Initializing EZServoServo. 2014-04-21T04:32:32.423Z,1398054752.423 [RudderServo](DEBUG): Initializing RudderServo. 2014-04-21T04:32:32.436Z,1398054752.436 [ThrusterServo](DEBUG): Initializing EZServoServo. 2014-04-21T04:32:32.443Z,1398054752.443 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2014-04-21T04:32:32.682Z,1398054752.682 [NAL9602](INFO): Powering up NAL9602 2014-04-21T04:32:32.917Z,1398054752.917 [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-21T04:32:33.328Z,1398054753.328 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout 2014-04-21T04:32:33.328Z,1398054753.328 [BuoyancyServo](FAULT): Buoyancy failed to initialize 2014-04-21T04:32:33.328Z,1398054753.328 [BuoyancyServo] Communications Fault, FailCount= 1 2014-04-21T04:32:33.328Z,1398054753.328 [BuoyancyServo](ERROR): Communications Fault 2014-04-21T04:32:33.539Z,1398054753.539 [CBIT](ERROR): Communications Fault in component: BuoyancyServo 2014-04-21T04:32:34.083Z,1398054754.083 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2014-04-21T04:32:34.085Z,1398054754.085 [BuoyancyServo](INFO): Powering down 2014-04-21T04:32:36.612Z,1398054756.612 [CBIT](INFO): Clearing failed state for component BuoyancyServo 2014-04-21T04:32:36.612Z,1398054756.612 [BuoyancyServo] No Fault, FailCount= 1 2014-04-21T04:32:37.087Z,1398054757.087 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2014-04-21T04:32:37.087Z,1398054757.087 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2014-04-21T04:32:37.999Z,1398054757.999 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout 2014-04-21T04:32:37.999Z,1398054757.999 [BuoyancyServo](FAULT): Buoyancy failed to initialize 2014-04-21T04:32:37.000Z,1398054758.000 [BuoyancyServo] Communications Fault, FailCount= 2 2014-04-21T04:32:37.000Z,1398054758.000 [BuoyancyServo](ERROR): Communications Fault 2014-04-21T04:32:38.040Z,1398054758.040 [CBIT](ERROR): Communications Fault in component: BuoyancyServo 2014-04-21T04:32:38.539Z,1398054758.539 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2014-04-21T04:32:38.540Z,1398054758.540 [BuoyancyServo](INFO): Powering down 2014-04-21T04:32:40.881Z,1398054760.881 [CBIT](INFO): Clearing failed state for component BuoyancyServo 2014-04-21T04:32:40.881Z,1398054760.881 [BuoyancyServo] No Fault, FailCount= 2 2014-04-21T04:32:41.481Z,1398054761.481 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2014-04-21T04:32:41.482Z,1398054761.482 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2014-04-21T04:32:43.344Z,1398054763.344 [NAL9602](INFO): NAL9602 initialized 2014-04-21T04:32:46.891Z,1398054766.891 [SBIT](IMPORTANT): Beginning Startup BIT 2014-04-21T04:32:46.907Z,1398054766.907 [CBIT](IMPORTANT): Beginning GF scan 2014-04-21T04:32:54.774Z,1398054774.774 [NAL9602](INFO): SBD MO Status=0, MOMSN=27922, MT Status=0, MTMSN=0 2014-04-21T04:32:54.774Z,1398054774.774 [NAL9602](INFO): No messages in MT queue 2014-04-21T04:33:11.370Z,1398054791.370 [NAL9602](IMPORTANT): GPS fix at: 1398054771.00 2014-04-21T04:33:14.210Z,1398054794.210 [CBIT](FAULT): Chan 0 High side GF detected mA: CHAN 5 (24V): 0.178678 CHAN 4 (Batt): 0.119087 CHAN 2 (12V): 0.081113 CHAN 1 (5V): 0.036443 CHAN 0 (3.3V): 0.028504 OPEN: 0.000765 Full Scale Calc: 0.392 2014-04-21T04:33:19.422Z,1398054799.422 [NAL9602](INFO): Powering down 2014-04-21T04:33:22.396Z,1398054802.396 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-21T04:33:22.400Z,1398054802.400 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 29.3 29.2 29.1 29.1 -399.0 -448.6 -334.0 -301.9 -413 -408 -303 -215 6 6 6 6 -86.8 -195.8 -400.0 1 204.0 -73.2 -398.6 257 -361 2 259 -142 -361 2 -1.01 -1.49 90.9 29.1 16.0 0.005 35.0 1489 102 2014-04-21T04:33:40.956Z,1398054820.956 [SBIT](IMPORTANT): SBIT PASSED 2014-04-21T04:33:41.373Z,1398054821.373 [MissionManager](IMPORTANT): Started mission Startup 2014-04-21T04:33:41.373Z,1398054821.373 [Startup] Running Loop=1 2014-04-21T04:33:41.374Z,1398054821.374 [Startup](INFO): Aggregate::initialize Startup 2014-04-21T04:33:41.374Z,1398054821.374 [Startup:A.GoToSurface] Running Loop=1 2014-04-21T04:33:41.374Z,1398054821.374 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-21T04:33:41.380Z,1398054821.380 [Startup:StartupSatComms] Running Loop=1 2014-04-21T04:33:41.380Z,1398054821.380 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms 2014-04-21T04:33:41.381Z,1398054821.381 [Startup:StartupSatComms:A] Running Loop=1 2014-04-21T04:33:41.811Z,1398054821.811 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2014-04-21T04:33:42.238Z,1398054822.238 [NAL9602](INFO): Powering up 2014-04-21T04:33:52.803Z,1398054832.803 [NAL9602](INFO): NAL9602 initialized 2014-04-21T04:34:07.083Z,1398054847.083 [DVL_micro](ERROR): No DVL communication! Re-initializing 2014-04-21T04:34:07.083Z,1398054847.083 [DVL_micro] Communications Fault, FailCount= 1 2014-04-21T04:34:07.083Z,1398054847.083 [DVL_micro](ERROR): Communications Fault 2014-04-21T04:34:07.148Z,1398054847.148 [CBIT](ERROR): Communications Fault in component: DVL_micro 2014-04-21T04:34:07.519Z,1398054847.519 [DVL_micro](INFO): uninitialize:Powering down 2014-04-21T04:34:07.932Z,1398054847.932 [DVL_micro](FAULT): LCB fault: Software Overcurrent. 2014-04-21T04:34:07.932Z,1398054847.932 [DVL_micro] Hardware Fault, FailCount= 1 2014-04-21T04:34:07.932Z,1398054847.932 [DVL_micro](ERROR): Hardware Fault 2014-04-21T04:34:08.395Z,1398054848.395 [CBIT](INFO): Clearing failed state for component DVL_micro 2014-04-21T04:34:08.395Z,1398054848.395 [DVL_micro] No Fault, FailCount= 1 2014-04-21T04:34:08.800Z,1398054848.800 [DVL_micro](INFO): Initializing 2014-04-21T04:34:10.916Z,1398054850.916 [NAL9602](INFO): SBD MO Status=0, MOMSN=27923, MT Status=0, MTMSN=0 2014-04-21T04:34:10.916Z,1398054850.916 [NAL9602](INFO): No messages in MT queue 2014-04-21T04:34:17.823Z,1398054857.823 [NAL9602](IMPORTANT): GPS fix at: 1398054838.00 2014-04-21T04:34:17.841Z,1398054857.841 [Startup:StartupSatComms:A] Stopped 2014-04-21T04:34:17.841Z,1398054857.841 [Startup:StartupSatComms:B] Running Loop=1 2014-04-21T04:34:18.318Z,1398054858.318 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2014-04-21T04:34:40.924Z,1398054880.924 [NAL9602](INFO): SBD MO Status=1, MOMSN=27924, MT Status=0, MTMSN=0 2014-04-21T04:34:40.982Z,1398054880.982 [NAL9602](INFO): Sent 25 bytes from file Logs/20140421T040726/Courier0024.lzma 2014-04-21T04:34:40.982Z,1398054880.982 [NAL9602](INFO): Packets left to send: 0 2014-04-21T04:34:40.984Z,1398054880.984 [NAL9602](INFO): Stored copy of sent data in Logs/20140421T040726/Courier0024.lzma.parts/0000.sbd 2014-04-21T04:34:40.984Z,1398054880.984 [NAL9602](INFO): Completed sending Logs/20140421T040726/Courier0024.lzma 2014-04-21T04:34:52.893Z,1398054892.893 [NAL9602](INFO): SBD MO Status=1, MOMSN=27925, MT Status=0, MTMSN=0 2014-04-21T04:34:52.941Z,1398054892.941 [NAL9602](INFO): Sent 294 bytes from file Logs/20140421T043220/Courier0000.lzma 2014-04-21T04:34:52.941Z,1398054892.941 [NAL9602](INFO): Packets left to send: 0 2014-04-21T04:34:52.943Z,1398054892.943 [NAL9602](INFO): Stored copy of sent data in Logs/20140421T043220/Courier0000.lzma.parts/0000.sbd 2014-04-21T04:34:52.943Z,1398054892.943 [NAL9602](INFO): Completed sending Logs/20140421T043220/Courier0000.lzma 2014-04-21T04:35:05.062Z,1398054905.062 [NAL9602](INFO): SBD MO Status=1, MOMSN=27926, MT Status=0, MTMSN=0 2014-04-21T04:35:05.124Z,1398054905.124 [NAL9602](INFO): Sent 280 bytes from file Logs/20140421T040726/Express0021.lzma 2014-04-21T04:35:05.124Z,1398054905.124 [NAL9602](INFO): Packets left to send: 0 2014-04-21T04:35:05.126Z,1398054905.126 [NAL9602](INFO): Stored copy of sent data in Logs/20140421T040726/Express0021.lzma.parts/0000.sbd 2014-04-21T04:35:05.126Z,1398054905.126 [NAL9602](INFO): Completed sending Logs/20140421T040726/Express0021.lzma 2014-04-21T04:35:14.272Z,1398054914.272 [NAL9602](INFO): SBD MO Status=1, MOMSN=27927, MT Status=0, MTMSN=0 2014-04-21T04:35:14.339Z,1398054914.339 [NAL9602](INFO): Sent 147 bytes from file Logs/20140421T040726/Express0025.lzma 2014-04-21T04:35:14.339Z,1398054914.339 [NAL9602](INFO): Packets left to send: 0 2014-04-21T04:35:14.341Z,1398054914.341 [NAL9602](INFO): Stored copy of sent data in Logs/20140421T040726/Express0025.lzma.parts/0000.sbd 2014-04-21T04:35:14.341Z,1398054914.341 [NAL9602](INFO): Completed sending Logs/20140421T040726/Express0025.lzma 2014-04-21T04:35:17.974Z,1398054917.974 [Startup:StartupSatComms:B](INFO): Timed out from 2014-04-21T04:34:17.8Z 2014-04-21T04:35:17.974Z,1398054917.974 [Startup:StartupSatComms:B] Stopped 2014-04-21T04:35:17.974Z,1398054917.974 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2014-04-21T04:35:17.974Z,1398054917.974 [Startup:StartupSatComms] Stopped 2014-04-21T04:35:17.974Z,1398054917.974 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms 2014-04-21T04:35:17.976Z,1398054917.976 [Startup](INFO): Completed Startup 2014-04-21T04:35:17.976Z,1398054917.976 [Startup] Stopped 2014-04-21T04:35:17.976Z,1398054917.976 [Startup](INFO): Aggregate::uninitialize Startup 2014-04-21T04:35:17.976Z,1398054917.976 [Startup:A.GoToSurface] Stopped 2014-04-21T04:35:17.976Z,1398054917.976 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-21T04:35:18.395Z,1398054918.395 [MissionManager](IMPORTANT): Started mission Default 2014-04-21T04:35:18.395Z,1398054918.395 [Default] Running Loop=1 2014-04-21T04:35:18.395Z,1398054918.395 [Default](INFO): Aggregate::initialize Default 2014-04-21T04:35:18.395Z,1398054918.395 [Default:Iridium] Running Loop=1 2014-04-21T04:35:18.396Z,1398054918.396 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2014-04-21T04:35:18.396Z,1398054918.396 [Default:Iridium:A.SetSpeed] Running Loop=1 2014-04-21T04:35:18.396Z,1398054918.396 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2014-04-21T04:35:18.396Z,1398054918.396 [Default:Iridium:B.GoToSurface] Running Loop=1 2014-04-21T04:35:18.396Z,1398054918.396 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-21T04:35:18.397Z,1398054918.397 [Default:CallIridium] Running Loop=1 2014-04-21T04:35:18.397Z,1398054918.397 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2014-04-21T04:35:18.397Z,1398054918.397 [Default:CallIridium:A] Running Loop=1 2014-04-21T04:35:18.399Z,1398054918.399 [Default:CallIridium:A] Stopped 2014-04-21T04:35:18.399Z,1398054918.399 [Default:CallIridium:B] Running Loop=1 2014-04-21T04:35:18.399Z,1398054918.399 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2014-04-21T04:35:18.437Z,1398054918.437 [Default:Iridium:B.GoToSurface] Stopped 2014-04-21T04:35:18.437Z,1398054918.437 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-21T04:35:18.437Z,1398054918.437 [Default:Iridium:Read_Iridium] Running Loop=1 2014-04-21T04:35:18.437Z,1398054918.437 [Default:Iridium:A.SetSpeed] Running Loop=1 2014-04-21T04:35:18.451Z,1398054918.451 [Default:GPS] Running Loop=1 2014-04-21T04:35:18.451Z,1398054918.451 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2014-04-21T04:35:18.451Z,1398054918.451 [Default:GPS:A.SetSpeed] Running Loop=1 2014-04-21T04:35:18.451Z,1398054918.451 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2014-04-21T04:35:18.451Z,1398054918.451 [Default:GPS:B.GoToSurface] Running Loop=1 2014-04-21T04:35:18.451Z,1398054918.451 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-21T04:35:18.465Z,1398054918.465 [Default:GPS:B.GoToSurface] Stopped 2014-04-21T04:35:18.465Z,1398054918.465 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-21T04:35:18.465Z,1398054918.465 [Default:GPS:Read_GPS] Running Loop=1 2014-04-21T04:35:18.465Z,1398054918.465 [Default:GPS:A.SetSpeed] Running Loop=1 2014-04-21T04:35:18.889Z,1398054918.889 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2014-04-21T04:35:18.892Z,1398054918.892 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2014-04-21T04:35:28.468Z,1398054928.468 [NAL9602](INFO): SBD MO Status=1, MOMSN=27928, MT Status=0, MTMSN=0 2014-04-21T04:35:28.524Z,1398054928.524 [NAL9602](INFO): Sent 332 bytes from file Logs/20140421T043220/Express0001.lzma 2014-04-21T04:35:28.524Z,1398054928.524 [NAL9602](INFO): Packets left to send: 2 2014-04-21T04:35:28.527Z,1398054928.527 [NAL9602](INFO): Stored copy of sent data in Logs/20140421T043220/Express0001.lzma.parts/0002.sbd 2014-04-21T04:35:40.518Z,1398054940.518 [NAL9602](INFO): SBD MO Status=1, MOMSN=27929, MT Status=0, MTMSN=0 2014-04-21T04:35:40.570Z,1398054940.570 [NAL9602](INFO): Sent 47 bytes from file Logs/20140421T043220/Courier0004.lzma 2014-04-21T04:35:40.570Z,1398054940.570 [NAL9602](INFO): Packets left to send: 0 2014-04-21T04:35:40.572Z,1398054940.572 [NAL9602](INFO): Stored copy of sent data in Logs/20140421T043220/Courier0004.lzma.parts/0000.sbd 2014-04-21T04:35:40.572Z,1398054940.572 [NAL9602](INFO): Completed sending Logs/20140421T043220/Courier0004.lzma 2014-04-21T04:35:49.506Z,1398054949.506 [NAL9602](INFO): SBD MO Status=1, MOMSN=27930, MT Status=0, MTMSN=0 2014-04-21T04:35:49.565Z,1398054949.565 [NAL9602](INFO): Sent 332 bytes from file Logs/20140421T043220/Express0001.lzma 2014-04-21T04:35:49.565Z,1398054949.565 [NAL9602](INFO): Packets left to send: 1 2014-04-21T04:35:49.566Z,1398054949.566 [NAL9602](INFO): Stored copy of sent data in Logs/20140421T043220/Express0001.lzma.parts/0001.sbd 2014-04-21T04:35:57.597Z,1398054957.597 [NAL9602](INFO): SBD MO Status=1, MOMSN=27931, MT Status=0, MTMSN=0 2014-04-21T04:35:57.657Z,1398054957.657 [NAL9602](INFO): Sent 269 bytes from file Logs/20140421T043220/Express0001.lzma 2014-04-21T04:35:57.657Z,1398054957.657 [NAL9602](INFO): Packets left to send: 0 2014-04-21T04:35:57.658Z,1398054957.658 [NAL9602](INFO): Stored copy of sent data in Logs/20140421T043220/Express0001.lzma.parts/0000.sbd 2014-04-21T04:35:57.659Z,1398054957.659 [NAL9602](INFO): Completed sending Logs/20140421T043220/Express0001.lzma 2014-04-21T04:36:05.969Z,1398054965.969 [NAL9602](INFO): SBD MO Status=1, MOMSN=27932, MT Status=0, MTMSN=0 2014-04-21T04:36:06.022Z,1398054966.022 [NAL9602](INFO): Sent 100 bytes from file Logs/20140421T043220/Express0005.lzma 2014-04-21T04:36:06.022Z,1398054966.022 [NAL9602](INFO): Packets left to send: 0 2014-04-21T04:36:06.024Z,1398054966.024 [NAL9602](INFO): Stored copy of sent data in Logs/20140421T043220/Express0005.lzma.parts/0000.sbd 2014-04-21T04:36:06.024Z,1398054966.024 [NAL9602](INFO): Completed sending Logs/20140421T043220/Express0005.lzma 2014-04-21T04:36:13.382Z,1398054973.382 [NAL9602](INFO): SBD MO Status=0, MOMSN=27933, MT Status=0, MTMSN=0 2014-04-21T04:36:13.478Z,1398054973.478 [Default:Iridium:Read_Iridium] Stopped 2014-04-21T04:36:13.478Z,1398054973.478 [Default:Iridium](INFO): Completed Default:Iridium 2014-04-21T04:36:13.478Z,1398054973.478 [Default:Iridium] Stopped 2014-04-21T04:36:13.478Z,1398054973.478 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2014-04-21T04:36:13.478Z,1398054973.478 [Default:Iridium:A.SetSpeed] Stopped 2014-04-21T04:36:13.478Z,1398054973.478 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2014-04-21T04:36:13.478Z,1398054973.478 [Default:WaitAtTheSurface] Running Loop=1 2014-04-21T04:36:13.479Z,1398054973.479 [Default:WaitAtTheSurface](INFO): Aggregate::initialize Default:WaitAtTheSurface 2014-04-21T04:36:13.479Z,1398054973.479 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Running Loop=1 2014-04-21T04:36:13.479Z,1398054973.479 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Initialize. 2014-04-21T04:36:13.479Z,1398054973.479 [Default:WaitAtTheSurface:B.GoToSurface] Running Loop=1 2014-04-21T04:36:13.479Z,1398054973.479 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-21T04:36:13.961Z,1398054973.961 [Default:WaitAtTheSurface:B.GoToSurface] Running Loop=1 2014-04-21T04:36:13.986Z,1398054973.986 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Running Loop=1 2014-04-21T04:36:13.996Z,1398054973.996 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2014-04-21T04:36:13.996Z,1398054973.996 [Default:CallIridium:B] Stopped 2014-04-21T04:36:13.996Z,1398054973.996 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2014-04-21T04:36:13.996Z,1398054973.996 [Default:CallIridium](INFO): Completed Default:CallIridium 2014-04-21T04:36:13.996Z,1398054973.996 [Default:CallIridium] Stopped 2014-04-21T04:36:13.996Z,1398054973.996 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2014-04-21T04:36:14.836Z,1398054974.836 [NAL9602](IMPORTANT): GPS fix at: 1398054955.00 2014-04-21T04:36:14.855Z,1398054974.855 [Default:GPS:Read_GPS] Stopped 2014-04-21T04:36:14.855Z,1398054974.855 [Default:GPS:D] Running Loop=1 2014-04-21T04:36:15.311Z,1398054975.311 [Default:GPS:D] Stopped 2014-04-21T04:36:15.311Z,1398054975.311 [Default:GPS](INFO): Completed Default:GPS 2014-04-21T04:36:15.311Z,1398054975.311 [Default:GPS] Stopped 2014-04-21T04:36:15.311Z,1398054975.311 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2014-04-21T04:36:15.311Z,1398054975.311 [Default:GPS:A.SetSpeed] Stopped 2014-04-21T04:36:15.311Z,1398054975.311 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2014-04-21T04:36:35.912Z,1398054995.912 [NAL9602](INFO): Powering down 2014-04-21T04:41:16.023Z,1398055276.023 [Default:CallIridium] Running Loop=1 2014-04-21T04:41:16.023Z,1398055276.023 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2014-04-21T04:41:16.024Z,1398055276.024 [Default:CallIridium:A] Running Loop=1 2014-04-21T04:41:16.024Z,1398055276.024 [Default:CallIridium:A] Stopped 2014-04-21T04:41:16.024Z,1398055276.024 [Default:CallIridium:B] Running Loop=1 2014-04-21T04:41:16.024Z,1398055276.024 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2014-04-21T04:41:20.883Z,1398055280.883 [Default:Iridium] Running Loop=1 2014-04-21T04:41:20.883Z,1398055280.883 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2014-04-21T04:41:20.883Z,1398055280.883 [Default:Iridium:A.SetSpeed] Running Loop=1 2014-04-21T04:41:20.883Z,1398055280.883 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2014-04-21T04:41:20.883Z,1398055280.883 [Default:Iridium:B.GoToSurface] Running Loop=1 2014-04-21T04:41:20.884Z,1398055280.884 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-21T04:41:20.884Z,1398055280.884 [Default:Iridium:B.GoToSurface] Stopped 2014-04-21T04:41:20.884Z,1398055280.884 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-21T04:41:20.885Z,1398055280.885 [Default:Iridium:Read_Iridium] Running Loop=1 2014-04-21T04:41:20.885Z,1398055280.885 [Default:GPS] Running Loop=1 2014-04-21T04:41:20.885Z,1398055280.885 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2014-04-21T04:41:20.885Z,1398055280.885 [Default:GPS:A.SetSpeed] Running Loop=1 2014-04-21T04:41:20.885Z,1398055280.885 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2014-04-21T04:41:20.885Z,1398055280.885 [Default:GPS:B.GoToSurface] Running Loop=1 2014-04-21T04:41:20.885Z,1398055280.885 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-21T04:41:20.886Z,1398055280.886 [Default:GPS:B.GoToSurface] Stopped 2014-04-21T04:41:20.887Z,1398055280.887 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-21T04:41:20.887Z,1398055280.887 [Default:GPS:Read_GPS] Running Loop=1 2014-04-21T04:41:21.971Z,1398055281.971 [NAL9602](INFO): Powering up 2014-04-21T04:41:32.921Z,1398055292.921 [NAL9602](INFO): NAL9602 initialized 2014-04-21T04:41:51.280Z,1398055311.280 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=27934, MT Status=1, MTMSN=1828 2014-04-21T04:41:51.333Z,1398055311.333 [NAL9602](INFO): Sent 78 bytes from file Logs/20140421T043220/Courier0008.lzma 2014-04-21T04:41:51.334Z,1398055311.334 [NAL9602](INFO): Packets left to send: 0 2014-04-21T04:41:51.335Z,1398055311.335 [NAL9602](INFO): Stored copy of sent data in Logs/20140421T043220/Courier0008.lzma.parts/0000.sbd 2014-04-21T04:41:51.336Z,1398055311.336 [NAL9602](INFO): Completed sending Logs/20140421T043220/Courier0008.lzma 2014-04-21T04:41:52.107Z,1398055312.107 [NAL9602](INFO): Received command:load Science/EcoHAB_box.xml;set EcoHAB_box.NeedCommsTime 30 minute;set EcoHAB_box.MissionTimeout 48 hour;set EcoHAB_box.LapTimeout 12 hour;run 2014-04-21T04:41:52.147Z,1398055312.147 [CommandLine](IMPORTANT): got command load ./Missions/Science/EcoHAB_box.xml 2014-04-21T04:41:52.147Z,1398055312.147 [MissionManager](INFO): Loading Mission: ./Missions/Science/EcoHAB_box.xml 2014-04-21T04:41:52.366Z,1398055312.366 [MissionManager](INFO): DefineArg EcoHAB_box.NeedCommsTime = 36.000000 h 2014-04-21T04:41:52.370Z,1398055312.370 [MissionManager](INFO): DefineArg EcoHAB_box.MinAltitude = 4.000000 m 2014-04-21T04:41:52.373Z,1398055312.373 [MissionManager](INFO): DefineArg EcoHAB_box.MaxDepth = 85.000000 m 2014-04-21T04:41:52.400Z,1398055312.400 [MissionManager](INFO): DefineArg EcoHAB_box.MinOffshore = 2000.000000 m 2014-04-21T04:41:52.404Z,1398055312.404 [MissionManager](INFO): DefineArg EcoHAB_box.Speed = 1.000000 m/s 2014-04-21T04:41:52.407Z,1398055312.407 [MissionManager](INFO): DefineArg EcoHAB_box.MissionTimeout = 9.000000 h 2014-04-21T04:41:52.411Z,1398055312.411 [MissionManager](INFO): DefineArg EcoHAB_box.MassDefault = 0.010000 n/a 2014-04-21T04:41:52.415Z,1398055312.415 [MissionManager](INFO): DefineArg EcoHAB_box.BuoyancyNeutral = 0.000280 n/a 2014-04-21T04:41:52.419Z,1398055312.419 [MissionManager](INFO): DefineArg EcoHAB_box.WpESPInshoreLat = 33.607614 arcdeg 2014-04-21T04:41:52.422Z,1398055312.422 [MissionManager](INFO): DefineArg EcoHAB_box.WpESPInshoreLon = -118.018798 arcdeg 2014-04-21T04:41:52.458Z,1398055312.458 [MissionManager](INFO): DefineArg EcoHAB_box.WpESPOffshoreLat = 33.585471 arcdeg 2014-04-21T04:41:52.462Z,1398055312.462 [MissionManager](INFO): DefineArg EcoHAB_box.WpESPOffshoreLon = -118.037372 arcdeg 2014-04-21T04:41:52.466Z,1398055312.466 [MissionManager](INFO): DefineArg EcoHAB_box.WpCorner1Lat = 33.586554 arcdeg 2014-04-21T04:41:52.478Z,1398055312.478 [MissionManager](INFO): DefineArg EcoHAB_box.WpCorner1Lon = -117.979903 arcdeg 2014-04-21T04:41:52.481Z,1398055312.481 [MissionManager](INFO): DefineArg EcoHAB_box.WpCorner2Lat = 33.563841 arcdeg 2014-04-21T04:41:52.485Z,1398055312.485 [MissionManager](INFO): DefineArg EcoHAB_box.WpCorner2Lon = -117.997449 arcdeg 2014-04-21T04:41:52.504Z,1398055312.504 [MissionManager](INFO): DefineArg EcoHAB_box.WpCorner3Lat = 33.606518 arcdeg 2014-04-21T04:41:52.508Z,1398055312.508 [MissionManager](INFO): DefineArg EcoHAB_box.WpCorner3Lon = -118.076276 arcdeg 2014-04-21T04:41:52.534Z,1398055312.534 [MissionManager](INFO): DefineArg EcoHAB_box.WpCorner4Lat = 33.628662 arcdeg 2014-04-21T04:41:52.538Z,1398055312.538 [MissionManager](INFO): DefineArg EcoHAB_box.WpCorner4Lon = -118.057712 arcdeg 2014-04-21T04:41:52.541Z,1398055312.541 [MissionManager](INFO): DefineArg EcoHAB_box.ApproachDepth = 10.000000 m 2014-04-21T04:41:52.560Z,1398055312.560 [MissionManager](INFO): DefineArg EcoHAB_box.ApproachTimeout = 4.000000 h 2014-04-21T04:41:52.564Z,1398055312.564 [MissionManager](INFO): DefineArg EcoHAB_box.ApproachNeedCommsTime = 20.000000 min 2014-04-21T04:41:52.582Z,1398055312.582 [MissionManager](INFO): DefineArg EcoHAB_box.Repeat = 13.000000 count 2014-04-21T04:41:52.586Z,1398055312.586 [MissionManager](INFO): DefineArg EcoHAB_box.CircleRadius = 500.000000 m 2014-04-21T04:41:52.617Z,1398055312.617 [MissionManager](INFO): DefineArg EcoHAB_box.CircleRepeat = 13.000000 count 2014-04-21T04:41:52.620Z,1398055312.620 [MissionManager](INFO): DefineArg EcoHAB_box.CircleDivisor = 2.000000 h 2014-04-21T04:41:52.639Z,1398055312.639 [MissionManager](INFO): DefineArg EcoHAB_box.CircleModulus = nan h 2014-04-21T04:41:52.643Z,1398055312.643 [MissionManager](INFO): DefineArg EcoHAB_box.CircleTimeout = 3.000000 h 2014-04-21T04:41:52.646Z,1398055312.646 [MissionManager](INFO): DefineArg EcoHAB_box.LapTimeout = 8.000000 h 2014-04-21T04:41:52.682Z,1398055312.682 [MissionManager](INFO): DefineArg EcoHAB_box.SCPITimeout = 420.000000 s 2014-04-21T04:41:52.686Z,1398055312.686 [MissionManager](INFO): DefineArg EcoHAB_box.YoYoMinDepth = 4.000000 m 2014-04-21T04:41:52.689Z,1398055312.689 [MissionManager](INFO): DefineArg EcoHAB_box.YoYoMaxDepth = 78.000000 m 2014-04-21T04:41:52.708Z,1398055312.708 [MissionManager](INFO): DefineArg EcoHAB_box.YoYoMinAltitude = 6.000000 m 2014-04-21T04:41:52.712Z,1398055312.712 [MissionManager](INFO): DefineArg EcoHAB_box.YoYoUpPitch = 20.000000 arcdeg 2014-04-21T04:41:52.738Z,1398055312.738 [MissionManager](INFO): DefineArg EcoHAB_box.YoYoDownPitch = -20.000000 arcdeg 2014-04-21T04:41:52.739Z,1398055312.739 [EcoHAB_box:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope. 2014-04-21T04:41:52.747Z,1398055312.747 [EcoHAB_box:B.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2014-04-21T04:41:52.770Z,1398055312.770 [EcoHAB_box:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope. 2014-04-21T04:41:52.795Z,1398055312.795 [MissionManager](INFO): Inserting Stack: Missions/Insert/NeedComms.xml 2014-04-21T04:41:52.857Z,1398055312.857 [MissionManager](INFO): DefineArg EcoHAB_box:NeedComms.CommsTimeout = 30.000000 min 2014-04-21T04:41:52.861Z,1398055312.861 [MissionManager](INFO): DefineArg EcoHAB_box:NeedComms.DiveInterval = 3.000000 h 2014-04-21T04:41:52.877Z,1398055312.877 [MissionManager](INFO): DefineArg EcoHAB_box:NeedComms.WaitForPitchUp = 10.000000 min 2014-04-21T04:41:52.880Z,1398055312.880 [MissionManager](INFO): DefineArg EcoHAB_box:NeedComms.SurfacePitch = 20.000000 arcdeg 2014-04-21T04:41:52.884Z,1398055312.884 [MissionManager](INFO): DefineArg EcoHAB_box:NeedComms.SurfaceSpeed = 1.000000 m/s 2014-04-21T04:41:52.900Z,1398055312.900 [EcoHAB_box:NeedComms:A.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-21T04:41:52.920Z,1398055312.920 [MissionManager](INFO): Inserting Stack: Missions/Insert/Surface.xml 2014-04-21T04:41:52.950Z,1398055312.950 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceComms.SurfaceDepthRate = nan m/s 2014-04-21T04:41:52.974Z,1398055312.974 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceComms.SurfacePitch = 20.000000 arcdeg 2014-04-21T04:41:52.977Z,1398055312.977 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceComms.SurfaceSpeed = 1.000000 m/s 2014-04-21T04:41:53.007Z,1398055313.007 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceComms.IridiumTimeout = 30.000000 min 2014-04-21T04:41:53.011Z,1398055313.011 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceComms.UnpackSplitAtSurface = 0 bool 2014-04-21T04:41:53.012Z,1398055313.012 [EcoHAB_box:SurfaceComms:A.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-21T04:41:53.035Z,1398055313.035 [MissionManager](INFO): Inserting Stack: Missions/Insert/SurfaceCommsSplit.xml 2014-04-21T04:41:53.070Z,1398055313.070 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceCommsSplit.SurfacePitch = 20.000000 arcdeg 2014-04-21T04:41:53.074Z,1398055313.074 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceCommsSplit.SurfaceSpeed = 1.000000 m/s 2014-04-21T04:41:53.074Z,1398055313.074 [MissionManager](INFO): Inserting Stack: Missions/Insert/Surface.xml 2014-04-21T04:41:53.128Z,1398055313.128 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceCommsSplit:SurfaceComms.SurfaceDepthRate = nan m/s 2014-04-21T04:41:53.131Z,1398055313.131 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceCommsSplit:SurfaceComms.SurfacePitch = 20.000000 arcdeg 2014-04-21T04:41:53.151Z,1398055313.151 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceCommsSplit:SurfaceComms.SurfaceSpeed = 1.000000 m/s 2014-04-21T04:41:53.154Z,1398055313.154 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceCommsSplit:SurfaceComms.IridiumTimeout = 30.000000 min 2014-04-21T04:41:53.173Z,1398055313.173 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceCommsSplit:SurfaceComms.UnpackSplitAtSurface = 0 bool 2014-04-21T04:41:53.175Z,1398055313.175 [EcoHAB_box:SurfaceCommsSplit:SurfaceComms:A.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-21T04:41:53.198Z,1398055313.198 [MissionManager](INFO): RedefineArg EcoHAB_box:SurfaceCommsSplit:SurfaceComms.SurfacePitch = value:20.000000 arcdeg 2014-04-21T04:41:53.201Z,1398055313.201 [MissionManager](INFO): RedefineArg EcoHAB_box:SurfaceCommsSplit:SurfaceComms.SurfaceSpeed = value:1.000000 m/s 2014-04-21T04:41:53.202Z,1398055313.202 [MissionManager](INFO): RedefineArg EcoHAB_box:SurfaceCommsSplit:SurfaceComms.UnpackSplitAtSurface = value:1 bool 2014-04-21T04:41:53.203Z,1398055313.203 [MissionManager](INFO): Inserting Stack: Missions/Insert/SurfaceCommsShort.xml 2014-04-21T04:41:53.241Z,1398055313.241 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceCommsShort.FloatTime = 180.000000 s 2014-04-21T04:41:53.245Z,1398055313.245 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceCommsShort.Timeout = 1.000000 h 2014-04-21T04:41:53.272Z,1398055313.272 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceCommsShort.Pitch = 20.000000 arcdeg 2014-04-21T04:41:53.275Z,1398055313.275 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceCommsShort.Speed = 1.000000 m/s 2014-04-21T04:41:53.277Z,1398055313.277 [EcoHAB_box:SurfaceCommsShort:A.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-21T04:41:53.300Z,1398055313.300 [MissionManager](INFO): Inserting Stack: Missions/Insert/SurfaceGPS.xml 2014-04-21T04:41:53.338Z,1398055313.338 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceGPS.HalfTimeout = 30.000000 s 2014-04-21T04:41:53.341Z,1398055313.341 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceGPS.SurfacePitch = 20.000000 arcdeg 2014-04-21T04:41:53.356Z,1398055313.356 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceGPS.SurfaceSpeed = 1.000000 m/s 2014-04-21T04:41:53.357Z,1398055313.357 [EcoHAB_box:SurfaceGPS:A.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-21T04:41:53.364Z,1398055313.364 [MissionManager](INFO): Inserting Stack: Missions/Insert/SurfaceSafety.xml 2014-04-21T04:41:53.416Z,1398055313.416 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceSafety.MaxTime = 11.000000 h 2014-04-21T04:41:53.429Z,1398055313.429 [MissionManager](INFO): Inserting Stack: Missions/Insert/Surface.xml 2014-04-21T04:41:53.461Z,1398055313.461 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceSafety:SurfaceComms.SurfaceDepthRate = nan m/s 2014-04-21T04:41:53.481Z,1398055313.481 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceSafety:SurfaceComms.SurfacePitch = 20.000000 arcdeg 2014-04-21T04:41:53.485Z,1398055313.485 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceSafety:SurfaceComms.SurfaceSpeed = 1.000000 m/s 2014-04-21T04:41:53.488Z,1398055313.488 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceSafety:SurfaceComms.IridiumTimeout = 30.000000 min 2014-04-21T04:41:53.491Z,1398055313.491 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceSafety:SurfaceComms.UnpackSplitAtSurface = 0 bool 2014-04-21T04:41:53.509Z,1398055313.509 [EcoHAB_box:SurfaceSafety:SurfaceComms:A.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-21T04:41:53.534Z,1398055313.534 [MissionManager](INFO): RedefineArg EcoHAB_box:SurfaceSafety:SurfaceComms.SurfacePitch = value:20.000000 arcdeg 2014-04-21T04:41:53.536Z,1398055313.536 [MissionManager](INFO): RedefineArg EcoHAB_box:SurfaceSafety:SurfaceComms.SurfaceSpeed = value:1.000000 m/s 2014-04-21T04:41:53.537Z,1398055313.537 [EcoHAB_box:L.Pitch](DEBUG): Construct. 2014-04-21T04:41:53.543Z,1398055313.543 [EcoHAB_box:M.Buoyancy](DEBUG): Construct Buoyancy. 2014-04-21T04:41:53.560Z,1398055313.560 [MissionManager](INFO): Inserting Stack: Missions/Insert/CircleWaypointRepeatedly.xml 2014-04-21T04:41:53.660Z,1398055313.660 [MissionManager](INFO): DefineArg EcoHAB_box:CircleWaypointRepeatedly.Timeout = 90.000000 min 2014-04-21T04:41:53.673Z,1398055313.673 [MissionManager](INFO): DefineArg EcoHAB_box:CircleWaypointRepeatedly.LapTimeout = 240.000000 min 2014-04-21T04:41:53.676Z,1398055313.676 [MissionManager](INFO): DefineArg EcoHAB_box:CircleWaypointRepeatedly.MaxLaps = 32.000000 count 2014-04-21T04:41:53.679Z,1398055313.679 [MissionManager](INFO): DefineArg EcoHAB_box:CircleWaypointRepeatedly.CenterLat = nan arcdeg 2014-04-21T04:41:53.699Z,1398055313.699 [MissionManager](INFO): DefineArg EcoHAB_box:CircleWaypointRepeatedly.CenterLon = nan arcdeg 2014-04-21T04:41:53.703Z,1398055313.703 [MissionManager](INFO): DefineArg EcoHAB_box:CircleWaypointRepeatedly.Radius = 250.000000 m 2014-04-21T04:41:53.706Z,1398055313.706 [MissionManager](INFO): DefineArg EcoHAB_box:CircleWaypointRepeatedly.MaxError = 250.000000 m 2014-04-21T04:41:53.721Z,1398055313.721 [MissionManager](INFO): DefineArg EcoHAB_box:CircleWaypointRepeatedly.TurnToPort = 0 bool 2014-04-21T04:41:53.725Z,1398055313.725 [MissionManager](INFO): DefineArg EcoHAB_box:CircleWaypointRepeatedly.KwpHeading = 0.010000 rad/m 2014-04-21T04:41:53.752Z,1398055313.752 [MissionManager](INFO): DefineArg EcoHAB_box:CircleWaypointRepeatedly.FloatTime = 60.000000 s 2014-04-21T04:41:53.756Z,1398055313.756 [MissionManager](INFO): DefineArg EcoHAB_box:CircleWaypointRepeatedly.Pitch = 20.000000 arcdeg 2014-04-21T04:41:53.769Z,1398055313.769 [MissionManager](INFO): DefineArg EcoHAB_box:CircleWaypointRepeatedly.Speed = 1.000000 m/s 2014-04-21T04:41:53.786Z,1398055313.786 [EcoHAB_box:CircleWaypointRepeatedly:Repeater:Lap:B.Circle](DEBUG): Construct. 2014-04-21T04:41:53.814Z,1398055313.814 [EcoHAB_box:CircleWaypointRepeatedly:Repeater:GTS:A.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-21T04:41:53.896Z,1398055313.896 [EcoHAB_box:Lap:WpESPInshore.Waypoint](DEBUG): Construct Waypoint. 2014-04-21T04:41:53.919Z,1398055313.919 [EcoHAB_box:Lap:WpCorner1.Waypoint](DEBUG): Construct Waypoint. 2014-04-21T04:41:53.934Z,1398055313.934 [EcoHAB_box:Lap:WpCorner2.Waypoint](DEBUG): Construct Waypoint. 2014-04-21T04:41:53.941Z,1398055313.941 [EcoHAB_box:Lap:WpESPOffshore.Waypoint](DEBUG): Construct Waypoint. 2014-04-21T04:41:53.991Z,1398055313.991 [EcoHAB_box:Lap:WpCorner3.Waypoint](DEBUG): Construct Waypoint. 2014-04-21T04:41:54.002Z,1398055314.002 [EcoHAB_box:Lap:WpCorner4.Waypoint](DEBUG): Construct Waypoint. 2014-04-21T04:41:54.016Z,1398055314.016 [EcoHAB_box:Lap:WpESPInshore.Waypoint](DEBUG): Construct Waypoint. 2014-04-21T04:41:54.038Z,1398055314.038 [EcoHAB_box:Approach:B.Pitch](DEBUG): Construct. 2014-04-21T04:41:54.044Z,1398055314.044 [EcoHAB_box:Approach:C.SetSpeed](DEBUG): Construct. 2014-04-21T04:41:54.055Z,1398055314.055 [EcoHAB_box:Approach:WpApproach.Waypoint](DEBUG): Construct Waypoint. 2014-04-21T04:41:54.070Z,1398055314.070 [MissionManager](INFO): Inserting Stack: Missions/Insert/Science.xml 2014-04-21T04:41:54.232Z,1398055314.232 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:Science.SampleISUS = 0 bool 2014-04-21T04:41:54.236Z,1398055314.236 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:Science.SampleISUSmaxPitch = 60.000000 arcdeg 2014-04-21T04:41:54.240Z,1398055314.240 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:Science.SampleISUSminPitch = -60.000000 arcdeg 2014-04-21T04:41:54.243Z,1398055314.243 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:Science.PeakDetectChlActive = 0 bool 2014-04-21T04:41:54.254Z,1398055314.254 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:Science.PeakDetectNO3Active = 0 bool 2014-04-21T04:41:54.258Z,1398055314.258 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:Science.UpwardDerivativeOfTemperatureActive = 0 bool 2014-04-21T04:41:54.261Z,1398055314.261 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:Science.ComputeWaterCurrent = 0 bool 2014-04-21T04:41:54.264Z,1398055314.264 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:Science.ComputeWaterCurrentMinDepth = 2.000000 m 2014-04-21T04:41:54.279Z,1398055314.279 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:Science.ComputeWaterCurrentMaxDepth = 5.000000 m 2014-04-21T04:41:54.283Z,1398055314.283 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:Science.EnabledAanderaaO2 = 0.000000 n/a 2014-04-21T04:41:54.310Z,1398055314.310 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:Science.EnabledNeilBrown = 1.000000 n/a 2014-04-21T04:41:54.314Z,1398055314.314 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:Science.EnabledTurbulence_NPS = 0.000000 n/a 2014-04-21T04:41:54.333Z,1398055314.333 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:Science.EnabledWetLabsBB2FL = 1.000000 n/a 2014-04-21T04:41:54.337Z,1398055314.337 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:Science.EnabledDVL = 1.000000 n/a 2014-04-21T04:41:54.341Z,1398055314.341 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:Science.EnabledISUS = 1.000000 n/a 2014-04-21T04:41:54.360Z,1398055314.360 [MissionManager](INFO): DefineOutput EcoHAB_box:ScienceOps:Science.PeakChl = 0.000000 ug/l 2014-04-21T04:41:54.364Z,1398055314.364 [MissionManager](INFO): DefineOutput EcoHAB_box:ScienceOps:Science.PeakChlDepth = 0.000000 m 2014-04-21T04:41:54.385Z,1398055314.385 [MissionManager](INFO): DefineOutput EcoHAB_box:ScienceOps:Science.PeakChlLatitude = nan arcdeg 2014-04-21T04:41:54.389Z,1398055314.389 [MissionManager](INFO): DefineOutput EcoHAB_box:ScienceOps:Science.PeakChlLongitude = nan arcdeg 2014-04-21T04:41:54.392Z,1398055314.392 [MissionManager](INFO): DefineOutput EcoHAB_box:ScienceOps:Science.PeakNO3 = 0.000000 umol/l 2014-04-21T04:41:54.405Z,1398055314.405 [MissionManager](INFO): DefineOutput EcoHAB_box:ScienceOps:Science.PeakNO3Depth = 0.000000 m 2014-04-21T04:41:54.409Z,1398055314.409 [MissionManager](INFO): DefineOutput EcoHAB_box:ScienceOps:Science.PeakNO3Latitude = nan arcdeg 2014-04-21T04:41:54.412Z,1398055314.412 [MissionManager](INFO): DefineOutput EcoHAB_box:ScienceOps:Science.PeakNO3Longitude = nan arcdeg 2014-04-21T04:41:54.459Z,1398055314.459 [EcoHAB_box:ScienceOps:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2014-04-21T04:41:54.484Z,1398055314.484 [EcoHAB_box:ScienceOps:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2014-04-21T04:41:54.508Z,1398055314.508 [MissionManager](INFO): RedefineArg EcoHAB_box:ScienceOps:Science.PeakDetectChlActive = value:1 bool 2014-04-21T04:41:54.510Z,1398055314.510 [MissionManager](INFO): RedefineArg EcoHAB_box:ScienceOps:Science.SampleISUS = value:1 bool 2014-04-21T04:41:54.512Z,1398055314.512 [MissionManager](INFO): RedefineArg EcoHAB_box:ScienceOps:Science.SampleISUSmaxPitch = value:30.000000 arcdeg 2014-04-21T04:41:54.530Z,1398055314.530 [MissionManager](INFO): RedefineArg EcoHAB_box:ScienceOps:Science.SampleISUSminPitch = value:10.000000 arcdeg 2014-04-21T04:41:54.532Z,1398055314.532 [MissionManager](INFO): RedefineArg EcoHAB_box:ScienceOps:Science.ComputeWaterCurrent = value:0 bool 2014-04-21T04:41:54.534Z,1398055314.534 [MissionManager](INFO): RedefineArg EcoHAB_box:ScienceOps:Science.UpwardDerivativeOfTemperatureActive = value:0 bool 2014-04-21T04:41:54.534Z,1398055314.534 [MissionManager](INFO): Inserting Stack: Missions/Insert/VerticalTemperatureHomogeneityIndex.xml 2014-04-21T04:41:54.723Z,1398055314.723 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:VTHIdx.DepthShallow = 5.000000 m 2014-04-21T04:41:54.727Z,1398055314.727 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:VTHIdx.DepthMidShallow = 10.000000 m 2014-04-21T04:41:54.730Z,1398055314.730 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:VTHIdx.DepthMidDeep = 15.000000 m 2014-04-21T04:41:54.734Z,1398055314.734 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:VTHIdx.DepthDeep = 20.000000 m 2014-04-21T04:41:54.737Z,1398055314.737 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:VTHIdx.Verbosity = 1.000000 count 2014-04-21T04:41:54.780Z,1398055314.780 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:VTHIdx.TemperatureShallow = 0.000000 K 2014-04-21T04:41:54.783Z,1398055314.783 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:VTHIdx.TemperatureMidShallow = 0.000000 K 2014-04-21T04:41:54.796Z,1398055314.796 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:VTHIdx.TemperatureMidDeep = 0.000000 K 2014-04-21T04:41:54.799Z,1398055314.799 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:VTHIdx.TemperatureDeep = 0.000000 K 2014-04-21T04:41:54.803Z,1398055314.803 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:VTHIdx.DTShallow = 0.000000 K 2014-04-21T04:41:54.806Z,1398055314.806 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:VTHIdx.DTMidShallow = 0.000000 K 2014-04-21T04:41:54.825Z,1398055314.825 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:VTHIdx.DTMidDeep = 0.000000 K 2014-04-21T04:41:54.828Z,1398055314.828 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:VTHIdx.DTDeep = 0.000000 K 2014-04-21T04:41:54.870Z,1398055314.870 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:VTHIdx.Zero = 0.000000 count 2014-04-21T04:41:54.883Z,1398055314.883 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:VTHIdx.One = 1.000000 count 2014-04-21T04:41:54.886Z,1398055314.886 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:VTHIdx.Two = 2.000000 count 2014-04-21T04:41:54.890Z,1398055314.890 [MissionManager](INFO): DefineOutput EcoHAB_box:ScienceOps:VTHIdx.TemperatureMean = 0.000000 K 2014-04-21T04:41:54.894Z,1398055314.894 [MissionManager](INFO): DefineOutput EcoHAB_box:ScienceOps:VTHIdx.TemperatureDelta = 0.000000 K 2014-04-21T04:41:54.914Z,1398055314.914 [MissionManager](INFO): DefineOutput EcoHAB_box:ScienceOps:VTHIdx.DetectLatitude = nan arcdeg 2014-04-21T04:41:54.917Z,1398055314.917 [MissionManager](INFO): DefineOutput EcoHAB_box:ScienceOps:VTHIdx.DetectLongitude = nan arcdeg 2014-04-21T04:41:54.921Z,1398055314.921 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures:DetectShallow.ValueDetect](DEBUG): Construct ValueDetect. 2014-04-21T04:41:54.940Z,1398055314.940 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures:DetectMidShallow.ValueDetect](DEBUG): Construct ValueDetect. 2014-04-21T04:41:54.954Z,1398055314.954 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures:DetectMidDeep.ValueDetect](DEBUG): Construct ValueDetect. 2014-04-21T04:41:54.960Z,1398055314.960 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures:DetectDeep.ValueDetect](DEBUG): Construct ValueDetect. 2014-04-21T04:41:55.082Z,1398055315.082 [MissionManager](INFO): RedefineArg EcoHAB_box:ScienceOps:VTHIdx.DepthShallow = value:5.000000 m 2014-04-21T04:41:55.084Z,1398055315.084 [MissionManager](INFO): RedefineArg EcoHAB_box:ScienceOps:VTHIdx.DepthMidShallow = value:10.000000 m 2014-04-21T04:41:55.087Z,1398055315.087 [MissionManager](INFO): RedefineArg EcoHAB_box:ScienceOps:VTHIdx.DepthMidDeep = value:20.000000 m 2014-04-21T04:41:55.101Z,1398055315.101 [MissionManager](INFO): RedefineArg EcoHAB_box:ScienceOps:VTHIdx.DepthDeep = value:25.000000 m 2014-04-21T04:41:55.118Z,1398055315.118 [MissionManager](INFO): RedefineArg EcoHAB_box:ScienceOps:VTHIdx.Verbosity = value:1.000000 count 2014-04-21T04:41:55.132Z,1398055315.132 [EcoHAB_box:ScienceOps:D.SetSpeed](DEBUG): Construct. 2014-04-21T04:41:55.141Z,1398055315.141 [EcoHAB_box:ScienceOps:E.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2014-04-21T04:41:55.171Z,1398055315.171 [EcoHAB_box:ScienceOps:F.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope. 2014-04-21T04:41:55.187Z,1398055315.187 [EcoHAB_box:ScienceOps:G.YoYo](DEBUG): Construct YoYo. 2014-04-21T04:41:55.288Z,1398055315.288 [MissionManager](DEBUG): This mission runs yoyos counterclockwise around a box. Two sides of the box pass through the planned locations for both Environmental Sample Processor (ESP) buoys during the Spring 2014 EcoHAB deployment. High-level NeedComms directive intended to assist debugging in the field. Elapsed time after previous surface fix when vehicle will begin to ascend for additional surface fix, 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. The timing operates based on Universal:time_fix to avoid repeated attempts after the Iridium timeout. 36 Minimum altitude for the entire mission. 4 Maximum depth for the entire mission. 85 Minimum offshore distance for the entire mission. 2000 Vehicle speed. 1 Maximum duration of mission 9 Static setting for mass during the mission. Defaults to massDefault setting in the Config/Control.cfg file. Buoyancy bladder position while performing the YoYo behavior. Defaults to buoyancyNeutral setting in the Config/Control.cfg file. Latitude of inshore ESP buoy. 33.607614 Longitude of offshore ESP buoy. -118.018798 Latitude of offshore ESP buoy. 33.585471 Longitude of offshore ESP buoy. -118.037372 Latitude of waypoint for first corner of box. 33.586554427309956 Longitude of waypoint for first corner of box. -117.97990263671926 Latitude of waypoint for second corner of box. 33.563841488839024 Longitude of waypoint for second corner of box. -117.99744852771295 Latitude of waypoint for third corner of box. 33.60651834669941 Longitude of waypoint for third corner of box. -118.076275825578 Latitude of waypoint for fourth corner of box. 33.628662266112016 Longitude of waypoint for fourth corner of box. -118.05771227683994 Depth for initial approach to WpCorner1. 10.0 Maximum duration of initial approach 4 Elapsed time after previous surface communications when vehicle will begin to ascend for additional surface communications. Only active during the approach. 20 Number of times to repeat the science loop 13 Radius of circle around Inshore ESP during wait time 500 Maximum number of times to circle the wayopint at the start of each lap. 13 UTC time between reporting events. (e.g., "set CircleDivisor 8 hour" for reports at 0000, 0800, 1600 UTC) 2 Current time modulo CircleDivisor (internal variable). NaN Timeout for circling buoy at start of each lap (internal variable). 3 Maximum duration of lap around box. 8 Request data from the SCPI for this long. 420 Minimum depth during yo-yo's. 4.0 Maximum depth during yo-yo's. 78.0 Min altitude while in yo-yo mode. 6.0 Pitch when yo-yo's are ascending. 20.0 Pitch when yo-yo's are descending. -20.0 Calculate (current time) mod (CircleDivisor) and determine when to stop circling the start-of-lap waypoint. CircleModulus calculated as: CircleTimeout updated to: Circle a waypoint at the nominal location of the Inshore ESP buoy until timeout specified by CircleDivisor and current time. Convenience aggregate to notify operator of estimated circling time _before_ starting to circle the waypoint. May be commented out, since the Timeout in CircleWaypointRepeatedly will still achieve the desired behavior. CircleInshoreESPBuoy should complete in , due to timeout in CircleWaypointRepeatedly aggregate. **** Finished circling. **** Run around the box. 2.0 **** Finished circling. **** Get to start point. Check in periodically, but do not split logs Circle then lap many times, collecting science data. Get science data, including PeakDetectChl 30.0 10.0 5 10 20 25 1 Turn on the SCPI camera. (SCPI.sampleTime is set in Sensor.cfg) 40 2014-04-21T04:41:55.289Z,1398055315.289 [CommandLine](IMPORTANT): Loaded ./Missions/Science/EcoHAB_box.xml 2014-04-21T04:41:58.229Z,1398055318.229 [CommandLine](IMPORTANT): got command set EcoHAB_box.NeedCommsTime 30.000000 minute 2014-04-21T04:41:58.229Z,1398055318.229 [CommandLine](IMPORTANT): got command set EcoHAB_box.MissionTimeout 48.000000 hour 2014-04-21T04:41:58.230Z,1398055318.230 [CommandLine](IMPORTANT): got command set EcoHAB_box.LapTimeout 12.000000 hour 2014-04-21T04:41:58.231Z,1398055318.231 [CommandLine](IMPORTANT): got command run 2014-04-21T04:41:58.235Z,1398055318.235 [CommandLine](IMPORTANT): Running 2014-04-21T04:41:58.253Z,1398055318.253 [Default] Stopped 2014-04-21T04:41:58.254Z,1398055318.254 [Default](INFO): Aggregate::uninitialize Default 2014-04-21T04:41:58.254Z,1398055318.254 [Default:GPS] Stopped 2014-04-21T04:41:58.254Z,1398055318.254 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2014-04-21T04:41:58.254Z,1398055318.254 [Default:GPS:A.SetSpeed] Stopped 2014-04-21T04:41:58.254Z,1398055318.254 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2014-04-21T04:41:58.254Z,1398055318.254 [Default:GPS:Read_GPS] Stopped 2014-04-21T04:41:58.254Z,1398055318.254 [Default:Iridium] Stopped 2014-04-21T04:41:58.254Z,1398055318.254 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2014-04-21T04:41:58.254Z,1398055318.254 [Default:Iridium:A.SetSpeed] Stopped 2014-04-21T04:41:58.254Z,1398055318.254 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2014-04-21T04:41:58.254Z,1398055318.254 [Default:Iridium:Read_Iridium] Stopped 2014-04-21T04:41:58.254Z,1398055318.254 [Default:CallIridium] Stopped 2014-04-21T04:41:58.255Z,1398055318.255 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2014-04-21T04:41:58.255Z,1398055318.255 [Default:CallIridium:B] Stopped 2014-04-21T04:41:58.255Z,1398055318.255 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2014-04-21T04:41:58.255Z,1398055318.255 [Default:WaitAtTheSurface] Stopped 2014-04-21T04:41:58.255Z,1398055318.255 [Default:WaitAtTheSurface](INFO): Aggregate::uninitialize Default:WaitAtTheSurface 2014-04-21T04:41:58.255Z,1398055318.255 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Stopped 2014-04-21T04:41:58.255Z,1398055318.255 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Uninitialize. 2014-04-21T04:41:58.255Z,1398055318.255 [Default:WaitAtTheSurface:B.GoToSurface] Stopped 2014-04-21T04:41:58.255Z,1398055318.255 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-21T04:41:58.255Z,1398055318.255 [MissionManager](IMPORTANT): Started mission EcoHAB_box 2014-04-21T04:41:58.256Z,1398055318.256 [EcoHAB_box] Running Loop=1 2014-04-21T04:41:58.256Z,1398055318.256 [EcoHAB_box](INFO): Aggregate::initialize EcoHAB_box 2014-04-21T04:41:58.256Z,1398055318.256 [EcoHAB_box:A.AltitudeEnvelope] Running Loop=1 2014-04-21T04:41:58.256Z,1398055318.256 [EcoHAB_box:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent. 2014-04-21T04:41:58.256Z,1398055318.256 [EcoHAB_box:B.DepthEnvelope] Running Loop=1 2014-04-21T04:41:58.256Z,1398055318.256 [EcoHAB_box:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent. 2014-04-21T04:41:58.257Z,1398055318.257 [EcoHAB_box:C.OffshoreEnvelope] Running Loop=1 2014-04-21T04:41:58.257Z,1398055318.257 [EcoHAB_box:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent. 2014-04-21T04:41:58.257Z,1398055318.257 [EcoHAB_box:L.Pitch] Running Loop=1 2014-04-21T04:41:58.257Z,1398055318.257 [EcoHAB_box:L.Pitch](DEBUG): Initialize. 2014-04-21T04:41:58.257Z,1398055318.257 [EcoHAB_box:M.Buoyancy] Running Loop=1 2014-04-21T04:41:58.257Z,1398055318.257 [EcoHAB_box:M.Buoyancy](DEBUG): Initialize Buoyancy Component. 2014-04-21T04:41:58.258Z,1398055318.258 [EcoHAB_box:E] Running Loop=1 2014-04-21T04:41:58.259Z,1398055318.259 [EcoHAB_box:M.Buoyancy] Running Loop=1 2014-04-21T04:41:58.264Z,1398055318.264 [EcoHAB_box:L.Pitch] Running Loop=1 2014-04-21T04:41:58.308Z,1398055318.308 [EcoHAB_box:E] Stopped 2014-04-21T04:41:58.308Z,1398055318.308 [EcoHAB_box:F] Running Loop=1 2014-04-21T04:41:58.308Z,1398055318.308 [EcoHAB_box:C.OffshoreEnvelope] Running Loop=1 2014-04-21T04:41:58.314Z,1398055318.314 [EcoHAB_box:B.DepthEnvelope] Running Loop=1 2014-04-21T04:41:58.328Z,1398055318.328 [EcoHAB_box:A.AltitudeEnvelope] Running Loop=1 2014-04-21T04:41:59.041Z,1398055319.041 [EcoHAB_box:F] Stopped 2014-04-21T04:41:59.041Z,1398055319.041 [EcoHAB_box:SurfaceComms] Running Loop=1 2014-04-21T04:41:59.057Z,1398055319.057 [EcoHAB_box:SurfaceComms](INFO): Aggregate::initialize EcoHAB_box:SurfaceComms 2014-04-21T04:41:59.057Z,1398055319.057 [EcoHAB_box:SurfaceComms:A.GoToSurface] Running Loop=1 2014-04-21T04:41:59.057Z,1398055319.057 [EcoHAB_box:SurfaceComms:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-21T04:41:59.483Z,1398055319.483 [EcoHAB_box:SurfaceComms:B] Running Loop=1 2014-04-21T04:41:59.483Z,1398055319.483 [EcoHAB_box:SurfaceComms:B](INFO): Aggregate::initialize EcoHAB_box:SurfaceComms:B 2014-04-21T04:41:59.483Z,1398055319.483 [EcoHAB_box:SurfaceComms:B:A] Running Loop=1 2014-04-21T04:41:59.899Z,1398055319.899 [EcoHAB_box:SurfaceComms:B] Stopped 2014-04-21T04:41:59.899Z,1398055319.899 [EcoHAB_box:SurfaceComms:B](INFO): Aggregate::uninitialize EcoHAB_box:SurfaceComms:B 2014-04-21T04:41:59.899Z,1398055319.899 [EcoHAB_box:SurfaceComms:B:A] Stopped 2014-04-21T04:41:59.899Z,1398055319.899 [EcoHAB_box:SurfaceComms:C] Running Loop=1 2014-04-21T04:41:59.899Z,1398055319.899 [EcoHAB_box:SurfaceComms:C](INFO): Aggregate::initialize EcoHAB_box:SurfaceComms:C 2014-04-21T04:41:59.899Z,1398055319.899 [EcoHAB_box:SurfaceComms:C:A] Running Loop=1 2014-04-21T04:42:00.384Z,1398055320.384 [EcoHAB_box:M.Buoyancy] Preempted 2014-04-21T04:42:00.384Z,1398055320.384 [EcoHAB_box:L.Pitch] Preempted 2014-04-21T04:42:00.385Z,1398055320.385 [EcoHAB_box:SurfaceComms:C:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2014-04-21T04:42:19.970Z,1398055339.970 [NAL9602](IMPORTANT): GPS fix at: 1398055320.00 2014-04-21T04:42:19.988Z,1398055339.988 [EcoHAB_box:SurfaceComms:C:A] Stopped 2014-04-21T04:42:19.989Z,1398055339.989 [EcoHAB_box:SurfaceComms:C:B] Running Loop=1 2014-04-21T04:42:20.424Z,1398055340.424 [EcoHAB_box:SurfaceComms:C:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2014-04-21T04:42:57.119Z,1398055377.119 [NAL9602](INFO): SBD MO Status=2, MOMSN=27935, MT Status=2, MTMSN=0 2014-04-21T04:42:57.119Z,1398055377.119 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2014-04-21T04:43:30.838Z,1398055410.838 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 40 of 46 2014-04-21T04:43:30.839Z,1398055410.839 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 28.2 31.1 31.1 28.0 -80.6 -18.0 54.0 -51.2 4 76 72 5 6 7 7 6 -179.6 44.3 -25.8 1 -30.6 -175.0 -57.6 1 -90 94 42 2 -90 -95 42 2 -7.56 1489 76 2014-04-21T04:43:33.898Z,1398055413.898 [NAL9602](INFO): SBD MO Status=2, MOMSN=27935, MT Status=2, MTMSN=0 2014-04-21T04:43:33.898Z,1398055413.898 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2014-04-21T04:44:03.093Z,1398055443.093 [NAL9602](INFO): SBD MO Status=2, MOMSN=27935, MT Status=2, MTMSN=0 2014-04-21T04:44:03.094Z,1398055443.094 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2014-04-21T04:44:25.403Z,1398055465.403 [NAL9602](INFO): SBD MO Status=1, MOMSN=27935, MT Status=0, MTMSN=0 2014-04-21T04:44:25.464Z,1398055465.464 [NAL9602](INFO): Sent 78 bytes from file Logs/20140421T043220/Courier0012.lzma 2014-04-21T04:44:25.465Z,1398055465.465 [NAL9602](INFO): Packets left to send: 0 2014-04-21T04:44:25.466Z,1398055465.466 [NAL9602](INFO): Stored copy of sent data in Logs/20140421T043220/Courier0012.lzma.parts/0000.sbd 2014-04-21T04:44:25.466Z,1398055465.466 [NAL9602](INFO): Completed sending Logs/20140421T043220/Courier0012.lzma 2014-04-21T04:44:35.207Z,1398055475.207 [NAL9602](INFO): SBD MO Status=1, MOMSN=27936, MT Status=0, MTMSN=0 2014-04-21T04:44:35.256Z,1398055475.256 [NAL9602](INFO): Sent 105 bytes from file Logs/20140421T043220/Express0009.lzma 2014-04-21T04:44:35.256Z,1398055475.256 [NAL9602](INFO): Packets left to send: 0 2014-04-21T04:44:35.257Z,1398055475.257 [NAL9602](INFO): Stored copy of sent data in Logs/20140421T043220/Express0009.lzma.parts/0000.sbd 2014-04-21T04:44:35.258Z,1398055475.258 [NAL9602](INFO): Completed sending Logs/20140421T043220/Express0009.lzma 2014-04-21T04:44:47.523Z,1398055487.523 [NAL9602](INFO): SBD MO Status=1, MOMSN=27937, MT Status=0, MTMSN=0 2014-04-21T04:44:47.583Z,1398055487.583 [NAL9602](INFO): Sent 332 bytes from file Logs/20140421T043220/Express0013.lzma 2014-04-21T04:44:47.583Z,1398055487.583 [NAL9602](INFO): Packets left to send: 1 2014-04-21T04:44:47.584Z,1398055487.584 [NAL9602](INFO): Stored copy of sent data in Logs/20140421T043220/Express0013.lzma.parts/0001.sbd 2014-04-21T04:44:56.633Z,1398055496.633 [NAL9602](INFO): SBD MO Status=1, MOMSN=27938, MT Status=0, MTMSN=0 2014-04-21T04:44:56.685Z,1398055496.685 [NAL9602](INFO): Sent 13 bytes from file Logs/20140421T043220/Express0013.lzma 2014-04-21T04:44:56.685Z,1398055496.685 [NAL9602](INFO): Packets left to send: 0 2014-04-21T04:44:56.686Z,1398055496.686 [NAL9602](INFO): Stored copy of sent data in Logs/20140421T043220/Express0013.lzma.parts/0000.sbd 2014-04-21T04:44:56.686Z,1398055496.686 [NAL9602](INFO): Completed sending Logs/20140421T043220/Express0013.lzma 2014-04-21T04:45:05.657Z,1398055505.657 [NAL9602](INFO): SBD MO Status=0, MOMSN=27939, MT Status=0, MTMSN=0 2014-04-21T04:45:28.029Z,1398055528.029 [NAL9602](INFO): SBD MO Status=1, MOMSN=27940, MT Status=0, MTMSN=0 2014-04-21T04:45:28.081Z,1398055528.081 [NAL9602](INFO): Sent 45 bytes from file Logs/20140421T043220/Courier0016.lzma 2014-04-21T04:45:28.082Z,1398055528.082 [NAL9602](INFO): Packets left to send: 0 2014-04-21T04:45:28.083Z,1398055528.083 [NAL9602](INFO): Stored copy of sent data in Logs/20140421T043220/Courier0016.lzma.parts/0000.sbd 2014-04-21T04:45:28.084Z,1398055528.084 [NAL9602](INFO): Completed sending Logs/20140421T043220/Courier0016.lzma 2014-04-21T04:46:12.182Z,1398055572.182 [NAL9602](INFO): SBD MO Status=2, MOMSN=27941, MT Status=2, MTMSN=0 2014-04-21T04:46:12.182Z,1398055572.182 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2014-04-21T04:46:35.764Z,1398055595.764 [NAL9602](INFO): SBD MO Status=1, MOMSN=27941, MT Status=0, MTMSN=0 2014-04-21T04:46:35.814Z,1398055595.814 [NAL9602](INFO): Sent 199 bytes from file Logs/20140421T043220/Express0017.lzma 2014-04-21T04:46:35.815Z,1398055595.815 [NAL9602](INFO): Packets left to send: 0 2014-04-21T04:46:35.816Z,1398055595.816 [NAL9602](INFO): Stored copy of sent data in Logs/20140421T043220/Express0017.lzma.parts/0000.sbd 2014-04-21T04:46:35.817Z,1398055595.817 [NAL9602](INFO): Completed sending Logs/20140421T043220/Express0017.lzma 2014-04-21T04:46:46.193Z,1398055606.193 [NAL9602](INFO): SBD MO Status=0, MOMSN=27942, MT Status=0, MTMSN=0 2014-04-21T04:46:46.288Z,1398055606.288 [EcoHAB_box:SurfaceComms:C:B] Stopped 2014-04-21T04:46:46.288Z,1398055606.288 [EcoHAB_box:SurfaceComms:C:C] Running Loop=1 2014-04-21T04:46:46.688Z,1398055606.688 [EcoHAB_box:SurfaceComms:C:C](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2014-04-21T04:46:48.799Z,1398055608.799 [NAL9602](IMPORTANT): GPS fix at: 1398055589.00 2014-04-21T04:46:48.845Z,1398055608.845 [EcoHAB_box:SurfaceComms:C:C] Stopped 2014-04-21T04:46:48.845Z,1398055608.845 [EcoHAB_box:SurfaceComms:C](INFO): Completed EcoHAB_box:SurfaceComms:C 2014-04-21T04:46:48.845Z,1398055608.845 [EcoHAB_box:SurfaceComms:C] Stopped 2014-04-21T04:46:48.845Z,1398055608.845 [EcoHAB_box:SurfaceComms:C](INFO): Aggregate::uninitialize EcoHAB_box:SurfaceComms:C 2014-04-21T04:46:48.851Z,1398055608.851 [EcoHAB_box:SurfaceComms](INFO): Completed EcoHAB_box:SurfaceComms 2014-04-21T04:46:48.851Z,1398055608.851 [EcoHAB_box:SurfaceComms] Stopped 2014-04-21T04:46:48.851Z,1398055608.851 [EcoHAB_box:SurfaceComms](INFO): Aggregate::uninitialize EcoHAB_box:SurfaceComms 2014-04-21T04:46:48.851Z,1398055608.851 [EcoHAB_box:SurfaceComms:A.GoToSurface] Stopped 2014-04-21T04:46:48.851Z,1398055608.851 [EcoHAB_box:SurfaceComms:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-21T04:46:48.851Z,1398055608.851 [EcoHAB_box:SurfaceGPS] Running Loop=1 2014-04-21T04:46:48.851Z,1398055608.851 [EcoHAB_box:SurfaceGPS](INFO): Aggregate::initialize EcoHAB_box:SurfaceGPS 2014-04-21T04:46:48.851Z,1398055608.851 [EcoHAB_box:SurfaceGPS:A.GoToSurface] Running Loop=1 2014-04-21T04:46:48.852Z,1398055608.852 [EcoHAB_box:SurfaceGPS:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-21T04:46:49.300Z,1398055609.300 [EcoHAB_box:M.Buoyancy] Running Loop=1 2014-04-21T04:46:49.301Z,1398055609.301 [EcoHAB_box:L.Pitch] Running Loop=1 2014-04-21T04:46:49.307Z,1398055609.307 [EcoHAB_box:SurfaceGPS:GetFix] Running Loop=1 2014-04-21T04:46:49.307Z,1398055609.307 [EcoHAB_box:SurfaceGPS:GetFix](INFO): Aggregate::initialize EcoHAB_box:SurfaceGPS:GetFix 2014-04-21T04:46:49.308Z,1398055609.308 [EcoHAB_box:SurfaceGPS:GetFix:A] Running Loop=1 2014-04-21T04:46:49.761Z,1398055609.761 [EcoHAB_box:SurfaceGPS:GetFix:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2014-04-21T04:46:51.953Z,1398055611.953 [NAL9602](IMPORTANT): GPS fix at: 1398055592.00 2014-04-21T04:46:51.973Z,1398055611.973 [EcoHAB_box:SurfaceGPS:GetFix:A] Stopped 2014-04-21T04:46:51.973Z,1398055611.973 [EcoHAB_box:SurfaceGPS:GetFix](INFO): Completed EcoHAB_box:SurfaceGPS:GetFix 2014-04-21T04:46:51.973Z,1398055611.973 [EcoHAB_box:SurfaceGPS:GetFix] Stopped 2014-04-21T04:46:51.973Z,1398055611.973 [EcoHAB_box:SurfaceGPS:GetFix](INFO): Aggregate::uninitialize EcoHAB_box:SurfaceGPS:GetFix 2014-04-21T04:46:51.973Z,1398055611.973 [EcoHAB_box:SurfaceGPS:GetFix](INFO): Running loop #2 2014-04-21T04:46:51.973Z,1398055611.973 [EcoHAB_box:SurfaceGPS:GetFix] Running Loop=2 2014-04-21T04:46:51.973Z,1398055611.973 [EcoHAB_box:SurfaceGPS:GetFix](INFO): Aggregate::initialize EcoHAB_box:SurfaceGPS:GetFix 2014-04-21T04:46:51.974Z,1398055611.974 [EcoHAB_box:SurfaceGPS:GetFix:A] Running Loop=1 2014-04-21T04:46:55.034Z,1398055615.034 [NAL9602](IMPORTANT): GPS fix at: 1398055595.00 2014-04-21T04:46:55.053Z,1398055615.053 [EcoHAB_box:SurfaceGPS:GetFix:A] Stopped 2014-04-21T04:46:55.054Z,1398055615.054 [EcoHAB_box:SurfaceGPS:GetFix](INFO): Completed EcoHAB_box:SurfaceGPS:GetFix 2014-04-21T04:46:55.054Z,1398055615.054 [EcoHAB_box:SurfaceGPS:GetFix] Stopped 2014-04-21T04:46:55.054Z,1398055615.054 [EcoHAB_box:SurfaceGPS:GetFix](INFO): Aggregate::uninitialize EcoHAB_box:SurfaceGPS:GetFix 2014-04-21T04:46:55.055Z,1398055615.055 [EcoHAB_box:SurfaceGPS](INFO): Completed EcoHAB_box:SurfaceGPS 2014-04-21T04:46:55.055Z,1398055615.055 [EcoHAB_box:SurfaceGPS] Stopped 2014-04-21T04:46:55.055Z,1398055615.055 [EcoHAB_box:SurfaceGPS](INFO): Aggregate::uninitialize EcoHAB_box:SurfaceGPS 2014-04-21T04:46:55.055Z,1398055615.055 [EcoHAB_box:SurfaceGPS:A.GoToSurface] Stopped 2014-04-21T04:46:55.055Z,1398055615.055 [EcoHAB_box:SurfaceGPS:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-21T04:46:55.055Z,1398055615.055 [EcoHAB_box:Approach] Running Loop=1 2014-04-21T04:46:55.055Z,1398055615.055 [EcoHAB_box:Approach](INFO): Aggregate::initialize EcoHAB_box:Approach 2014-04-21T04:46:55.056Z,1398055615.056 [EcoHAB_box:Approach:B.Pitch] Running Loop=1 2014-04-21T04:46:55.056Z,1398055615.056 [EcoHAB_box:Approach:B.Pitch](DEBUG): Initialize. 2014-04-21T04:46:55.088Z,1398055615.088 [EcoHAB_box:Approach:C.SetSpeed] Running Loop=1 2014-04-21T04:46:55.088Z,1398055615.088 [EcoHAB_box:Approach:C.SetSpeed](DEBUG): Initialize. 2014-04-21T04:46:55.088Z,1398055615.088 [EcoHAB_box:Approach:WpApproach.Waypoint] Running Loop=1 2014-04-21T04:46:55.088Z,1398055615.088 [EcoHAB_box:Approach:WpApproach.Waypoint](DEBUG): Initialize WaypointComponent. 2014-04-21T04:46:55.646Z,1398055615.646 [EcoHAB_box:Approach:C.SetSpeed] Running Loop=1 2014-04-21T04:46:55.651Z,1398055615.651 [EcoHAB_box:Approach:B.Pitch] Running Loop=1 2014-04-21T04:47:02.126Z,1398055622.126 [NAL9602](INFO): Powering down 2014-04-21T04:47:08.417Z,1398055628.417 [Radio_Freewave](INFO): Powering down 2014-04-21T04:47:27.304Z,1398055647.304 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 44 of 46 2014-04-21T04:47:27.304Z,1398055647.304 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 25.9 27.7 25.8 23.8 -185.8 50.2 248.8 -0.2 -00 -21 5 6 5 4 -580.0 67.3 30.5 1 -453.2 368.5 26.6 1 -572 48 -9 43 -9 2 -12.04 1.07 328.1 23.8 16.0 0.005 35.0 1489 113 2014-04-21T04:47:52.044Z,1398055672.044 [Radio_Freewave](INFO): Powering up 2014-04-21T04:47:53.363Z,1398055673.363 [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-21T04:48:00.137Z,1398055680.137 [Radio_Freewave](INFO): Powering down 2014-04-21T04:48:20.541Z,1398055700.541 [Radio_Freewave](INFO): Powering up 2014-04-21T04:48:21.832Z,1398055701.832 [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-21T04:48:27.808Z,1398055707.808 [Radio_Freewave](INFO): Powering down 2014-04-21T04:48:34.111Z,1398055714.111 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#7 STATUS: 65535 2014-04-21T04:48:38.681Z,1398055718.681 [Radio_Freewave](INFO): Powering up 2014-04-21T04:48:39.793Z,1398055719.793 [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-21T04:49:10.379Z,1398055750.379 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:104 Calculated:107 2014-04-21T04:49:10.379Z,1398055750.379 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 30.6 30.9 28.3 28.2 -481.3 -92.8 202.2 -130.20 241 -213 7 7 6 6 -912.2 50.3 -135.5 1 -88.3 917.5 -58.7 1 -955 257 -125 2 127 981 -125 2 -8.77 5.18 277.7 28.2 16.0 0.005 35.0 1489 104 2014-04-21T04:49:16.440Z,1398055756.440 [Radio_Freewave](INFO): Powering down 2014-04-21T04:49:22.794Z,1398055762.794 [Radio_Freewave](INFO): Powering up 2014-04-21T04:49:24.084Z,1398055764.084 [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-21T04:49:46.956Z,1398055786.956 [Radio_Freewave](INFO): Powering down 2014-04-21T04:49:50.929Z,1398055790.929 [Radio_Freewave](INFO): Powering up 2014-04-21T04:49:52.183Z,1398055792.183 [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-21T04:50:08.027Z,1398055808.027 [Radio_Freewave](INFO): Powering down 2014-04-21T04:50:16.128Z,1398055816.128 [Radio_Freewave](INFO): Powering up 2014-04-21T04:50:17.224Z,1398055817.224 [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-21T04:50:58.339Z,1398055858.339 [EcoHAB_box:Approach:WpApproach.Waypoint](INFO): Reached Waypoint: 33.607614,-118.018798 2014-04-21T04:50:58.340Z,1398055858.340 [EcoHAB_box:Approach:WpApproach.Waypoint] Stopped 2014-04-21T04:50:58.340Z,1398055858.340 [EcoHAB_box:Approach:WpApproach.Waypoint](DEBUG): Uninitialize WaypointComponent. 2014-04-21T04:50:58.340Z,1398055858.340 [EcoHAB_box:Approach:E] Running Loop=1 2014-04-21T04:50:58.340Z,1398055858.340 [EcoHAB_box:Approach:E](INFO): Aggregate::initialize EcoHAB_box:Approach:E 2014-04-21T04:50:58.826Z,1398055858.826 [EcoHAB_box:SurfaceComms] Running Loop=1 2014-04-21T04:50:58.826Z,1398055858.826 [EcoHAB_box:SurfaceComms](INFO): Aggregate::initialize EcoHAB_box:SurfaceComms 2014-04-21T04:50:58.827Z,1398055858.827 [EcoHAB_box:SurfaceComms:A.GoToSurface] Running Loop=1 2014-04-21T04:50:58.827Z,1398055858.827 [EcoHAB_box:SurfaceComms:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-21T04:50:58.828Z,1398055858.828 [EcoHAB_box:SurfaceComms:B] Running Loop=1 2014-04-21T04:50:58.828Z,1398055858.828 [EcoHAB_box:SurfaceComms:B](INFO): Aggregate::initialize EcoHAB_box:SurfaceComms:B 2014-04-21T04:50:58.828Z,1398055858.828 [EcoHAB_box:SurfaceComms:B:A] Running Loop=1 2014-04-21T04:50:59.298Z,1398055859.298 [EcoHAB_box:SurfaceComms:B] Stopped 2014-04-21T04:50:59.298Z,1398055859.298 [EcoHAB_box:SurfaceComms:B](INFO): Aggregate::uninitialize EcoHAB_box:SurfaceComms:B 2014-04-21T04:50:59.298Z,1398055859.298 [EcoHAB_box:SurfaceComms:B:A] Stopped 2014-04-21T04:50:59.298Z,1398055859.298 [EcoHAB_box:SurfaceComms:C] Running Loop=1 2014-04-21T04:50:59.298Z,1398055859.298 [EcoHAB_box:SurfaceComms:C](INFO): Aggregate::initialize EcoHAB_box:SurfaceComms:C 2014-04-21T04:50:59.298Z,1398055859.298 [EcoHAB_box:SurfaceComms:C:A] Running Loop=1 2014-04-21T04:50:59.998Z,1398055859.998 [EcoHAB_box:M.Buoyancy] Preempted 2014-04-21T04:50:59.998Z,1398055859.998 [EcoHAB_box:L.Pitch] Preempted 2014-04-21T04:51:00.448Z,1398055860.448 [NAL9602](INFO): Powering up 2014-04-21T04:51:00.949Z,1398055860.949 [Radio_Freewave](INFO): Powering down 2014-04-21T04:51:11.338Z,1398055871.338 [NAL9602](INFO): NAL9602 initialized 2014-04-21T04:51:14.747Z,1398055874.747 [Radio_Freewave](INFO): Powering up 2014-04-21T04:51:16.095Z,1398055876.095 [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-21T04:51:24.249Z,1398055884.249 [NAL9602](INFO): SBD MO Status=0, MOMSN=27943, MT Status=0, MTMSN=0 2014-04-21T04:51:24.250Z,1398055884.250 [NAL9602](INFO): No messages in MT queue 2014-04-21T04:51:31.717Z,1398055891.717 [Radio_Freewave](INFO): Powering down 2014-04-21T04:51:55.746Z,1398055915.746 [Radio_Freewave](INFO): Powering up 2014-04-21T04:51:57.064Z,1398055917.064 [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-21T04:52:53.852Z,1398055973.852 [NAL9602](IMPORTANT): GPS fix at: 1398055954.00 2014-04-21T04:52:53.891Z,1398055973.891 [EcoHAB_box:SurfaceComms:C:A] Stopped 2014-04-21T04:52:53.891Z,1398055973.891 [EcoHAB_box:SurfaceComms:C:B] Running Loop=1 2014-04-21T04:53:14.431Z,1398055994.431 [NAL9602](INFO): SBD MO Status=1, MOMSN=27944, MT Status=0, MTMSN=0 2014-04-21T04:53:14.481Z,1398055994.481 [NAL9602](INFO): Sent 75 bytes from file Logs/20140421T043220/Courier0020.lzma 2014-04-21T04:53:14.481Z,1398055994.481 [NAL9602](INFO): Packets left to send: 0 2014-04-21T04:53:14.482Z,1398055994.482 [NAL9602](INFO): Stored copy of sent data in Logs/20140421T043220/Courier0020.lzma.parts/0000.sbd 2014-04-21T04:53:14.483Z,1398055994.483 [NAL9602](INFO): Completed sending Logs/20140421T043220/Courier0020.lzma 2014-04-21T04:53:24.657Z,1398056004.657 [NAL9602](INFO): SBD MO Status=1, MOMSN=27945, MT Status=0, MTMSN=0 2014-04-21T04:53:24.705Z,1398056004.705 [NAL9602](INFO): Sent 332 bytes from file Logs/20140421T043220/Express0021.lzma 2014-04-21T04:53:24.705Z,1398056004.705 [NAL9602](INFO): Packets left to send: 1 2014-04-21T04:53:24.714Z,1398056004.714 [NAL9602](INFO): Stored copy of sent data in Logs/20140421T043220/Express0021.lzma.parts/0001.sbd 2014-04-21T04:53:35.785Z,1398056015.785 [NAL9602](INFO): SBD MO Status=1, MOMSN=27946, MT Status=0, MTMSN=0 2014-04-21T04:53:35.842Z,1398056015.842 [NAL9602](INFO): Sent 37 bytes from file Logs/20140421T043220/Express0021.lzma 2014-04-21T04:53:35.842Z,1398056015.842 [NAL9602](INFO): Packets left to send: 0 2014-04-21T04:53:35.843Z,1398056015.843 [NAL9602](INFO): Stored copy of sent data in Logs/20140421T043220/Express0021.lzma.parts/0000.sbd 2014-04-21T04:53:35.843Z,1398056015.843 [NAL9602](INFO): Completed sending Logs/20140421T043220/Express0021.lzma 2014-04-21T04:53:47.163Z,1398056027.163 [NAL9602](INFO): SBD MO Status=0, MOMSN=27947, MT Status=0, MTMSN=0 2014-04-21T04:53:47.244Z,1398056027.244 [EcoHAB_box:SurfaceComms:C:B] Stopped 2014-04-21T04:53:47.244Z,1398056027.244 [EcoHAB_box:SurfaceComms:C:C] Running Loop=1 2014-04-21T04:53:49.881Z,1398056029.881 [NAL9602](IMPORTANT): GPS fix at: 1398056010.00 2014-04-21T04:53:49.923Z,1398056029.923 [EcoHAB_box:SurfaceComms:C:C] Stopped 2014-04-21T04:53:49.924Z,1398056029.924 [EcoHAB_box:SurfaceComms:C](INFO): Completed EcoHAB_box:SurfaceComms:C 2014-04-21T04:53:49.924Z,1398056029.924 [EcoHAB_box:SurfaceComms:C] Stopped 2014-04-21T04:53:49.924Z,1398056029.924 [EcoHAB_box:SurfaceComms:C](INFO): Aggregate::uninitialize EcoHAB_box:SurfaceComms:C 2014-04-21T04:53:49.925Z,1398056029.925 [EcoHAB_box:SurfaceComms](INFO): Completed EcoHAB_box:SurfaceComms 2014-04-21T04:53:49.925Z,1398056029.925 [EcoHAB_box:SurfaceComms] Stopped 2014-04-21T04:53:49.925Z,1398056029.925 [EcoHAB_box:SurfaceComms](INFO): Aggregate::uninitialize EcoHAB_box:SurfaceComms 2014-04-21T04:53:49.925Z,1398056029.925 [EcoHAB_box:SurfaceComms:A.GoToSurface] Stopped 2014-04-21T04:53:49.925Z,1398056029.925 [EcoHAB_box:SurfaceComms:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-21T04:53:50.345Z,1398056030.345 [EcoHAB_box:Approach:E](INFO): Completed EcoHAB_box:Approach:E 2014-04-21T04:53:50.345Z,1398056030.345 [EcoHAB_box:Approach:E] Stopped 2014-04-21T04:53:50.345Z,1398056030.345 [EcoHAB_box:Approach:E](INFO): Aggregate::uninitialize EcoHAB_box:Approach:E 2014-04-21T04:53:50.346Z,1398056030.346 [EcoHAB_box:Approach](INFO): Completed EcoHAB_box:Approach 2014-04-21T04:53:50.346Z,1398056030.346 [EcoHAB_box:Approach] Stopped 2014-04-21T04:53:50.346Z,1398056030.346 [EcoHAB_box:Approach](INFO): Aggregate::uninitialize EcoHAB_box:Approach 2014-04-21T04:53:50.347Z,1398056030.347 [EcoHAB_box:Approach:B.Pitch] Stopped 2014-04-21T04:53:50.347Z,1398056030.347 [EcoHAB_box:Approach:C.SetSpeed] Stopped 2014-04-21T04:53:50.347Z,1398056030.347 [EcoHAB_box:Approach:C.SetSpeed](DEBUG): Uninitialize. 2014-04-21T04:53:50.347Z,1398056030.347 [EcoHAB_box:ScienceOps] Running Loop=1 2014-04-21T04:53:50.347Z,1398056030.347 [EcoHAB_box:ScienceOps](INFO): Aggregate::initialize EcoHAB_box:ScienceOps 2014-04-21T04:53:50.347Z,1398056030.347 [EcoHAB_box:ScienceOps:Science] Running Loop=1 2014-04-21T04:53:50.347Z,1398056030.347 [EcoHAB_box:ScienceOps:Science](INFO): Aggregate::initialize EcoHAB_box:ScienceOps:Science 2014-04-21T04:53:50.347Z,1398056030.347 [EcoHAB_box:ScienceOps:Science:A] Running Loop=1 2014-04-21T04:53:50.347Z,1398056030.347 [EcoHAB_box:ScienceOps:Science:B] Running Loop=1 2014-04-21T04:53:50.382Z,1398056030.382 [EcoHAB_box:ScienceOps:Science:C] Running Loop=1 2014-04-21T04:53:50.383Z,1398056030.383 [EcoHAB_box:ScienceOps:Science:D] Running Loop=1 2014-04-21T04:53:50.383Z,1398056030.383 [EcoHAB_box:ScienceOps:Science:E] Running Loop=1 2014-04-21T04:53:50.383Z,1398056030.383 [EcoHAB_box:ScienceOps:Science:F] Running Loop=1 2014-04-21T04:53:50.383Z,1398056030.383 [EcoHAB_box:ScienceOps:Science:G] Running Loop=1 2014-04-21T04:53:50.383Z,1398056030.383 [EcoHAB_box:ScienceOps:Science:PeakDetectChl] Running Loop=1 2014-04-21T04:53:50.383Z,1398056030.383 [EcoHAB_box:ScienceOps:Science:PeakDetectChl](INFO): Aggregate::initialize EcoHAB_box:ScienceOps:Science:PeakDetectChl 2014-04-21T04:53:50.383Z,1398056030.383 [EcoHAB_box:ScienceOps:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1 2014-04-21T04:53:50.383Z,1398056030.383 [EcoHAB_box:ScienceOps:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize. 2014-04-21T04:53:50.392Z,1398056030.392 [EcoHAB_box:ScienceOps:Science:PeakDetectNO3] Running Loop=1 2014-04-21T04:53:50.392Z,1398056030.392 [EcoHAB_box:ScienceOps:Science:PeakDetectNO3](INFO): Aggregate::initialize EcoHAB_box:ScienceOps:Science:PeakDetectNO3 2014-04-21T04:53:50.392Z,1398056030.392 [EcoHAB_box:ScienceOps:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1 2014-04-21T04:53:50.393Z,1398056030.393 [EcoHAB_box:ScienceOps:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize. 2014-04-21T04:53:50.396Z,1398056030.396 [EcoHAB_box:ScienceOps:D.SetSpeed] Running Loop=1 2014-04-21T04:53:50.396Z,1398056030.396 [EcoHAB_box:ScienceOps:D.SetSpeed](DEBUG): Initialize. 2014-04-21T04:53:50.396Z,1398056030.396 [EcoHAB_box:ScienceOps:E.DepthEnvelope] Running Loop=1 2014-04-21T04:53:50.397Z,1398056030.397 [EcoHAB_box:ScienceOps:E.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent. 2014-04-21T04:53:50.397Z,1398056030.397 [EcoHAB_box:ScienceOps:F.AltitudeEnvelope] Running Loop=1 2014-04-21T04:53:50.397Z,1398056030.397 [EcoHAB_box:ScienceOps:F.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent. 2014-04-21T04:53:50.397Z,1398056030.397 [EcoHAB_box:ScienceOps:G.YoYo] Running Loop=1 2014-04-21T04:53:50.397Z,1398056030.397 [EcoHAB_box:ScienceOps:G.YoYo](DEBUG): Initialize YoYoComponent. 2014-04-21T04:53:50.398Z,1398056030.398 [EcoHAB_box:ScienceOps:VTHIdx] Running Loop=1 2014-04-21T04:53:50.398Z,1398056030.398 [EcoHAB_box:ScienceOps:VTHIdx](INFO): Aggregate::initialize EcoHAB_box:ScienceOps:VTHIdx 2014-04-21T04:53:50.398Z,1398056030.398 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures] Running Loop=1 2014-04-21T04:53:50.398Z,1398056030.398 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures](INFO): Aggregate::initialize EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures 2014-04-21T04:53:50.399Z,1398056030.399 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures:DetectShallow.ValueDetect] Running Loop=1 2014-04-21T04:53:50.399Z,1398056030.399 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures:DetectShallow.ValueDetect](DEBUG): Initialize. 2014-04-21T04:53:50.399Z,1398056030.399 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures:DetectShallow.ValueDetect](INFO): Initialize with detect=depth 2014-04-21T04:53:50.408Z,1398056030.408 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures:DetectShallow.ValueDetect](INFO): Initialize with output=sea_water_temperature 2014-04-21T04:53:50.410Z,1398056030.410 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures:DetectMidShallow.ValueDetect] Running Loop=1 2014-04-21T04:53:50.410Z,1398056030.410 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures:DetectMidShallow.ValueDetect](DEBUG): Initialize. 2014-04-21T04:53:50.410Z,1398056030.410 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures:DetectMidShallow.ValueDetect](INFO): Initialize with detect=depth 2014-04-21T04:53:50.411Z,1398056030.411 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures:DetectMidShallow.ValueDetect](INFO): Initialize with output=sea_water_temperature 2014-04-21T04:53:50.412Z,1398056030.412 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures:DetectMidDeep.ValueDetect] Running Loop=1 2014-04-21T04:53:50.412Z,1398056030.412 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures:DetectMidDeep.ValueDetect](DEBUG): Initialize. 2014-04-21T04:53:50.412Z,1398056030.412 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures:DetectMidDeep.ValueDetect](INFO): Initialize with detect=depth 2014-04-21T04:53:50.413Z,1398056030.413 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures:DetectMidDeep.ValueDetect](INFO): Initialize with output=sea_water_temperature 2014-04-21T04:53:50.414Z,1398056030.414 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures:DetectDeep.ValueDetect] Running Loop=1 2014-04-21T04:53:50.415Z,1398056030.415 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures:DetectDeep.ValueDetect](DEBUG): Initialize. 2014-04-21T04:53:50.415Z,1398056030.415 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures:DetectDeep.ValueDetect](INFO): Initialize with detect=depth 2014-04-21T04:53:50.415Z,1398056030.415 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures:DetectDeep.ValueDetect](INFO): Initialize with output=sea_water_temperature 2014-04-21T04:53:50.417Z,1398056030.417 [EcoHAB_box:M.Buoyancy] Running Loop=1 2014-04-21T04:53:50.417Z,1398056030.417 [EcoHAB_box:L.Pitch] Running Loop=1 2014-04-21T04:53:50.906Z,1398056030.906 [EcoHAB_box:ScienceOps:G.YoYo] Running Loop=1 2014-04-21T04:53:50.912Z,1398056030.912 [EcoHAB_box:ScienceOps:F.AltitudeEnvelope] Running Loop=1 2014-04-21T04:53:50.918Z,1398056030.918 [EcoHAB_box:ScienceOps:E.DepthEnvelope] Running Loop=1 2014-04-21T04:53:50.923Z,1398056030.923 [EcoHAB_box:ScienceOps:D.SetSpeed] Running Loop=1 2014-04-21T04:53:50.945Z,1398056030.945 [EcoHAB_box:ScienceOps:RollSCPI] Running Loop=1 2014-04-21T04:53:50.945Z,1398056030.945 [EcoHAB_box:ScienceOps:RollSCPI](INFO): Aggregate::initialize EcoHAB_box:ScienceOps:RollSCPI 2014-04-21T04:53:50.945Z,1398056030.945 [EcoHAB_box:ScienceOps:RollSCPI:A] Running Loop=1 2014-04-21T04:53:50.945Z,1398056030.945 [EcoHAB_box:ScienceOps:RollSCPI:A] Running Loop=1 2014-04-21T04:53:50.946Z,1398056030.946 [EcoHAB_box:ScienceOps:RollSCPI:A](DEBUG): Initialize ReadDataComponent to sense SCPI.sampleSCPI 2014-04-21T04:53:50.975Z,1398056030.975 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures:DetectDeep.ValueDetect] Running Loop=1 2014-04-21T04:53:50.985Z,1398056030.985 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures:DetectMidDeep.ValueDetect] Running Loop=1 2014-04-21T04:53:50.998Z,1398056030.998 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures:DetectMidShallow.ValueDetect] Running Loop=1 2014-04-21T04:53:51.008Z,1398056031.008 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures:DetectShallow.ValueDetect] Running Loop=1 2014-04-21T04:53:51.021Z,1398056031.021 [EcoHAB_box:ScienceOps:Science] Running Loop=1 2014-04-21T04:53:51.048Z,1398056031.048 [EcoHAB_box:ScienceOps:Science:PeakDetectNO3] Stopped 2014-04-21T04:53:51.048Z,1398056031.048 [EcoHAB_box:ScienceOps:Science:PeakDetectNO3](INFO): Aggregate::uninitialize EcoHAB_box:ScienceOps:Science:PeakDetectNO3 2014-04-21T04:53:51.048Z,1398056031.048 [EcoHAB_box:ScienceOps:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped 2014-04-21T04:53:51.048Z,1398056031.048 [EcoHAB_box:ScienceOps:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2014-04-21T04:53:51.048Z,1398056031.048 [EcoHAB_box:ScienceOps:Science:PeakDetectChl] Running Loop=1 2014-04-21T04:53:51.058Z,1398056031.058 [EcoHAB_box:ScienceOps:Science:G] Running Loop=1 2014-04-21T04:53:51.059Z,1398056031.059 [EcoHAB_box:ScienceOps:Science:G](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water 2014-04-21T04:53:51.061Z,1398056031.061 [EcoHAB_box:ScienceOps:Science:F] Stopped 2014-04-21T04:53:51.061Z,1398056031.061 [EcoHAB_box:ScienceOps:Science:E] Stopped 2014-04-21T04:53:51.069Z,1398056031.069 [EcoHAB_box:ScienceOps:Science:D] Running Loop=1 2014-04-21T04:53:51.070Z,1398056031.070 [EcoHAB_box:ScienceOps:Science:D](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature 2014-04-21T04:53:51.070Z,1398056031.070 [EcoHAB_box:ScienceOps:Science:D](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity 2014-04-21T04:53:51.072Z,1398056031.072 [EcoHAB_box:ScienceOps:Science:C] Stopped 2014-04-21T04:53:51.072Z,1398056031.072 [EcoHAB_box:ScienceOps:Science:B] Stopped 2014-04-21T04:53:51.073Z,1398056031.073 [EcoHAB_box:ScienceOps:Science:A] Stopped 2014-04-21T04:53:51.367Z,1398056031.367 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4 2014-04-21T04:53:51.412Z,1398056031.412 [WetLabsBB2FL](INFO): Opening uart, block timeout 10ths=4 2014-04-21T04:53:51.412Z,1398056031.412 [WetLabsBB2FL](INFO): Powering up 2014-04-21T04:53:51.566Z,1398056031.566 [SCPI](INFO): Powering up 2014-04-21T04:53:52.172Z,1398056032.172 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-21T04:53:52.172Z,1398056032.172 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 29.2 28.8 29.7 30.0 32.9 -60.5 62.3 179.8 189 135 199 179 6 6 7 7 -39.2 -320.7 57.8 1 -287.8 152.0 42.1 1 -13 -58 0 32 189 2 2.11 -5.27 249.9 28.8 15.9 0.005 35.0 1489 87 2014-04-21T04:53:57.435Z,1398056037.435 [NAL9602](INFO): Powering down 2014-04-21T04:54:01.732Z,1398056041.732 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:64 Calculated:95 2014-04-21T04:54:01.732Z,1398056041.732 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 27.3 2 29.7 82.8 203.8 280.7 184.0 -33 181 303 36 6 7 8 7 -264.1 26.4 202.5 1 155.9 259.7 140.3 1 -448 193 131 2 363 326 131 2 -2.20 -12.33 245.3 27.3 16.0 0.005 35.0 1489 64 2014-04-21T04:54:07.693Z,1398056047.693 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-21T04:54:07.694Z,1398056047.694 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 26.8 34.3 26.8 31.2 -475.6 -201.6 -465.8 -182.4 -308 47 245 -48 5 9 5 8 -13.1 -25.6 -3.4 -319.3 1 -738 126 -17 2 473 579 -17 2 -7.16 -26.53 240.5 26.8 16.0 0.005 35.0 1489 117 2014-04-21T04:54:08.380Z,1398056048.380 [Radio_Freewave](INFO): Powering down 2014-04-21T04:54:13.807Z,1398056053.807 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-21T04:54:13.808Z,1398056053.808 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 0 1 25.1 34.8 0 33.4 52.1 399.8 0 355.4 -72 265 370 169 5 -868.8 59.3 407.3 1 437.7 820.4 -244.4 1 -589 128 197 2 357 486 197 2 -3.27 -39.62 245.9 25.1 16.0 0.005 35.0 1489 111 2014-04-21T04:54:36.605Z,1398056076.605 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-21T04:54:36.606Z,1398056076.606 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 18.5 21.7 24.7 20.5 -399.5 -86.2 366.6 139.8 -299 67 289 83 3 4 6 4 -1022.5 -301.6 5.6 1 -209.8 995.3 -319.3 1 -784 -21 37 2 60 782 37 2 -3.93 -19.718.5 15.9 0.005 35.0 1489 73 2014-04-21T04:55:13.723Z,1398056113.723 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures] Stopped 2014-04-21T04:55:13.723Z,1398056113.723 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures](INFO): Aggregate::uninitialize EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures 2014-04-21T04:55:13.723Z,1398056113.723 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures:DetectShallow.ValueDetect] Stopped 2014-04-21T04:55:13.723Z,1398056113.723 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures:DetectShallow.ValueDetect](DEBUG): Uninitialize. 2014-04-21T04:55:13.723Z,1398056113.723 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures:DetectMidShallow.ValueDetect] Stopped 2014-04-21T04:55:13.723Z,1398056113.723 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures:DetectMidShallow.ValueDetect](DEBUG): Uninitialize. 2014-04-21T04:55:13.723Z,1398056113.723 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures:DetectMidDeep.ValueDetect] Stopped 2014-04-21T04:55:13.724Z,1398056113.724 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures:DetectMidDeep.ValueDetect](DEBUG): Uninitialize. 2014-04-21T04:55:13.724Z,1398056113.724 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures:DetectDeep.ValueDetect] Stopped 2014-04-21T04:55:13.724Z,1398056113.724 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures:DetectDeep.ValueDetect](DEBUG): Uninitialize. 2014-04-21T04:55:13.724Z,1398056113.724 [EcoHAB_box:ScienceOps:VTHIdx:B] Running Loop=1 2014-04-21T04:55:14.289Z,1398056114.289 [EcoHAB_box:ScienceOps:VTHIdx:B](INFO): Temps= 15.426691 degC , 15.226404 degC , 13.876093 degC , 12.897791 degC 2014-04-21T04:55:14.296Z,1398056114.296 [EcoHAB_box:ScienceOps:VTHIdx:B] Stopped 2014-04-21T04:55:14.296Z,1398056114.296 [EcoHAB_box:ScienceOps:VTHIdx:C] Running Loop=1 2014-04-21T04:55:14.968Z,1398056114.968 [EcoHAB_box:ScienceOps:VTHIdx:C] Stopped 2014-04-21T04:55:14.968Z,1398056114.968 [EcoHAB_box:ScienceOps:VTHIdx:D] Running Loop=1 2014-04-21T04:55:15.549Z,1398056115.549 [EcoHAB_box:ScienceOps:VTHIdx:D] Stopped 2014-04-21T04:55:15.549Z,1398056115.549 [EcoHAB_box:ScienceOps:VTHIdx:E] Running Loop=1 2014-04-21T04:55:16.030Z,1398056116.030 [EcoHAB_box:ScienceOps:VTHIdx:E] Stopped 2014-04-21T04:55:16.030Z,1398056116.030 [EcoHAB_box:ScienceOps:VTHIdx:F] Running Loop=1 2014-04-21T04:55:16.616Z,1398056116.616 [EcoHAB_box:ScienceOps:VTHIdx:F] Stopped 2014-04-21T04:55:16.616Z,1398056116.616 [EcoHAB_box:ScienceOps:VTHIdx:G] Running Loop=1 2014-04-21T04:55:17.156Z,1398056117.156 [EcoHAB_box:ScienceOps:VTHIdx:G] Stopped 2014-04-21T04:55:17.156Z,1398056117.156 [EcoHAB_box:ScienceOps:VTHIdx:H] Running Loop=1 2014-04-21T04:55:17.808Z,1398056117.808 [EcoHAB_box:ScienceOps:VTHIdx:H] Stopped 2014-04-21T04:55:17.808Z,1398056117.808 [EcoHAB_box:ScienceOps:VTHIdx:I] Running Loop=1 2014-04-21T04:55:18.445Z,1398056118.445 [EcoHAB_box:ScienceOps:VTHIdx:I] Stopped 2014-04-21T04:55:18.445Z,1398056118.445 [EcoHAB_box:ScienceOps:VTHIdx:J] Running Loop=1 2014-04-21T04:55:19.103Z,1398056119.103 [EcoHAB_box:ScienceOps:VTHIdx:J](INFO): 288.576691 K - 286.047791 K = 0.969803 K 2014-04-21T04:55:19.110Z,1398056119.110 [EcoHAB_box:ScienceOps:VTHIdx:J] Stopped 2014-04-21T04:55:19.111Z,1398056119.111 [EcoHAB_box:ScienceOps:VTHIdx:K] Running Loop=1 2014-04-21T04:55:19.621Z,1398056119.621 [EcoHAB_box:ScienceOps:VTHIdx:K](INFO): Detect at 33.607896 arcdeg , -118.019890 arcdeg 2014-04-21T04:55:19.624Z,1398056119.624 [EcoHAB_box:ScienceOps:VTHIdx:K] Stopped 2014-04-21T04:55:19.624Z,1398056119.624 [EcoHAB_box:ScienceOps:VTHIdx:L] Running Loop=1 2014-04-21T04:55:20.277Z,1398056120.277 [EcoHAB_box:ScienceOps:VTHIdx:L] Stopped 2014-04-21T04:55:20.277Z,1398056120.277 [EcoHAB_box:ScienceOps:VTHIdx:M] Running Loop=1 2014-04-21T04:55:20.827Z,1398056120.827 [EcoHAB_box:ScienceOps:VTHIdx:M] Stopped 2014-04-21T04:55:20.827Z,1398056120.827 [EcoHAB_box:ScienceOps:VTHIdx:N] Running Loop=1 2014-04-21T04:55:21.442Z,1398056121.442 [EcoHAB_box:ScienceOps:VTHIdx:N] Stopped 2014-04-21T04:55:21.442Z,1398056121.442 [EcoHAB_box:ScienceOps:VTHIdx:O] Running Loop=1 2014-04-21T04:55:21.916Z,1398056121.916 [EcoHAB_box:ScienceOps:VTHIdx:O] Stopped 2014-04-21T04:55:21.916Z,1398056121.916 [EcoHAB_box:ScienceOps:VTHIdx:P] Running Loop=1 2014-04-21T04:55:22.440Z,1398056122.440 [EcoHAB_box:ScienceOps:VTHIdx:P](INFO): In VTHIdx: -272.180197 degC 2014-04-21T04:55:22.442Z,1398056122.442 [EcoHAB_box:ScienceOps:VTHIdx:P] Stopped 2014-04-21T04:55:22.442Z,1398056122.442 [EcoHAB_box:ScienceOps:VTHIdx](INFO): Completed EcoHAB_box:ScienceOps:VTHIdx 2014-04-21T04:55:22.442Z,1398056122.442 [EcoHAB_box:ScienceOps:VTHIdx] Stopped 2014-04-21T04:55:22.447Z,1398056122.447 [EcoHAB_box:ScienceOps:VTHIdx](INFO): Aggregate::uninitialize EcoHAB_box:ScienceOps:VTHIdx 2014-04-21T04:55:22.447Z,1398056122.447 [EcoHAB_box:ScienceOps:H] Running Loop=1 2014-04-21T04:55:22.447Z,1398056122.447 [EcoHAB_box:ScienceOps:H](INFO): Aggregate::initialize EcoHAB_box:ScienceOps:H 2014-04-21T04:55:22.997Z,1398056122.997 [EcoHAB_box:CircleInshoreESPBuoy] Running Loop=1 2014-04-21T04:55:22.997Z,1398056122.997 [EcoHAB_box:CircleInshoreESPBuoy](INFO): Aggregate::initialize EcoHAB_box:CircleInshoreESPBuoy 2014-04-21T04:55:22.997Z,1398056122.997 [EcoHAB_box:CircleInshoreESPBuoy:A] Running Loop=1 2014-04-21T04:55:22.998Z,1398056122.998 [EcoHAB_box:CircleInshoreESPBuoy:A](INFO): Aggregate::initialize EcoHAB_box:CircleInshoreESPBuoy:A 2014-04-21T04:55:23.532Z,1398056123.532 [EcoHAB_box:UpdateCircleTimeout] Running Loop=1 2014-04-21T04:55:23.532Z,1398056123.532 [EcoHAB_box:UpdateCircleTimeout](INFO): Aggregate::initialize EcoHAB_box:UpdateCircleTimeout 2014-04-21T04:55:23.532Z,1398056123.532 [EcoHAB_box:UpdateCircleTimeout:A] Running Loop=1 2014-04-21T04:55:23.546Z,1398056123.546 [EcoHAB_box:UpdateCircleTimeout:A] Stopped 2014-04-21T04:55:23.546Z,1398056123.546 [EcoHAB_box:UpdateCircleTimeout:B] Running Loop=1 2014-04-21T04:55:24.032Z,1398056124.032 [EcoHAB_box:UpdateCircleTimeout:B](IMPORTANT): CircleModulus calculated as: 0.923079 h 2014-04-21T04:55:24.037Z,1398056124.037 [EcoHAB_box:UpdateCircleTimeout:B] Stopped 2014-04-21T04:55:24.037Z,1398056124.037 [EcoHAB_box:UpdateCircleTimeout:C] Running Loop=1 2014-04-21T04:55:24.630Z,1398056124.630 [EcoHAB_box:UpdateCircleTimeout:C] Stopped 2014-04-21T04:55:24.634Z,1398056124.634 [EcoHAB_box:UpdateCircleTimeout:D] Running Loop=1 2014-04-21T04:55:25.129Z,1398056125.129 [EcoHAB_box:UpdateCircleTimeout:D](IMPORTANT): CircleTimeout updated to: 1.076921 h 2014-04-21T04:55:25.136Z,1398056125.136 [EcoHAB_box:UpdateCircleTimeout:D] Stopped 2014-04-21T04:55:25.137Z,1398056125.137 [EcoHAB_box:UpdateCircleTimeout](INFO): Completed EcoHAB_box:UpdateCircleTimeout 2014-04-21T04:55:25.137Z,1398056125.137 [EcoHAB_box:UpdateCircleTimeout] Stopped 2014-04-21T04:55:25.137Z,1398056125.137 [EcoHAB_box:UpdateCircleTimeout](INFO): Aggregate::uninitialize EcoHAB_box:UpdateCircleTimeout 2014-04-21T04:55:25.818Z,1398056125.818 [EcoHAB_box:CircleInshoreESPBuoy:A](INFO): Completed EcoHAB_box:CircleInshoreESPBuoy:A 2014-04-21T04:55:25.818Z,1398056125.818 [EcoHAB_box:CircleInshoreESPBuoy:A] Stopped 2014-04-21T04:55:25.818Z,1398056125.818 [EcoHAB_box:CircleInshoreESPBuoy:A](INFO): Aggregate::uninitialize EcoHAB_box:CircleInshoreESPBuoy:A 2014-04-21T04:55:25.818Z,1398056125.818 [EcoHAB_box:CircleInshoreESPBuoy:TellMeHowLong] Running Loop=1 2014-04-21T04:55:25.819Z,1398056125.819 [EcoHAB_box:CircleInshoreESPBuoy:TellMeHowLong](INFO): Aggregate::initialize EcoHAB_box:CircleInshoreESPBuoy:TellMeHowLong 2014-04-21T04:55:25.819Z,1398056125.819 [EcoHAB_box:CircleInshoreESPBuoy:TellMeHowLong:A] Running Loop=1 2014-04-21T04:55:26.347Z,1398056126.347 [EcoHAB_box:CircleInshoreESPBuoy:TellMeHowLong:A](IMPORTANT): CircleInshoreESPBuoy should complete in 64.615286 min , due to timeout in CircleWaypointRepeatedly aggregate. 2014-04-21T04:55:26.352Z,1398056126.352 [EcoHAB_box:CircleInshoreESPBuoy:TellMeHowLong:A] Stopped 2014-04-21T04:55:26.352Z,1398056126.352 [EcoHAB_box:CircleInshoreESPBuoy:TellMeHowLong:B] Running Loop=1 2014-04-21T04:55:26.353Z,1398056126.353 [EcoHAB_box:CircleInshoreESPBuoy:TellMeHowLong:B](INFO): Aggregate::initialize EcoHAB_box:CircleInshoreESPBuoy:TellMeHowLong:B 2014-04-21T04:55:26.989Z,1398056126.989 [EcoHAB_box:SurfaceCommsShort] Running Loop=1 2014-04-21T04:55:26.989Z,1398056126.989 [EcoHAB_box:SurfaceCommsShort](INFO): Aggregate::initialize EcoHAB_box:SurfaceCommsShort 2014-04-21T04:55:26.989Z,1398056126.989 [EcoHAB_box:SurfaceCommsShort:A.GoToSurface] Running Loop=1 2014-04-21T04:55:26.989Z,1398056126.989 [EcoHAB_box:SurfaceCommsShort:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-21T04:55:31.202Z,1398056131.202 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 43 of 46 2014-04-21T04:55:31.202Z,1398056131.202 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 4.3 4.5 4.6 4.2 -418.7 -45.7 214.4 -66.9 0 0 0 0 0 0 0 0 -845.0 28.3 -85.5 1 -338.7 764.4 -152.3 1 0 0 0 0 04.49 -4.42 295.2 4.2 15.5 0.005 35.0 1489 75 2014-04-21T04:55:33.821Z,1398056133.821 [EcoHAB_box:ScienceOps:Science:B] Running Loop=1 2014-04-21T04:55:33.821Z,1398056133.821 [EcoHAB_box:ScienceOps:Science:B] Running Loop=1 2014-04-21T04:55:33.822Z,1398056133.822 [EcoHAB_box:ScienceOps:Science:B](DEBUG): Initialize ReadDataComponent to sense mole_concentration_of_nitrate_in_sea_water 2014-04-21T04:55:35.087Z,1398056135.087 [ISUS](INFO): Powering up 2014-04-21T04:55:36.451Z,1398056136.451 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 4 of 46 2014-04-21T04:55:36.451Z,1398056136.451 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X 1 1 5.5 4.9 4.3 4.9 -367.0 -58.1 267.9 -109.4 0 0 0 0 0 0 0 0 -847.4 68.5 -71.9 1 -312.2 776.8 164.3 1 0 0 0 0 0 0 0 0 -3.59 16.28 296.8 4.3 15.4 0.005 35.0 1489 68 2014-04-21T04:55:39.025Z,1398056139.025 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:125 Calculated:126 2014-04-21T04:55:39.025Z,1398056139.025 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 5.0 5.7 -434.2 213.5 309.8 -295.8 0 0 0 0 0 0 0 0 -993.0 679.7 -55.8 1 122.8 1173.5 243.3 1 0 0 0 0 0 0 0 0 -3.92 20.15 299.6 5.0 15.4 0.005 35.0 1489 125 2014-04-21T04:55:47.330Z,1398056147.330 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-21T04:55:50.036Z,1398056150.036 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-21T04:55:50.598Z,1398056150.598 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:123 Calculated:118 2014-04-21T04:55:50.598Z,1398056150.598 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 10.9 9.4 8.0 9.0 -294.3 71.2 334.5 0.7 -360 62 210 2 1 1 1 1 -839.2 94.1 30.2 1 -0.8 304.6 1 -760 80 -23 2 -464 607 -23 2 -4.26 19.73 313.4 8.0 15.1 0.005 35.0 1489 123 2014-04-21T04:55:52.357Z,1398056152.357 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-21T04:55:55.032Z,1398056155.032 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-21T04:55:56.120Z,1398056156.120 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-21T04:55:56.120Z,1398056156.120 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 13.7 11.4 9.7 10.9 -463.3 -96.5 355.0 11.4 -339 17 287 83 2 1 1 1 -1092.1 -144.0 -52.2 1 -874.0 575.1 3835 -88 12 2 -690 478 12 2 -3.73 20.81 319.3 9.7 15.0 0.005 35.0 1489 113 2014-04-21T04:55:57.300Z,1398056157.300 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-21T04:55:59.493Z,1398056159.493 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-21T04:56:01.857Z,1398056161.857 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:127 Calculated:107 2014-04-21T04:56:01.857Z,1398056161.857 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 16.4 13.4 11.3 8.0 -106.1 290.4 -38.1 -364 -205 285 28 3 2 1 2 -1038.9 -90.8 -92.2 1 -888.7 464.0 301.7 1 -866 -311 -69 2 -897 201 -69 2 -3.30 21.58 327.6 11.3 14.9 0.005 35.0 1489 127 2014-04-21T04:56:02.435Z,1398056162.435 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-21T04:56:04.574Z,1398056164.574 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-21T04:56:07.337Z,1398056167.337 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-21T04:56:08.492Z,1398056168.492 [ISUS](FAULT): ISUS initialization failed. 2014-04-21T04:56:08.493Z,1398056168.493 [ISUS] Communications Fault, FailCount= 1 2014-04-21T04:56:08.493Z,1398056168.493 [ISUS](ERROR): Communications Fault 2014-04-21T04:56:08.617Z,1398056168.617 [CBIT](ERROR): Communications Fault in component: ISUS 2014-04-21T04:56:09.611Z,1398056169.611 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-21T04:56:10.287Z,1398056170.287 [CBIT](INFO): Clearing failed state for component ISUS 2014-04-21T04:56:10.288Z,1398056170.288 [ISUS] No Fault, FailCount= 1 2014-04-21T04:56:10.728Z,1398056170.728 [ISUS](INFO): Powering up 2014-04-21T04:56:11.769Z,1398056171.769 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-21T04:56:11.830Z,1398056171.830 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-21T04:56:11.830Z,1398056171.830 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 20.5 17.3 14.4 15.9 -415.6 -17.2 375.0 15.4 -404 -118 357 75 4 3 2 3 -1055.2 -43.5 -11.5 1 -922.4 323.3 400.2 1 -1015 -257 -24 2 -1041 2 -7.05 22.60 339.6 14.4 14.8 0.005 35.0 1489 107 2014-04-21T04:56:14.316Z,1398056174.316 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-21T04:56:16.511Z,1398056176.511 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-21T04:56:27.446Z,1398056187.446 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 43 of 46 2014-04-21T04:56:27.446Z,1398056187.446 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 26.6 22.8 18.9 212 33.9 404.4 41.3 -376 0 35 3 4 -999.1 -9.9 36.5 1 -892.8 191.8 407.0 1 -993 -28 3 2 -978 170 3 2 -4.95 21.89 348.5 18.9 14.6 0.005 35.0 1489 126 2014-04-21T04:56:28.694Z,1398056188.694 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 44 of 46 2014-04-21T04:56:28.694Z,1398056188.694 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 27.8 23.2 19.4 22.1 -40090.9 -12.8 -368 28 391 24 7 5 4 4 -1055.8 25.0 -4.4 1 -956.6 207.5 396.4 1 -1013 5 20 2 20 2 -4.66 22.41 350.2 19.4 14.5 0.005 35.0 1489 70 2014-04-21T04:56:29.753Z,1398056189.753 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:104 Calculated:114 2014-04-21T04:56:29.754Z,1398056189.754 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 28.6 23.7 19.8 22.2 -431.5 0.2 441.1 36.1 -372 -62 7 5 4 4 -1164.6 -47.9 12.4 1 -1059.1 140.4 466.2 1 -1191 69 20 2 -1166 255 20 2 -4.80 22.78 351.0 19.8 14.5 0.005 35.0 1489 104 2014-04-21T04:56:40.102Z,1398056200.102 [ISUS](DEBUG): Error parsing device response 2014-04-21T04:56:42.258Z,1398056202.258 [CTD_NeilBrown](ERROR): Bad response: 5.61139 2014-04-21T04:56:51.986Z,1398056211.986 [DVL_micro](ERROR): No DVL communication! Re-initializing 2014-04-21T04:56:51.986Z,1398056211.986 [DVL_micro] Communications Fault, FailCount= 1 2014-04-21T04:56:51.986Z,1398056211.986 [DVL_micro](ERROR): Communications Fault 2014-04-21T04:56:52.185Z,1398056212.185 [CBIT](ERROR): Communications Fault in component: DVL_micro 2014-04-21T04:56:52.632Z,1398056212.632 [DVL_micro](INFO): uninitialize:Powering down 2014-04-21T04:56:53.048Z,1398056213.048 [CTD_NeilBrown](ERROR): Salinity reading out of range: 18.187901 psu 2014-04-21T04:56:53.254Z,1398056213.254 [DVL_micro](FAULT): LCB fault: Software Overcurrent. 2014-04-21T04:56:53.254Z,1398056213.254 [DVL_micro] Hardware Fault, FailCount= 1 2014-04-21T04:56:53.254Z,1398056213.254 [DVL_micro](ERROR): Hardware Fault 2014-04-21T04:56:53.998Z,1398056213.998 [Radio_Freewave](INFO): Powering up 2014-04-21T04:56:54.126Z,1398056214.126 [EcoHAB_box:SurfaceCommsShort:CheckIn] Running Loop=1 2014-04-21T04:56:54.126Z,1398056214.126 [EcoHAB_box:SurfaceCommsShort:CheckIn](INFO): Aggregate::initialize EcoHAB_box:SurfaceCommsShort:CheckIn 2014-04-21T04:56:54.126Z,1398056214.126 [EcoHAB_box:SurfaceCommsShort:CheckIn:A] Running Loop=1 2014-04-21T04:56:54.265Z,1398056214.265 [CBIT](INFO): Clearing failed state for component DVL_micro 2014-04-21T04:56:54.265Z,1398056214.265 [DVL_micro] No Fault, FailCount= 1 2014-04-21T04:56:54.689Z,1398056214.689 [DVL_micro](INFO): Initializing 2014-04-21T04:56:54.752Z,1398056214.752 [EcoHAB_box:ScienceOps:Science:B] Stopped 2014-04-21T04:56:54.763Z,1398056214.763 [EcoHAB_box:SurfaceCommsShort:CheckIn:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2014-04-21T04:56:55.366Z,1398056215.366 [NAL9602](INFO): Powering up 2014-04-21T04:56:55.378Z,1398056215.378 [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-21T04:57:01.652Z,1398056221.652 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:108 Calculated:109 2014-04-21T04:57:01.652Z,1398056221.652 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 2829.3 27.8 11.1 265.2 270.8 123.6 35 256 253 51 6 7 7 6 -346.6 189.0 180.8 1 -407.1 56.2 140.2 1 -291 273 160 2 -373 141 160 2 -6.67 -2.84 22.5 27.8 14.4 0.005 35.0 1489 108 2014-04-21T04:57:06.241Z,1398056226.241 [NAL9602](INFO): NAL9602 initialized 2014-04-21T04:57:10.985Z,1398056230.985 [Radio_Freewave](INFO): Powering down 2014-04-21T04:57:25.337Z,1398056245.337 [EcoHAB_box:ScienceOps:Science:B] Running Loop=1 2014-04-21T04:57:26.205Z,1398056246.205 [DVL_micro](ERROR): No DVL communication! Re-initializing 2014-04-21T04:57:26.205Z,1398056246.205 [DVL_micro] Communications Fault, FailCount= 1 2014-04-21T04:57:26.205Z,1398056246.205 [DVL_micro](ERROR): Communications Fault 2014-04-21T04:57:26.586Z,1398056246.586 [CBIT](ERROR): Communications Fault in component: DVL_micro 2014-04-21T04:57:27.140Z,1398056247.140 [DVL_micro](INFO): uninitialize:Powering down 2014-04-21T04:57:27.182Z,1398056247.182 [ISUS](INFO): Powering up 2014-04-21T04:57:27.870Z,1398056247.870 [DVL_micro](FAULT): LCB fault: Software Overcurrent. 2014-04-21T04:57:27.870Z,1398056247.870 [DVL_micro] Hardware Fault, FailCount= 1 2014-04-21T04:57:27.870Z,1398056247.870 [DVL_micro](ERROR): Hardware Fault 2014-04-21T04:57:29.018Z,1398056249.018 [CBIT](INFO): Clearing failed state for component DVL_micro 2014-04-21T04:57:29.018Z,1398056249.018 [DVL_micro] No Fault, FailCount= 1 2014-04-21T04:57:29.580Z,1398056249.580 [DVL_micro](INFO): Initializing 2014-04-21T04:57:30.656Z,1398056250.656 [EcoHAB_box:ScienceOps:Science:B] Stopped 2014-04-21T04:57:32.650Z,1398056252.650 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2.427500 psu 2014-04-21T04:57:32.858Z,1398056252.858 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2.344700 psu 2014-04-21T04:57:33.062Z,1398056253.062 [CTD_NeilBrown](ERROR): Salinity reading out of range: 5.456800 psu 2014-04-21T04:57:33.272Z,1398056253.272 [CTD_NeilBrown](ERROR): Salinity reading out of range: 4.487400 psu 2014-04-21T04:57:33.491Z,1398056253.491 [CTD_NeilBrown](ERROR): Salinity reading out of range: 11.134000 psu 2014-04-21T04:57:33.980Z,1398056253.980 [EcoHAB_box:ScienceOps:Science:B] Running Loop=1 2014-04-21T04:57:34.741Z,1398056254.741 [Radio_Freewave](INFO): Powering up 2014-04-21T04:57:36.020Z,1398056256.020 [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-21T04:57:36.260Z,1398056256.260 [EcoHAB_box:ScienceOps:Science:B] Stopped 2014-04-21T04:57:43.316Z,1398056263.316 [NAL9602](INFO): SBD MO Status=0, MOMSN=27948, MT Status=0, MTMSN=0 2014-04-21T04:57:43.316Z,1398056263.316 [NAL9602](INFO): No messages in MT queue 2014-04-21T04:57:46.527Z,1398056266.527 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:123 Calculated:100 2014-04-21T04:57:46.528Z,1398056266.528 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 27.3 29.6 31.0 28.2 -149.5 1.7 234.3 66.1 -43 98 258 103 5 7 7 6 -512.2 -86.0 41.1 1 -321.4 -409.9 -9.9 1 -401 -6 112 2 6 112 2 -3.35 -6.24 42.5 27.3 14.7 0.005 35.0 1489 123 2014-04-21T04:57:58.433Z,1398056278.433 [Radio_Freewave](INFO): Powering down 2014-04-21T04:58:00.266Z,1398056280.266 [ISUS](FAULT): ISUS initialization failed. 2014-04-21T04:58:00.266Z,1398056280.266 [ISUS] Communications Fault, FailCount= 1 2014-04-21T04:58:00.266Z,1398056280.266 [ISUS](ERROR): Communications Fault 2014-04-21T04:58:00.494Z,1398056280.494 [CBIT](ERROR): Communications Fault in component: ISUS 2014-04-21T04:58:03.659Z,1398056283.659 [CBIT](INFO): Clearing failed state for component ISUS 2014-04-21T04:58:03.659Z,1398056283.659 [ISUS] No Fault, FailCount= 1 2014-04-21T04:58:04.142Z,1398056284.142 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 42 of 46 2014-04-21T04:58:04.142Z,1398056284.142 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 25.4 31.5 37.2 29.3 -48.5 77.3 207.9 70.9 -62 39 109 7 5 8 11 7 -342.2 8.5 82.9 1 -219.3 -267.8 -65.4 1 -228 -173 -154 25 2 -3.59 -24.21 52.2 25.4005 35.0 1489 67 2014-04-21T04:58:04.162Z,1398056284.162 [ISUS](INFO): Powering up 2014-04-21T04:58:13.583Z,1398056293.583 [EcoHAB_box:ScienceOps:Science:B] Running Loop=1 2014-04-21T04:58:15.012Z,1398056295.012 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-21T04:58:15.012Z,1398056295.012 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 32.0 28.3 24.6 27.2 -254.3 3.0 323.8 69.4 -191 9 225 60 8 6 5 6 -771.6 -88.6 38.2 1 -223.2 -684.8 293.1 1 -555 -68 27 2 -127 2 -4.69 18.90 66.0 24.6 14.9 0.005 35.0 1489 71 2014-04-21T04:58:21.570Z,1398056301.570 [EcoHAB_box:ScienceOps:Science:B] Stopped 2014-04-21T04:58:21.682Z,1398056301.682 [CTD_NeilBrown](ERROR): Salinity reading out of range: 7.926600 psu 2014-04-21T04:58:21.890Z,1398056301.890 [CTD_NeilBrown](ERROR): Salinity reading out of range: 3.333500 psu 2014-04-21T04:58:22.098Z,1398056302.098 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2.362600 psu 2014-04-21T04:58:22.311Z,1398056302.311 [CTD_NeilBrown](ERROR): Salinity reading out of range: 11.113200 psu 2014-04-21T04:58:23.230Z,1398056303.230 [Radio_Freewave](INFO): Powering up 2014-04-21T04:58:23.418Z,1398056303.418 [EcoHAB_box:ScienceOps:Science:B] Running Loop=1 2014-04-21T04:58:24.228Z,1398056304.228 [EcoHAB_box:ScienceOps:Science:B] Stopped 2014-04-21T04:58:24.960Z,1398056304.960 [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-21T04:58:25.247Z,1398056305.247 [EcoHAB_box:ScienceOps:Science:B] Running Loop=1 2014-04-21T04:58:26.169Z,1398056306.169 [EcoHAB_box:ScienceOps:Science:B] Stopped 2014-04-21T04:58:28.137Z,1398056308.137 [DVL_micro](ERROR): No DVL communication! Re-initializing 2014-04-21T04:58:28.137Z,1398056308.137 [DVL_micro] Communications Fault, FailCount= 1 2014-04-21T04:58:28.137Z,1398056308.137 [DVL_micro](ERROR): Communications Fault 2014-04-21T04:58:28.420Z,1398056308.420 [CBIT](ERROR): Communications Fault in component: DVL_micro 2014-04-21T04:58:29.101Z,1398056309.101 [DVL_micro](INFO): uninitialize:Powering down 2014-04-21T04:58:29.783Z,1398056309.783 [DVL_micro](FAULT): LCB fault: Software Overcurrent. 2014-04-21T04:58:29.783Z,1398056309.783 [DVL_micro] Hardware Fault, FailCount= 1 2014-04-21T04:58:29.783Z,1398056309.783 [DVL_micro](ERROR): Hardware Fault 2014-04-21T04:58:30.815Z,1398056310.815 [CBIT](INFO): Clearing failed state for component DVL_micro 2014-04-21T04:58:30.815Z,1398056310.815 [DVL_micro] No Fault, FailCount= 1 2014-04-21T04:58:31.278Z,1398056311.278 [DVL_micro](INFO): Initializing 2014-04-21T04:58:37.600Z,1398056317.600 [ISUS](FAULT): ISUS initialization failed. 2014-04-21T04:58:37.600Z,1398056317.600 [ISUS] Communications Fault, FailCount= 2 2014-04-21T04:58:37.600Z,1398056317.600 [ISUS](ERROR): Communications Fault 2014-04-21T04:58:37.797Z,1398056317.797 [CBIT](ERROR): Communications Fault in component: ISUS 2014-04-21T04:58:40.478Z,1398056320.478 [CBIT](INFO): Clearing failed state for component ISUS 2014-04-21T04:58:40.478Z,1398056320.478 [ISUS] No Fault, FailCount= 2 2014-04-21T04:58:40.959Z,1398056320.959 [ISUS](INFO): Powering up 2014-04-21T04:58:42.621Z,1398056322.621 [Radio_Freewave](INFO): Powering down 2014-04-21T04:58:47.285Z,1398056327.285 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:124 Calculated:108 2014-04-21T04:58:47.286Z,1398056327.286 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 26.1 28.6 30.0 27.2 -134.9 -85.2 145.5 70.0 -157 -65 31 -6 5 6 7 6 -374.2 -207.1115.9 -408.0 -55.0 1 -250 -78 -53 2 17 -262 -53 2 -3.08 -9.98 76.4 26.1 15.2 0.005 35.0 1489 124 2014-04-21T04:58:49.258Z,1398056329.258 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 43 of 46 2014-04-21T04:58:49.258Z,1398056329.258 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 26.0 29.5 31.7 27.2 7.3 68.0 213.1 176.1 -93 8 1098 6 -274.7 -144.3 125.2 1 43.7 -321.5 81.8 1 -269 -85 25 2 3 -282 25 2 -5.22 -11.26 73.2 26.0 15.2 0.005 35.0 1489 119 2014-04-21T04:58:54.607Z,1398056334.607 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 44 of 46 2014-04-21T04:58:54.607Z,1398056334.607 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 27.3 28.2 27.7 26.3 -219.7 72.3 318.4 8.3 -207 22 205 36 6 6 6 5 -718.2 85.4 48.3 1 -177.1 -701.8 39.1 1 -549 -18 15 2 -49 -548 15 2 -4.64 -0.17 82.9 260.005 35.0 1489 69 2014-04-21T04:58:57.342Z,1398056337.342 [EcoHAB_box:ScienceOps:Science:B] Running Loop=1 2014-04-21T04:59:03.270Z,1398056343.270 [CTD_NeilBrown](ERROR): Salinity reading out of range: 4.145900 psu 2014-04-21T04:59:03.482Z,1398056343.482 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2.077200 psu 2014-04-21T04:59:03.695Z,1398056343.695 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2.335500 psu 2014-04-21T04:59:03.908Z,1398056343.908 [CTD_NeilBrown](ERROR): Salinity reading out of range: 17.924101 psu 2014-04-21T04:59:04.116Z,1398056344.116 [CTD_NeilBrown](ERROR): Salinity reading out of range: 9.074800 psu 2014-04-21T04:59:04.508Z,1398056344.508 [Radio_Freewave](INFO): Powering up 2014-04-21T04:59:05.708Z,1398056345.708 [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-21T04:59:06.803Z,1398056346.803 [EcoHAB_box:ScienceOps:Science:B] Stopped 2014-04-21T04:59:07.374Z,1398056347.374 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-21T04:59:07.375Z,1398056347.375 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 30.0 31.0 28.4 27.9 -198.0 120.1 477.4 212.0 -234 -12 392 101 7 7 6 6 -901.4 -122.7 164.9 1 111.7 -878.2 266.8 1 -835 -150 66 2 168 -832 66 2 -7.76 5.58 91.2 27.9 15.3 0.005 3 85 2014-04-21T04:59:09.698Z,1398056349.698 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 44 of 46 2014-04-21T04:59:09.698Z,1398056349.698 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 29.2 31.0 28.9 27.5 -299.3 -57.9 129.6 -101.3 -326 -191 111 -67 6 7 6 6 -572.4 57.9 -88.7 1 12.3 -574.8 -91.4 1 -583 -165 -127 2 221 -564 -127 2 -8.90 0.52 95.6 27.5 15.3 0.00489 104 2014-04-21T04:59:11.275Z,1398056351.275 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:89 Calculated:88 2014-04-21T04:59:11.275Z,1398056351.275 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 30.1 30.0 28.3 28.2 -361.1-130.6 -247.1 -332 -253 -45 -191 7 7 6 6 -307.6 72.5 -251.2 1 13.4 -323.7 -240.9 1 -383 -82 -221 2 163 -356 -221 2 -3.74 2.65 102.4 28.2 15.3 0.005 35.0 1489 89 2014-04-21T04:59:12.825Z,1398056352.825 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:125 Calculated:110 2014-04-21T04:59:12.825Z,1398056352.825 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 28.6 29.6 29.7 28.4 -161.2 191.1 502.6 131.54 548 268 6 7 7 6 -885.9 79.7 179.0 1 47.6 -894.8 142.5 1 -876 -18 259 2 149 -864 259 2 -2.49 -2.12 98.6 28.4 15.3 0.005 35.0 1489 125 2014-04-21T04:59:21.332Z,1398056361.332 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 2 of 46 2014-04-21T04:59:21.333Z,1398056361.333 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 26.8 29.6 31.5 28.0 8.7 140.7 272.3 127.7 -32 129 201 78 5 7 8 6 -351.8 17.4 148.1 1 27.1 -374.4 71.8 1 -311 68 101 2 -24 -317 101 2 -4.04 -11.74 98.0 26.8 15.4 0.005 35.0 1489 99 2014-04-21T04:59:26.205Z,1398056366.205 [Radio_Freewave](INFO): Powering down 2014-04-21T04:59:28.761Z,1398056368.761 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-21T04:59:28.762Z,1398056368.762 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 0 1 25.5 30.1 0 29. -217.6 0 -207.3 -298 -282 -101 -146 5 7 20 7 -366.4 -13.7 -229.1 1 56.7 -236.0 -357.8 1 -262 -181 -223 2 210 -239 -223 2 -2.82 -.7 25.5 15.4 0.005 35.0 1489 119 2014-04-21T04:59:39.957Z,1398056379.957 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-21T04:59:39.958Z,1398056379.958 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 29.3 28.6 25.1 25.8 -279.6 50.1 278.4 -27.4 -358 -99 212 1 7 7 5 5 -744.7 103.4 5.8 1 80.7 -737.6 121.7 1 -760 -133 -65 2 3225 2 -5.06 9.68 104.7 25.1 15.5 0.005 35.0 1489 84 2014-04-21T04:59:40.166Z,1398056380.166 [EcoHAB_box:ScienceOps:Science:B] Running Loop=1 2014-04-21T04:59:41.907Z,1398056381.907 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 4 of 46 2014-04-21T04:59:41.907Z,1398056381.907 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 01 1 1 32.8 29.2 24.9 27.2 -343.9 26.9 236.9 -125.1 -258 -101 254 -54 9 7 5 6 -775.2 202.9 -55.4 1 15.1 -786.0 164.8 1 -683 -62 -42 2 253 -637 -42 2 -4.61 17.55 106.4 24.9 15.55.0 1489 90 2014-04-21T04:59:41.994Z,1398056381.994 [ISUS](INFO): Powering up 2014-04-21T04:59:47.803Z,1398056387.803 [EcoHAB_box:ScienceOps:Science:B] Stopped 2014-04-21T04:59:48.706Z,1398056388.706 [EcoHAB_box:ScienceOps:Science:B] Running Loop=1 2014-04-21T04:59:49.061Z,1398056389.061 [CTD_NeilBrown](ERROR): Salinity reading out of range: 5.786800 psu 2014-04-21T04:59:49.265Z,1398056389.265 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2.463100 psu 2014-04-21T04:59:49.394Z,1398056389.394 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 29 of 46 2014-04-21T04:59:49.395Z,1398056389.395 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 41.3 33.5 26.4 31.4 -255.4 -120.7 352.7 169.9 -144 -14 330 167 13 9 5 8 -811.6 -387.8 39.5 1 555.4 -541.4 457.1 1 - 91 2 416 -533 91 2 -3.48 29.48 107.1 26.4 15.6 0.005 35.0 1489 113 2014-04-21T04:59:49.477Z,1398056389.477 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2.390800 psu 2014-04-21T04:59:49.566Z,1398056389.566 [EcoHAB_box:ScienceOps:Science:B] Stopped 2014-04-21T04:59:49.686Z,1398056389.686 [CTD_NeilBrown](ERROR): Salinity reading out of range: 6.449400 psu 2014-04-21T04:59:49.898Z,1398056389.898 [CTD_NeilBrown](ERROR): Salinity reading out of range: 7.920900 psu 2014-04-21T04:59:50.220Z,1398056390.220 [Radio_Freewave](INFO): Powering up 2014-04-21T04:59:50.401Z,1398056390.401 [EcoHAB_box:ScienceOps:Science:B] Running Loop=1 2014-04-21T04:59:51.597Z,1398056391.597 [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-21T04:59:52.709Z,1398056392.709 [EcoHAB_box:ScienceOps:Science:B] Stopped 2014-04-21T05:00:12.642Z,1398056412.642 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-21T05:00:12.643Z,1398056412.643 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 2 32.4 27.2 391.9 411.1 439.8 442.5 307 252 344 376 5 7 8 5 -63.9 -41.9 454.4 1 7.6 -135.7 440.3 1 -49 -165 344 2 172 -3 344 2 -95 105.5 27.2 15.6 0.005 35.0 1489 97 2014-04-21T05:00:14.194Z,1398056414.194 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:97 Calculated:99 2014-04-21T05:00:14.195Z,1398056414.195 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 27.7 30.3 31.4 27.9 -20.4 131.8 233.0 42.6 -25 9 6 7 8 6 -338.2 119.0 104.3 1 4.3 -371.7 35.8 1 -373 29 2 2 102 -360 2 2 -5.27 -9.49 110.4 27.7 15.6 0.005 35.0 1489 97 2014-04-21T05:00:15.722Z,1398056415.722 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:127 Calculated:102 2014-04-21T05:00:15.722Z,1398056415.722 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 0 1 27.0 30.0 0 28.8 -21.0 63.4 -69 185 259 115 5 7 21 6 -455.5 228.4 160.6 1 -62.4 -528.5 47.2 1 -437 93 132 2 53 -444 132 2 -0.99 -13.34 108.9 27.0 15.7 0.005 35.0 1489 127 2014-04-21T05:00:19.019Z,1398056419.019 [NAL9602](IMPORTANT): GPS fix at: 1398056399.00 2014-04-21T05:00:19.170Z,1398056419.170 [EcoHAB_box:SurfaceCommsShort:CheckIn:A] Stopped 2014-04-21T05:00:19.179Z,1398056419.179 [EcoHAB_box:SurfaceCommsShort:CheckIn:B] Running Loop=1