2014-04-16T08:35:47.523Z,1397637347.523 [Supervisor](DEBUG): Initializing supervisor. 2014-04-16T08:35:47.528Z,1397637347.528 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0 2014-04-16T08:35:47.529Z,1397637347.529 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2014-04-16T08:35:47.532Z,1397637347.532 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0 2014-04-16T08:35:47.535Z,1397637347.535 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2014-04-16T08:35:47.548Z,1397637347.548 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2014-04-16T08:35:47.552Z,1397637347.552 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0 2014-04-16T08:35:47.553Z,1397637347.553 [ComponentRegistry](DEBUG): SyncComponent "logger" handled in the control thread. 2014-04-16T08:35:47.555Z,1397637347.555 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2014-04-16T08:35:47.556Z,1397637347.556 [Supervisor](INFO): Looking for Config files in directory: Config/ 2014-04-16T08:35:47.560Z,1397637347.560 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2014-04-16T08:35:48.002Z,1397637348.002 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2014-04-16T08:35:48.003Z,1397637348.003 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2014-04-16T08:35:48.341Z,1397637348.341 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2014-04-16T08:35:48.341Z,1397637348.341 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2014-04-16T08:35:48.442Z,1397637348.442 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2014-04-16T08:35:48.444Z,1397637348.444 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2014-04-16T08:35:48.703Z,1397637348.703 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2014-04-16T08:35:48.704Z,1397637348.704 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2014-04-16T08:35:48.895Z,1397637348.895 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2014-04-16T08:35:48.897Z,1397637348.897 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2014-04-16T08:35:49.270Z,1397637349.270 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2014-04-16T08:35:49.271Z,1397637349.271 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2014-04-16T08:35:49.492Z,1397637349.492 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2014-04-16T08:35:49.494Z,1397637349.494 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2014-04-16T08:35:49.928Z,1397637349.928 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2014-04-16T08:35:49.930Z,1397637349.930 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2014-04-16T08:35:50.060Z,1397637350.060 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2014-04-16T08:35:50.060Z,1397637350.060 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2014-04-16T08:35:50.670Z,1397637350.670 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2014-04-16T08:35:50.670Z,1397637350.670 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2014-04-16T08:35:50.801Z,1397637350.801 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2014-04-16T08:35:50.802Z,1397637350.802 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2014-04-16T08:35:51.003Z,1397637351.003 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2014-04-16T08:35:51.130Z,1397637351.130 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2014-04-16T08:35:51.133Z,1397637351.133 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2014-04-16T08:35:51.255Z,1397637351.255 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2014-04-16T08:35:51.255Z,1397637351.255 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2014-04-16T08:35:51.415Z,1397637351.415 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2014-04-16T08:35:51.417Z,1397637351.417 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2014-04-16T08:35:51.421Z,1397637351.421 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2014-04-16T08:35:51.548Z,1397637351.548 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2014-04-16T08:35:51.704Z,1397637351.704 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2014-04-16T08:35:51.816Z,1397637351.816 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2014-04-16T08:35:51.924Z,1397637351.924 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2014-04-16T08:35:52.113Z,1397637352.113 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2014-04-16T08:35:52.253Z,1397637352.253 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2014-04-16T08:35:52.354Z,1397637352.354 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2014-04-16T08:35:52.478Z,1397637352.478 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2014-04-16T08:35:52.595Z,1397637352.595 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2014-04-16T08:35:52.599Z,1397637352.599 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2014-04-16T08:35:53.223Z,1397637353.223 [AHRS_sp3003D] Loaded 2014-04-16T08:35:53.223Z,1397637353.223 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread. 2014-04-16T08:35:53.564Z,1397637353.564 [Batt_Ocean_Server] Loaded 2014-04-16T08:35:53.565Z,1397637353.565 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread. 2014-04-16T08:35:53.747Z,1397637353.747 [DataOverHttps] Loaded 2014-04-16T08:35:53.747Z,1397637353.747 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2014-04-16T08:35:53.761Z,1397637353.761 [Depth_Keller] Loaded 2014-04-16T08:35:53.762Z,1397637353.762 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2014-04-16T08:35:53.767Z,1397637353.767 [DropWeight] Loaded 2014-04-16T08:35:53.767Z,1397637353.767 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2014-04-16T08:35:53.929Z,1397637353.929 [DVL_micro] Loaded 2014-04-16T08:35:53.929Z,1397637353.929 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2014-04-16T08:35:54.045Z,1397637354.045 [NAL9602] Loaded 2014-04-16T08:35:54.045Z,1397637354.045 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2014-04-16T08:35:54.103Z,1397637354.103 [Onboard] Loaded 2014-04-16T08:35:54.104Z,1397637354.104 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2014-04-16T08:35:54.111Z,1397637354.111 [Radio_Freewave] Loaded 2014-04-16T08:35:54.111Z,1397637354.111 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread. 2014-04-16T08:35:54.122Z,1397637354.122 [SCPI] Loaded 2014-04-16T08:35:54.123Z,1397637354.123 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread. 2014-04-16T08:35:54.123Z,1397637354.123 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2014-04-16T08:35:54.124Z,1397637354.124 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2014-04-16T08:35:54.341Z,1397637354.341 [InternalSim] Loaded 2014-04-16T08:35:54.342Z,1397637354.342 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread. 2014-04-16T08:35:54.342Z,1397637354.342 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2014-04-16T08:35:54.343Z,1397637354.343 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2014-04-16T08:35:54.653Z,1397637354.653 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2014-04-16T08:35:54.654Z,1397637354.654 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2014-04-16T08:35:54.662Z,1397637354.662 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator. 2014-04-16T08:35:54.667Z,1397637354.667 [AsyncPiEstimator] Loaded 2014-04-16T08:35:54.668Z,1397637354.668 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread. 2014-04-16T08:35:54.671Z,1397637354.671 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406714E0 2014-04-16T08:35:54.672Z,1397637354.672 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2014-04-16T08:35:54.673Z,1397637354.673 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2014-04-16T08:35:54.780Z,1397637354.780 [DeadReckonUsingMultipleVelocitySources] Loaded 2014-04-16T08:35:54.780Z,1397637354.780 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2014-04-16T08:35:54.835Z,1397637354.835 [DeadReckonWithRespectToWater] Loaded 2014-04-16T08:35:54.835Z,1397637354.835 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToWater" handled in the control thread. 2014-04-16T08:35:54.888Z,1397637354.888 [DeadReckonWithRespectToSeafloor] Loaded 2014-04-16T08:35:54.888Z,1397637354.888 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToSeafloor" handled in the control thread. 2014-04-16T08:35:54.958Z,1397637354.958 [DeadReckonUsingDVLWaterTrack] Loaded 2014-04-16T08:35:54.959Z,1397637354.959 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingDVLWaterTrack" handled in the control thread. 2014-04-16T08:35:55.078Z,1397637355.078 [DeadReckonUsingCompactModelForecast] Loaded 2014-04-16T08:35:55.079Z,1397637355.079 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingCompactModelForecast" handled in the control thread. 2014-04-16T08:35:55.108Z,1397637355.108 [NavChart] Loaded 2014-04-16T08:35:55.108Z,1397637355.108 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2014-04-16T08:35:55.125Z,1397637355.125 [UniversalFixResidualReporter] Loaded 2014-04-16T08:35:55.126Z,1397637355.126 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2014-04-16T08:35:55.126Z,1397637355.126 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2014-04-16T08:35:55.127Z,1397637355.127 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2014-04-16T08:35:55.217Z,1397637355.217 [VerticalControl](DEBUG): Construct VerticalControl. 2014-04-16T08:35:55.366Z,1397637355.366 [VerticalControl] Loaded 2014-04-16T08:35:55.366Z,1397637355.366 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2014-04-16T08:35:55.367Z,1397637355.367 [HorizontalControl](DEBUG): Construct HorizontalControl. 2014-04-16T08:35:55.469Z,1397637355.469 [HorizontalControl] Loaded 2014-04-16T08:35:55.469Z,1397637355.469 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2014-04-16T08:35:55.470Z,1397637355.470 [SpeedControl](DEBUG): Construct SpeedControl. 2014-04-16T08:35:55.471Z,1397637355.471 [SpeedControl] Loaded 2014-04-16T08:35:55.472Z,1397637355.472 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2014-04-16T08:35:55.473Z,1397637355.473 [LoopControl](DEBUG): Construct LoopControl. 2014-04-16T08:35:55.474Z,1397637355.474 [LoopControl] Loaded 2014-04-16T08:35:55.474Z,1397637355.474 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2014-04-16T08:35:55.475Z,1397637355.475 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2014-04-16T08:35:55.475Z,1397637355.475 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2014-04-16T08:35:55.529Z,1397637355.529 [DepthRateCalculator] Loaded 2014-04-16T08:35:55.529Z,1397637355.529 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2014-04-16T08:35:55.535Z,1397637355.535 [PitchRateCalculator] Loaded 2014-04-16T08:35:55.535Z,1397637355.535 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2014-04-16T08:35:55.548Z,1397637355.548 [SpeedCalculator] Loaded 2014-04-16T08:35:55.549Z,1397637355.549 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2014-04-16T08:35:55.566Z,1397637355.566 [TempGradientCalculator] Loaded 2014-04-16T08:35:55.566Z,1397637355.566 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2014-04-16T08:35:55.571Z,1397637355.571 [YawRateCalculator] Loaded 2014-04-16T08:35:55.572Z,1397637355.572 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2014-04-16T08:35:55.572Z,1397637355.572 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2014-04-16T08:35:55.573Z,1397637355.573 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2014-04-16T08:35:55.810Z,1397637355.810 [CTD_NeilBrown] Loaded 2014-04-16T08:35:55.810Z,1397637355.810 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2014-04-16T08:35:55.821Z,1397637355.821 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 407134E0 2014-04-16T08:35:55.835Z,1397637355.835 [ISUS] Loaded 2014-04-16T08:35:55.835Z,1397637355.835 [ComponentRegistry](DEBUG): SyncComponent "ISUS" handled in the control thread. 2014-04-16T08:35:55.859Z,1397637355.859 [PAR_Licor] Loaded 2014-04-16T08:35:55.859Z,1397637355.859 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2014-04-16T08:35:55.937Z,1397637355.937 [WetLabsBB2FL] Loaded 2014-04-16T08:35:55.937Z,1397637355.937 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2014-04-16T08:35:55.941Z,1397637355.941 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407434E0 2014-04-16T08:35:55.942Z,1397637355.942 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2014-04-16T08:35:55.944Z,1397637355.944 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2014-04-16T08:35:56.282Z,1397637356.282 [SBIT](DEBUG): Construct Startup Built In Test. 2014-04-16T08:35:56.311Z,1397637356.311 [SBIT] Loaded 2014-04-16T08:35:56.311Z,1397637356.311 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2014-04-16T08:35:56.312Z,1397637356.312 [IBIT](DEBUG): Construct Initiated Built In Test. 2014-04-16T08:35:56.350Z,1397637356.350 [IBIT] Loaded 2014-04-16T08:35:56.350Z,1397637356.350 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2014-04-16T08:35:56.352Z,1397637356.352 [CBIT](DEBUG): Construct CBIT Built In Test. 2014-04-16T08:35:56.506Z,1397637356.506 [CBIT] Loaded 2014-04-16T08:35:56.506Z,1397637356.506 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2014-04-16T08:35:56.507Z,1397637356.507 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2014-04-16T08:35:56.518Z,1397637356.518 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2014-04-16T08:36:02.787Z,1397637362.787 [HFRadarModelCalc] Loaded 2014-04-16T08:36:02.787Z,1397637362.787 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread. 2014-04-16T08:36:07.721Z,1397637367.721 [HFRadarCompactModelForecaster] Loaded 2014-04-16T08:36:07.722Z,1397637367.722 [ComponentRegistry](DEBUG): SyncComponent "HFRadarCompactModelForecaster" handled in the control thread. 2014-04-16T08:36:08.841Z,1397637368.841 [HFRCMSpaceInterpolator] Loaded 2014-04-16T08:36:08.841Z,1397637368.841 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSpaceInterpolator" handled in the control thread. 2014-04-16T08:36:08.843Z,1397637368.843 [HFRCMTimeInterpolator] Loaded 2014-04-16T08:36:08.844Z,1397637368.844 [ComponentRegistry](DEBUG): SyncComponent "HFRCMTimeInterpolator" handled in the control thread. 2014-04-16T08:36:08.857Z,1397637368.857 [HFRCMSurfaceCurrentAtVehicleLocation] Loaded 2014-04-16T08:36:08.857Z,1397637368.857 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSurfaceCurrentAtVehicleLocation" handled in the control thread. 2014-04-16T08:36:08.890Z,1397637368.890 [HFRCMVirtualSurfaceDrifter] Loaded 2014-04-16T08:36:08.890Z,1397637368.890 [ComponentRegistry](DEBUG): SyncComponent "HFRCMVirtualSurfaceDrifter" handled in the control thread. 2014-04-16T08:36:08.891Z,1397637368.891 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2014-04-16T08:36:08.891Z,1397637368.891 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2014-04-16T08:36:09.029Z,1397637369.029 [BuoyancyServo] Loaded 2014-04-16T08:36:09.029Z,1397637369.029 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2014-04-16T08:36:09.042Z,1397637369.042 [ElevatorServo] Loaded 2014-04-16T08:36:09.042Z,1397637369.042 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2014-04-16T08:36:09.054Z,1397637369.054 [MassServo] Loaded 2014-04-16T08:36:09.054Z,1397637369.054 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2014-04-16T08:36:09.070Z,1397637369.070 [RudderServo] Loaded 2014-04-16T08:36:09.071Z,1397637369.071 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2014-04-16T08:36:09.083Z,1397637369.083 [ThrusterServo] Loaded 2014-04-16T08:36:09.083Z,1397637369.083 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2014-04-16T08:36:09.083Z,1397637369.083 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2014-04-16T08:36:09.084Z,1397637369.084 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2014-04-16T08:36:09.124Z,1397637369.124 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2014-04-16T08:36:09.130Z,1397637369.130 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2014-04-16T08:36:09.131Z,1397637369.131 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2014-04-16T08:36:09.137Z,1397637369.137 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2014-04-16T08:36:09.142Z,1397637369.142 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A004E0 2014-04-16T08:36:09.147Z,1397637369.147 [Supervisor](DEBUG): Running supervisor. 2014-04-16T08:36:09.148Z,1397637369.148 [CommandLine](INFO): Thread ID is 778 2014-04-16T08:36:09.154Z,1397637369.154 [controlThread](INFO): Thread ID is 777 2014-04-16T08:36:09.155Z,1397637369.155 [controlThread](DEBUG): Initializing ControlThread 2014-04-16T08:36:09.155Z,1397637369.155 [CycleStarter](INFO): Thread ID is 776 2014-04-16T08:36:09.162Z,1397637369.162 [AsyncPiEstimator](INFO): Thread ID is 851 2014-04-16T08:36:09.162Z,1397637369.162 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator. 2014-04-16T08:36:09.174Z,1397637369.174 [CTD_NeilBrown](INFO): Thread ID is 855 2014-04-16T08:36:09.175Z,1397637369.175 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown. 2014-04-16T08:36:09.176Z,1397637369.176 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4 2014-04-16T08:36:09.191Z,1397637369.191 [WetLabsBB2FL](INFO): Thread ID is 856 2014-04-16T08:36:09.192Z,1397637369.192 [WetLabsBB2FL](INFO): Powering down 2014-04-16T08:36:09.215Z,1397637369.215 [NavChartDb](INFO): Thread ID is 860 2014-04-16T08:36:09.228Z,1397637369.228 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources 2014-04-16T08:36:09.228Z,1397637369.228 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2014-04-16T08:36:09.229Z,1397637369.229 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2014-04-16T08:36:09.229Z,1397637369.229 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2014-04-16T08:36:09.229Z,1397637369.229 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2014-04-16T08:36:09.230Z,1397637369.230 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2014-04-16T08:36:09.230Z,1397637369.230 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2014-04-16T08:36:09.230Z,1397637369.230 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2014-04-16T08:36:09.230Z,1397637369.230 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2014-04-16T08:36:10.671Z,1397637370.671 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized 2014-04-16T08:36:10.703Z,1397637370.703 [InternalSim](DEBUG): InternalSim initializing... 2014-04-16T08:36:11.055Z,1397637371.055 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2014-04-16T08:36:11.055Z,1397637371.055 [DeadReckonWithRespectToWater](DEBUG): Initializing DeadReckonWithRespectToWater component. 2014-04-16T08:36:11.056Z,1397637371.056 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component. 2014-04-16T08:36:11.056Z,1397637371.056 [DeadReckonUsingDVLWaterTrack](DEBUG): Initializing DeadReckonUsingDVLWaterTrack component. 2014-04-16T08:36:11.056Z,1397637371.056 [DeadReckonUsingCompactModelForecast](DEBUG): Initializing DeadReckonUsingCompactModelForecast component. 2014-04-16T08:36:11.057Z,1397637371.057 [NavChart](DEBUG): Initialize NavChart Navigation. 2014-04-16T08:36:11.057Z,1397637371.057 [UniversalFixResidualReporter](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2014-04-16T08:36:11.058Z,1397637371.058 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2014-04-16T08:36:11.060Z,1397637371.060 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2014-04-16T08:36:11.060Z,1397637371.060 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2014-04-16T08:36:11.077Z,1397637371.077 [LoopControl](DEBUG): Initialize LoopControlComponent. 2014-04-16T08:36:11.077Z,1397637371.077 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2014-04-16T08:36:11.078Z,1397637371.078 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2014-04-16T08:36:11.078Z,1397637371.078 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2014-04-16T08:36:11.078Z,1397637371.078 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2014-04-16T08:36:11.079Z,1397637371.079 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2014-04-16T08:36:11.081Z,1397637371.081 [SBIT](INFO): Initialize SBIT Component. 2014-04-16T08:36:11.081Z,1397637371.081 [SBIT](IMPORTANT): Tethys CM Info: $Rev:11220 2014-04-16T08:36:11.082Z,1397637371.082 [SBIT](IMPORTANT): Kernel Release:2.6.27.8 2014-04-16T08:36:11.082Z,1397637371.082 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014 2014-04-16T08:36:11.083Z,1397637371.083 [IBIT](INFO): Initialize IBIT Component. 2014-04-16T08:36:11.084Z,1397637371.084 [CBIT](DEBUG): Initialize CBIT Component. 2014-04-16T08:36:11.084Z,1397637371.084 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL. 2014-04-16T08:36:11.084Z,1397637371.084 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2014-04-16T08:36:11.109Z,1397637371.109 [HFRCMSpaceInterpolator](DEBUG): Initializing HFRCMSpaceInterpolator component. 2014-04-16T08:36:11.111Z,1397637371.111 [HFRCMTimeInterpolator](DEBUG): Initializing HFRCMTimeInterpolator component. 2014-04-16T08:36:11.111Z,1397637371.111 [HFRCMSurfaceCurrentAtVehicleLocation](DEBUG): Initializing HFRCMSurfaceCurrentAtVehicleLocation component. 2014-04-16T08:36:11.112Z,1397637371.112 [HFRCMVirtualSurfaceDrifter](DEBUG): Initializing HFRCMVirtualSurfaceDrifter component. 2014-04-16T08:36:11.114Z,1397637371.114 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2014-04-16T08:36:11.174Z,1397637371.174 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-16T08:36:11.183Z,1397637371.183 [MissionManager](DEBUG): 2014-04-16T08:36:11.184Z,1397637371.184 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2014-04-16T08:36:11.243Z,1397637371.243 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool 2014-04-16T08:36:11.245Z,1397637371.245 [Default:GPS:A.SetSpeed](DEBUG): Construct. 2014-04-16T08:36:11.261Z,1397637371.261 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-16T08:36:11.270Z,1397637371.270 [Default:Iridium:A.SetSpeed](DEBUG): Construct. 2014-04-16T08:36:11.290Z,1397637371.290 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-16T08:36:11.297Z,1397637371.297 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2014-04-16T08:36:11.319Z,1397637371.319 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Construct. 2014-04-16T08:36:11.334Z,1397637371.334 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-16T08:36:11.342Z,1397637371.342 [MissionManager](DEBUG): 400 400 Burn 300 Dropped drop weight due to communications timeout 5.0 1.0 5 2014-04-16T08:36:11.359Z,1397637371.359 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,DataOverHttps,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,Radio_Freewave,SCPI,ISUS,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,HFRadarModelCalc,HFRadarCompactModelForecaster,HFRCMSpaceInterpolator,HFRCMTimeInterpolator,HFRCMSurfaceCurrentAtVehicleLocation,HFRCMVirtualSurfaceDrifter,DeadReckonUsingMultipleVelocitySources,DeadReckonWithRespectToWater,DeadReckonWithRespectToSeafloor,DeadReckonUsingDVLWaterTrack,DeadReckonUsingCompactModelForecast,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,logger,LogSplitter, 2014-04-16T08:36:11.473Z,1397637371.473 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2014-04-16T08:36:11.502Z,1397637371.502 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T08:36:11.551Z,1397637371.551 [DVL_micro](INFO): Initializing 2014-04-16T08:36:11.580Z,1397637371.580 [NAL9602](INFO): Powering up NAL9602 2014-04-16T08:36:11.646Z,1397637371.645 [Radio_Freewave](INFO): Powering up 2014-04-16T08:36:11.958Z,1397637371.958 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:12.127Z,1397637372.127 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2014-04-16T08:36:12.135Z,1397637372.135 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2014-04-16T08:36:12.141Z,1397637372.141 [ElevatorServo](DEBUG): Initializing EZServoServo. 2014-04-16T08:36:12.146Z,1397637372.146 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2014-04-16T08:36:12.153Z,1397637372.153 [MassServo](DEBUG): Initializing EZServoServo. 2014-04-16T08:36:12.159Z,1397637372.159 [MassServo](DEBUG): Initializing MassServo. 2014-04-16T08:36:12.165Z,1397637372.165 [RudderServo](DEBUG): Initializing EZServoServo. 2014-04-16T08:36:12.171Z,1397637372.171 [RudderServo](DEBUG): Initializing RudderServo. 2014-04-16T08:36:12.177Z,1397637372.177 [ThrusterServo](DEBUG): Initializing EZServoServo. 2014-04-16T08:36:12.183Z,1397637372.183 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2014-04-16T08:36:22.355Z,1397637382.355 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T08:36:22.356Z,1397637382.356 [DataOverHttps](DEBUG): sslConnect 2014-04-16T08:36:22.359Z,1397637382.359 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:36:22.510Z,1397637382.510 [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-16T08:36:22.558Z,1397637382.558 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:23.472Z,1397637383.472 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:36:24.650Z,1397637384.650 [NAL9602](INFO): NAL9602 initialized 2014-04-16T08:36:24.681Z,1397637384.681 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:25.339Z,1397637385.339 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:36:25.342Z,1397637385.342 [DataOverHttps](DEBUG): dataWrite 2014-04-16T08:36:25.342Z,1397637385.342 [DataOverHttps](DEBUG): dataWriting 2014-04-16T08:36:25.344Z,1397637385.344 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-16T08:36:25.468Z,1397637385.468 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:26.269Z,1397637386.269 [DataOverHttps](DEBUG): dataRead 2014-04-16T08:36:26.335Z,1397637386.335 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:26.868Z,1397637386.868 [DataOverHttps](DEBUG): dataRead 2014-04-16T08:36:26.869Z,1397637386.869 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-16T08:36:26.870Z,1397637386.870 [DataOverHttps](DEBUG): disconnect 2014-04-16T08:36:26.874Z,1397637386.874 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004713 2014-04-16T08:36:27.061Z,1397637387.061 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:27.267Z,1397637387.267 [SBIT](IMPORTANT): Beginning Startup BIT 2014-04-16T08:36:27.270Z,1397637387.270 [CBIT](IMPORTANT): Beginning GF scan 2014-04-16T08:36:28.006Z,1397637388.006 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:28.966Z,1397637388.966 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:30.191Z,1397637390.191 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:30.790Z,1397637390.790 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:31.439Z,1397637391.439 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:32.187Z,1397637392.187 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:32.777Z,1397637392.777 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:33.477Z,1397637393.477 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:34.057Z,1397637394.057 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:34.710Z,1397637394.710 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:35.273Z,1397637395.273 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:35.906Z,1397637395.906 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:36.563Z,1397637396.563 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#4 STATUS: 65535 2014-04-16T08:36:36.727Z,1397637396.727 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:37.575Z,1397637397.575 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:38.175Z,1397637398.175 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:38.794Z,1397637398.794 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:39.475Z,1397637399.475 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:40.206Z,1397637400.206 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:40.894Z,1397637400.894 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:41.697Z,1397637401.697 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:42.464Z,1397637402.464 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:43.080Z,1397637403.080 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:43.709Z,1397637403.709 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:44.567Z,1397637404.567 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:45.216Z,1397637405.216 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:45.842Z,1397637405.842 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:46.527Z,1397637406.527 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:47.272Z,1397637407.272 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:48.037Z,1397637408.037 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:48.657Z,1397637408.657 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:49.254Z,1397637409.254 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:49.861Z,1397637409.861 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:50.380Z,1397637410.380 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:51.027Z,1397637411.027 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:51.740Z,1397637411.740 [NAL9602](INFO): SBD MO Status=2, MOMSN=26089, MT Status=2, MTMSN=0 2014-04-16T08:36:51.741Z,1397637411.741 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2014-04-16T08:36:51.766Z,1397637411.766 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:52.451Z,1397637412.451 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:52.986Z,1397637412.986 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:53.434Z,1397637413.434 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:53.908Z,1397637413.908 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:54.442Z,1397637414.442 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:55.046Z,1397637415.046 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:55.075Z,1397637415.075 [CBIT](IMPORTANT): No ground fault detected 2014-04-16T08:36:55.620Z,1397637415.620 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:56.200Z,1397637416.200 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:56.694Z,1397637416.694 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:57.349Z,1397637417.349 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:57.939Z,1397637417.939 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:58.587Z,1397637418.587 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:59.118Z,1397637419.118 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:36:59.653Z,1397637419.653 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:00.139Z,1397637420.139 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:00.713Z,1397637420.713 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:01.257Z,1397637421.257 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:01.826Z,1397637421.826 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:02.409Z,1397637422.409 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:02.988Z,1397637422.988 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:03.505Z,1397637423.505 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:03.997Z,1397637423.997 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:04.489Z,1397637424.489 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:04.936Z,1397637424.936 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:05.385Z,1397637425.385 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:05.806Z,1397637425.806 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:06.221Z,1397637426.221 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:06.635Z,1397637426.635 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:07.052Z,1397637427.052 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:07.577Z,1397637427.577 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:08.049Z,1397637428.049 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:08.450Z,1397637428.450 [NAL9602](INFO): SBD MO Status=0, MOMSN=26089, MT Status=0, MTMSN=0 2014-04-16T08:37:08.450Z,1397637428.450 [NAL9602](INFO): No messages in MT queue 2014-04-16T08:37:08.464Z,1397637428.464 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:08.894Z,1397637428.894 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:09.325Z,1397637429.325 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:09.993Z,1397637429.993 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:10.908Z,1397637430.908 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:11.467Z,1397637431.467 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:11.967Z,1397637431.967 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T08:37:11.992Z,1397637431.992 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:12.581Z,1397637432.581 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T08:37:12.581Z,1397637432.581 [DataOverHttps](DEBUG): sslConnect 2014-04-16T08:37:12.582Z,1397637432.582 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:37:12.607Z,1397637432.607 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:13.235Z,1397637433.235 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:37:13.720Z,1397637433.720 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:14.177Z,1397637434.177 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:37:14.179Z,1397637434.179 [DataOverHttps](DEBUG): dataWrite 2014-04-16T08:37:14.179Z,1397637434.179 [DataOverHttps](DEBUG): dataWriting 2014-04-16T08:37:14.181Z,1397637434.181 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-16T08:37:14.234Z,1397637434.234 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:14.744Z,1397637434.744 [DataOverHttps](DEBUG): dataRead 2014-04-16T08:37:14.786Z,1397637434.786 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:15.243Z,1397637435.243 [DataOverHttps](DEBUG): dataRead 2014-04-16T08:37:15.243Z,1397637435.243 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-16T08:37:15.244Z,1397637435.244 [DataOverHttps](DEBUG): disconnect 2014-04-16T08:37:15.287Z,1397637435.287 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:15.752Z,1397637435.752 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:16.210Z,1397637436.210 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:16.629Z,1397637436.629 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:17.079Z,1397637437.079 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:17.582Z,1397637437.582 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:18.063Z,1397637438.063 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:18.492Z,1397637438.492 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:18.906Z,1397637438.906 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:19.319Z,1397637439.319 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:19.769Z,1397637439.769 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:20.192Z,1397637440.192 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:20.643Z,1397637440.643 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:21.108Z,1397637441.108 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:21.123Z,1397637441.123 [SBIT](IMPORTANT): SBIT PASSED 2014-04-16T08:37:21.548Z,1397637441.548 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:21.556Z,1397637441.556 [MissionManager](IMPORTANT): Started mission Startup 2014-04-16T08:37:21.556Z,1397637441.556 [Startup] Running Loop=1 2014-04-16T08:37:21.556Z,1397637441.556 [Startup](INFO): Aggregate::initialize Startup 2014-04-16T08:37:21.556Z,1397637441.556 [Startup:A.GoToSurface] Running Loop=1 2014-04-16T08:37:21.556Z,1397637441.556 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-16T08:37:21.563Z,1397637441.563 [Startup:StartupSatComms] Running Loop=1 2014-04-16T08:37:21.563Z,1397637441.563 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms 2014-04-16T08:37:21.563Z,1397637441.563 [Startup:StartupSatComms:A] Running Loop=1 2014-04-16T08:37:22.051Z,1397637442.051 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:22.059Z,1397637442.059 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2014-04-16T08:37:22.482Z,1397637442.482 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:22.950Z,1397637442.950 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:23.395Z,1397637443.395 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:23.852Z,1397637443.852 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:24.347Z,1397637444.347 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:24.767Z,1397637444.767 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:25.182Z,1397637445.182 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:25.607Z,1397637445.607 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:26.021Z,1397637446.021 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:26.475Z,1397637446.475 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:26.955Z,1397637446.955 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:27.430Z,1397637447.430 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:27.909Z,1397637447.909 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:28.344Z,1397637448.344 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:28.760Z,1397637448.760 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:29.207Z,1397637449.207 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:29.641Z,1397637449.641 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:30.090Z,1397637450.090 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:30.553Z,1397637450.553 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:30.965Z,1397637450.965 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:31.420Z,1397637451.420 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:31.844Z,1397637451.844 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:32.278Z,1397637452.278 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:32.718Z,1397637452.718 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:33.209Z,1397637453.209 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:33.705Z,1397637453.705 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:34.126Z,1397637454.126 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:34.545Z,1397637454.545 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:34.955Z,1397637454.955 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:35.390Z,1397637455.390 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:35.796Z,1397637455.796 [NAL9602](IMPORTANT): GPS fix at: 1397637454.00 2014-04-16T08:37:35.809Z,1397637455.809 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:35.828Z,1397637455.828 [Startup:StartupSatComms:A] Stopped 2014-04-16T08:37:35.828Z,1397637455.828 [Startup:StartupSatComms:B] Running Loop=1 2014-04-16T08:37:36.368Z,1397637456.368 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:36.382Z,1397637456.382 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2014-04-16T08:37:37.375Z,1397637457.375 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T08:37:37.409Z,1397637457.409 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:37.988Z,1397637457.988 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T08:37:37.988Z,1397637457.988 [DataOverHttps](DEBUG): sslConnect 2014-04-16T08:37:37.989Z,1397637457.989 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:37:38.028Z,1397637458.028 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:38.621Z,1397637458.621 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:37:39.284Z,1397637459.284 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:39.725Z,1397637459.725 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:37:39.727Z,1397637459.727 [DataOverHttps](DEBUG): dataWrite 2014-04-16T08:37:39.729Z,1397637459.729 [DataOverHttps](INFO): Sending 292 bytes from file Logs/20140416T083547/Courier0000.lzma 2014-04-16T08:37:39.729Z,1397637459.729 [DataOverHttps](DEBUG): dataWriting 2014-04-16T08:37:39.732Z,1397637459.732 [DataOverHttps](DEBUG): Wrote 1011 bytes 2014-04-16T08:37:39.754Z,1397637459.754 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:40.281Z,1397637460.281 [DataOverHttps](DEBUG): dataRead 2014-04-16T08:37:40.323Z,1397637460.323 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:40.804Z,1397637460.804 [DataOverHttps](DEBUG): dataRead 2014-04-16T08:37:40.805Z,1397637460.805 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=true&momsn=775182&filename=Logs%2F20140416T083547%2FCourier0000.lzma 2014-04-16T08:37:40.806Z,1397637460.806 [DataOverHttps](INFO): Moved sent file to Logs/20140416T083547/Courier0000.lzma.bak 2014-04-16T08:37:40.806Z,1397637460.806 [DataOverHttps](INFO): SBD MOMSN=775182 2014-04-16T08:37:40.806Z,1397637460.806 [DataOverHttps](DEBUG): disconnect 2014-04-16T08:37:40.826Z,1397637460.826 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:41.282Z,1397637461.282 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T08:37:41.341Z,1397637461.341 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:41.844Z,1397637461.844 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T08:37:41.844Z,1397637461.844 [DataOverHttps](DEBUG): sslConnect 2014-04-16T08:37:41.845Z,1397637461.845 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:37:41.869Z,1397637461.869 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:42.297Z,1397637462.297 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:37:42.779Z,1397637462.779 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:43.424Z,1397637463.424 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:37:43.426Z,1397637463.426 [DataOverHttps](DEBUG): dataWrite 2014-04-16T08:37:43.427Z,1397637463.427 [DataOverHttps](DEBUG): dataWriting 2014-04-16T08:37:43.428Z,1397637463.428 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-16T08:37:43.452Z,1397637463.452 [NAL9602](INFO): Powering down 2014-04-16T08:37:43.467Z,1397637463.467 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:43.967Z,1397637463.967 [DataOverHttps](DEBUG): dataRead 2014-04-16T08:37:43.989Z,1397637463.989 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:44.464Z,1397637464.464 [DataOverHttps](DEBUG): dataRead 2014-04-16T08:37:44.465Z,1397637464.465 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-16T08:37:44.465Z,1397637464.465 [DataOverHttps](DEBUG): disconnect 2014-04-16T08:37:44.549Z,1397637464.549 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:44.981Z,1397637464.981 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T08:37:44.998Z,1397637464.998 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:45.414Z,1397637465.414 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T08:37:45.414Z,1397637465.414 [DataOverHttps](DEBUG): sslConnect 2014-04-16T08:37:45.415Z,1397637465.415 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:37:45.438Z,1397637465.438 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:45.904Z,1397637465.904 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:37:46.436Z,1397637466.436 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:46.904Z,1397637466.904 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:37:46.906Z,1397637466.906 [DataOverHttps](DEBUG): dataWrite 2014-04-16T08:37:46.909Z,1397637466.909 [DataOverHttps](INFO): Sending 684 bytes from file Logs/20140416T083547/Express0001.lzma 2014-04-16T08:37:46.909Z,1397637466.909 [DataOverHttps](DEBUG): dataWriting 2014-04-16T08:37:46.912Z,1397637466.912 [DataOverHttps](DEBUG): Wrote 1978 bytes 2014-04-16T08:37:46.951Z,1397637466.951 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:47.413Z,1397637467.413 [DataOverHttps](DEBUG): dataRead 2014-04-16T08:37:47.437Z,1397637467.437 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:47.907Z,1397637467.907 [DataOverHttps](DEBUG): dataRead 2014-04-16T08:37:47.908Z,1397637467.908 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=true&momsn=775185&filename=Logs%2F20140416T083547%2FExpress0001.lzma 2014-04-16T08:37:47.909Z,1397637467.909 [DataOverHttps](INFO): Moved sent file to Logs/20140416T083547/Express0001.lzma.bak 2014-04-16T08:37:47.909Z,1397637467.909 [DataOverHttps](INFO): SBD MOMSN=775185 2014-04-16T08:37:47.909Z,1397637467.909 [DataOverHttps](DEBUG): disconnect 2014-04-16T08:37:47.935Z,1397637467.935 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:48.505Z,1397637468.505 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T08:37:48.524Z,1397637468.524 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T08:37:48.525Z,1397637468.525 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:48.538Z,1397637468.538 [Startup:StartupSatComms:B] Stopped 2014-04-16T08:37:48.538Z,1397637468.538 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2014-04-16T08:37:48.538Z,1397637468.538 [Startup:StartupSatComms] Stopped 2014-04-16T08:37:48.538Z,1397637468.538 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms 2014-04-16T08:37:48.539Z,1397637468.539 [Startup](INFO): Completed Startup 2014-04-16T08:37:48.539Z,1397637468.539 [Startup] Stopped 2014-04-16T08:37:48.539Z,1397637468.539 [Startup](INFO): Aggregate::uninitialize Startup 2014-04-16T08:37:48.540Z,1397637468.540 [Startup:A.GoToSurface] Stopped 2014-04-16T08:37:48.540Z,1397637468.540 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-16T08:37:49.023Z,1397637469.023 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T08:37:49.023Z,1397637469.023 [DataOverHttps](DEBUG): sslConnect 2014-04-16T08:37:49.024Z,1397637469.024 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:37:49.048Z,1397637469.048 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:49.061Z,1397637469.061 [MissionManager](IMPORTANT): Started mission Default 2014-04-16T08:37:49.061Z,1397637469.061 [Default] Running Loop=1 2014-04-16T08:37:49.061Z,1397637469.061 [Default](INFO): Aggregate::initialize Default 2014-04-16T08:37:49.061Z,1397637469.061 [Default:Iridium] Running Loop=1 2014-04-16T08:37:49.062Z,1397637469.062 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2014-04-16T08:37:49.062Z,1397637469.062 [Default:Iridium:A.SetSpeed] Running Loop=1 2014-04-16T08:37:49.062Z,1397637469.062 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2014-04-16T08:37:49.062Z,1397637469.062 [Default:Iridium:B.GoToSurface] Running Loop=1 2014-04-16T08:37:49.062Z,1397637469.062 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-16T08:37:49.068Z,1397637469.068 [Default:Iridium:B.GoToSurface] Stopped 2014-04-16T08:37:49.068Z,1397637469.068 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-16T08:37:49.069Z,1397637469.069 [Default:Iridium:Read_Iridium] Running Loop=1 2014-04-16T08:37:49.069Z,1397637469.069 [Default:Iridium:A.SetSpeed] Running Loop=1 2014-04-16T08:37:49.074Z,1397637469.074 [Default:GPS] Running Loop=1 2014-04-16T08:37:49.074Z,1397637469.074 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2014-04-16T08:37:49.074Z,1397637469.074 [Default:GPS:A.SetSpeed] Running Loop=1 2014-04-16T08:37:49.074Z,1397637469.074 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2014-04-16T08:37:49.075Z,1397637469.075 [Default:GPS:B.GoToSurface] Running Loop=1 2014-04-16T08:37:49.075Z,1397637469.075 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-16T08:37:49.081Z,1397637469.081 [Default:GPS:B.GoToSurface] Stopped 2014-04-16T08:37:49.081Z,1397637469.081 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-16T08:37:49.081Z,1397637469.081 [Default:GPS:Read_GPS] Running Loop=1 2014-04-16T08:37:49.081Z,1397637469.081 [Default:GPS:A.SetSpeed] Running Loop=1 2014-04-16T08:37:49.614Z,1397637469.614 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:37:50.116Z,1397637470.116 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:50.130Z,1397637470.130 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2014-04-16T08:37:50.133Z,1397637470.133 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2014-04-16T08:37:51.042Z,1397637471.042 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:37:51.044Z,1397637471.044 [DataOverHttps](DEBUG): dataWrite 2014-04-16T08:37:51.044Z,1397637471.044 [DataOverHttps](DEBUG): dataWriting 2014-04-16T08:37:51.045Z,1397637471.045 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-16T08:37:51.048Z,1397637471.048 [NAL9602](INFO): Powering up 2014-04-16T08:37:51.062Z,1397637471.062 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:51.515Z,1397637471.515 [DataOverHttps](DEBUG): dataRead 2014-04-16T08:37:51.540Z,1397637471.540 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:51.956Z,1397637471.956 [DataOverHttps](DEBUG): dataRead 2014-04-16T08:37:51.956Z,1397637471.956 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-16T08:37:51.957Z,1397637471.957 [DataOverHttps](DEBUG): disconnect 2014-04-16T08:37:51.980Z,1397637471.980 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:52.440Z,1397637472.440 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T08:37:52.462Z,1397637472.462 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:52.885Z,1397637472.885 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T08:37:52.885Z,1397637472.885 [DataOverHttps](DEBUG): sslConnect 2014-04-16T08:37:52.886Z,1397637472.886 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:37:52.910Z,1397637472.910 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:53.416Z,1397637473.416 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:37:53.922Z,1397637473.922 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:54.415Z,1397637474.415 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:37:54.418Z,1397637474.418 [DataOverHttps](DEBUG): dataWrite 2014-04-16T08:37:54.420Z,1397637474.420 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20140416T083547/Courier0004.lzma 2014-04-16T08:37:54.420Z,1397637474.420 [DataOverHttps](DEBUG): dataWriting 2014-04-16T08:37:54.422Z,1397637474.422 [DataOverHttps](DEBUG): Wrote 391 bytes 2014-04-16T08:37:54.439Z,1397637474.439 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:54.888Z,1397637474.888 [DataOverHttps](DEBUG): dataRead 2014-04-16T08:37:54.913Z,1397637474.913 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:55.359Z,1397637475.359 [DataOverHttps](DEBUG): dataRead 2014-04-16T08:37:55.360Z,1397637475.360 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=true&momsn=775199&filename=Logs%2F20140416T083547%2FCourier0004.lzma 2014-04-16T08:37:55.360Z,1397637475.360 [DataOverHttps](INFO): Moved sent file to Logs/20140416T083547/Courier0004.lzma.bak 2014-04-16T08:37:55.360Z,1397637475.360 [DataOverHttps](INFO): SBD MOMSN=775199 2014-04-16T08:37:55.361Z,1397637475.361 [DataOverHttps](DEBUG): disconnect 2014-04-16T08:37:55.380Z,1397637475.380 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:55.829Z,1397637475.829 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T08:37:55.854Z,1397637475.854 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:56.270Z,1397637476.270 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T08:37:56.271Z,1397637476.271 [DataOverHttps](DEBUG): sslConnect 2014-04-16T08:37:56.272Z,1397637476.272 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:37:56.295Z,1397637476.295 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:56.715Z,1397637476.715 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:37:57.224Z,1397637477.224 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:57.742Z,1397637477.742 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:37:57.744Z,1397637477.744 [DataOverHttps](DEBUG): dataWrite 2014-04-16T08:37:57.745Z,1397637477.745 [DataOverHttps](DEBUG): dataWriting 2014-04-16T08:37:57.746Z,1397637477.746 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-16T08:37:57.770Z,1397637477.770 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:58.255Z,1397637478.255 [DataOverHttps](DEBUG): dataRead 2014-04-16T08:37:58.278Z,1397637478.278 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:58.710Z,1397637478.710 [DataOverHttps](DEBUG): dataRead 2014-04-16T08:37:58.711Z,1397637478.711 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-16T08:37:58.711Z,1397637478.711 [DataOverHttps](DEBUG): disconnect 2014-04-16T08:37:58.730Z,1397637478.730 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:59.155Z,1397637479.155 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T08:37:59.179Z,1397637479.179 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:37:59.609Z,1397637479.609 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T08:37:59.609Z,1397637479.609 [DataOverHttps](DEBUG): sslConnect 2014-04-16T08:37:59.610Z,1397637479.610 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:37:59.632Z,1397637479.632 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:00.082Z,1397637480.082 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:38:00.589Z,1397637480.589 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:01.054Z,1397637481.054 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:38:01.056Z,1397637481.056 [DataOverHttps](DEBUG): dataWrite 2014-04-16T08:38:01.060Z,1397637481.060 [DataOverHttps](INFO): Sending 92 bytes from file Logs/20140416T083547/Express0005.lzma 2014-04-16T08:38:01.061Z,1397637481.061 [DataOverHttps](DEBUG): dataWriting 2014-04-16T08:38:01.064Z,1397637481.064 [DataOverHttps](DEBUG): Wrote 494 bytes 2014-04-16T08:38:01.085Z,1397637481.085 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:01.518Z,1397637481.518 [DataOverHttps](DEBUG): dataRead 2014-04-16T08:38:01.568Z,1397637481.568 [NAL9602](INFO): NAL9602 initialized 2014-04-16T08:38:01.587Z,1397637481.587 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:02.079Z,1397637482.079 [DataOverHttps](DEBUG): dataRead 2014-04-16T08:38:02.080Z,1397637482.080 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=true&momsn=775201&filename=Logs%2F20140416T083547%2FExpress0005.lzma 2014-04-16T08:38:02.081Z,1397637482.081 [DataOverHttps](INFO): Moved sent file to Logs/20140416T083547/Express0005.lzma.bak 2014-04-16T08:38:02.081Z,1397637482.081 [DataOverHttps](INFO): SBD MOMSN=775201 2014-04-16T08:38:02.082Z,1397637482.082 [DataOverHttps](DEBUG): disconnect 2014-04-16T08:38:02.101Z,1397637482.101 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:02.601Z,1397637482.601 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T08:38:02.645Z,1397637482.645 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T08:38:02.646Z,1397637482.646 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:02.659Z,1397637482.659 [Default:Iridium:Read_Iridium] Stopped 2014-04-16T08:38:02.660Z,1397637482.660 [Default:Iridium](INFO): Completed Default:Iridium 2014-04-16T08:38:02.660Z,1397637482.660 [Default:Iridium] Stopped 2014-04-16T08:38:02.660Z,1397637482.660 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2014-04-16T08:38:02.660Z,1397637482.660 [Default:Iridium:A.SetSpeed] Stopped 2014-04-16T08:38:02.660Z,1397637482.660 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2014-04-16T08:38:02.660Z,1397637482.660 [Default:WaitAtTheSurface] Running Loop=1 2014-04-16T08:38:02.660Z,1397637482.660 [Default:WaitAtTheSurface](INFO): Aggregate::initialize Default:WaitAtTheSurface 2014-04-16T08:38:02.660Z,1397637482.660 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Running Loop=1 2014-04-16T08:38:02.660Z,1397637482.660 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Initialize. 2014-04-16T08:38:02.661Z,1397637482.661 [Default:WaitAtTheSurface:B.GoToSurface] Running Loop=1 2014-04-16T08:38:02.661Z,1397637482.661 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-16T08:38:03.137Z,1397637483.137 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T08:38:03.137Z,1397637483.137 [DataOverHttps](DEBUG): sslConnect 2014-04-16T08:38:03.138Z,1397637483.138 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:38:03.185Z,1397637483.185 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:03.200Z,1397637483.200 [Default:WaitAtTheSurface:B.GoToSurface] Running Loop=1 2014-04-16T08:38:03.206Z,1397637483.206 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Running Loop=1 2014-04-16T08:38:03.708Z,1397637483.708 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:38:04.231Z,1397637484.231 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:04.719Z,1397637484.719 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:38:04.721Z,1397637484.721 [DataOverHttps](DEBUG): dataWrite 2014-04-16T08:38:04.722Z,1397637484.722 [DataOverHttps](DEBUG): dataWriting 2014-04-16T08:38:04.723Z,1397637484.723 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-16T08:38:04.745Z,1397637484.745 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:05.230Z,1397637485.230 [DataOverHttps](DEBUG): dataRead 2014-04-16T08:38:05.254Z,1397637485.254 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:05.677Z,1397637485.677 [DataOverHttps](DEBUG): dataRead 2014-04-16T08:38:05.678Z,1397637485.678 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-16T08:38:05.678Z,1397637485.678 [DataOverHttps](DEBUG): disconnect 2014-04-16T08:38:05.704Z,1397637485.704 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:06.160Z,1397637486.160 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:06.596Z,1397637486.596 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:07.032Z,1397637487.032 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:07.528Z,1397637487.528 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:08.006Z,1397637488.006 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:08.496Z,1397637488.496 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:08.955Z,1397637488.955 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:09.388Z,1397637489.388 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:09.860Z,1397637489.860 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:10.305Z,1397637490.305 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:10.763Z,1397637490.763 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:11.238Z,1397637491.238 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:11.676Z,1397637491.676 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:12.174Z,1397637492.174 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:12.621Z,1397637492.621 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:13.057Z,1397637493.057 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:13.548Z,1397637493.548 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:14.025Z,1397637494.025 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:14.532Z,1397637494.532 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:14.972Z,1397637494.972 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:15.409Z,1397637495.409 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:15.858Z,1397637495.858 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:16.298Z,1397637496.298 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:16.759Z,1397637496.759 [NAL9602](INFO): SBD MO Status=0, MOMSN=26090, MT Status=0, MTMSN=0 2014-04-16T08:38:16.759Z,1397637496.759 [NAL9602](INFO): No messages in MT queue 2014-04-16T08:38:16.773Z,1397637496.773 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:17.253Z,1397637497.253 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:17.736Z,1397637497.736 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:18.192Z,1397637498.192 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:18.692Z,1397637498.692 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:19.227Z,1397637499.227 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:19.678Z,1397637499.678 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:20.117Z,1397637500.117 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:20.620Z,1397637500.620 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:21.120Z,1397637501.120 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:21.622Z,1397637501.622 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:22.063Z,1397637502.063 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:22.504Z,1397637502.504 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:22.937Z,1397637502.937 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:23.392Z,1397637503.392 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:23.944Z,1397637503.944 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:24.462Z,1397637504.462 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:24.904Z,1397637504.904 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:25.347Z,1397637505.347 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:25.776Z,1397637505.776 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:26.237Z,1397637506.237 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:26.720Z,1397637506.720 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:27.209Z,1397637507.209 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:27.693Z,1397637507.693 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:28.131Z,1397637508.131 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:28.608Z,1397637508.608 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:29.124Z,1397637509.124 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:29.598Z,1397637509.598 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:30.055Z,1397637510.055 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:30.526Z,1397637510.526 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:31.030Z,1397637511.030 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:31.472Z,1397637511.472 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:31.911Z,1397637511.911 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:32.362Z,1397637512.362 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:32.819Z,1397637512.819 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:33.280Z,1397637513.280 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:33.776Z,1397637513.776 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:34.311Z,1397637514.311 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:34.899Z,1397637514.899 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:35.472Z,1397637515.472 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:36.153Z,1397637516.153 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:36.628Z,1397637516.628 [NAL9602](IMPORTANT): GPS fix at: 1397637514.00 2014-04-16T08:38:36.642Z,1397637516.642 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:36.659Z,1397637516.659 [Default:GPS:Read_GPS] Stopped 2014-04-16T08:38:36.659Z,1397637516.659 [Default:GPS:D] Running Loop=1 2014-04-16T08:38:37.150Z,1397637517.150 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:37.171Z,1397637517.171 [Default:GPS:D] Stopped 2014-04-16T08:38:37.172Z,1397637517.172 [Default:GPS](INFO): Completed Default:GPS 2014-04-16T08:38:37.172Z,1397637517.172 [Default:GPS] Stopped 2014-04-16T08:38:37.172Z,1397637517.172 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2014-04-16T08:38:37.172Z,1397637517.172 [Default:GPS:A.SetSpeed] Stopped 2014-04-16T08:38:37.172Z,1397637517.172 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2014-04-16T08:38:37.727Z,1397637517.727 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:42.945Z,1397637522.945 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:47.890Z,1397637527.890 [Depth_Keller](ERROR): Pressure reading out of range: 1830.238403 decibar 2014-04-16T08:38:47.912Z,1397637527.912 [Radio_Freewave](INFO): Powering down 2014-04-16T08:38:47.941Z,1397637527.941 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:52.919Z,1397637532.919 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:38:57.891Z,1397637537.891 [NAL9602](INFO): Powering down 2014-04-16T08:38:57.907Z,1397637537.907 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:39:02.888Z,1397637542.888 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T08:39:02.931Z,1397637542.931 [Radio_Freewave](INFO): Powering up 2014-04-16T08:39:02.952Z,1397637542.952 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:39:08.036Z,1397637548.036 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T08:39:08.036Z,1397637548.036 [DataOverHttps](DEBUG): sslConnect 2014-04-16T08:39:08.038Z,1397637548.038 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:39:08.088Z,1397637548.088 [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-16T08:39:08.151Z,1397637548.151 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:39:12.891Z,1397637552.891 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:39:13.387Z,1397637553.387 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:39:17.891Z,1397637557.891 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:39:17.893Z,1397637557.893 [DataOverHttps](DEBUG): dataWrite 2014-04-16T08:39:17.893Z,1397637557.893 [DataOverHttps](DEBUG): dataWriting 2014-04-16T08:39:17.895Z,1397637557.895 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-16T08:39:17.912Z,1397637557.912 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:39:22.887Z,1397637562.887 [DataOverHttps](DEBUG): dataRead 2014-04-16T08:39:22.889Z,1397637562.889 [Depth_Keller](ERROR): Pressure reading out of range: 1830.263794 decibar 2014-04-16T08:39:22.930Z,1397637562.930 [Radio_Freewave](INFO): Powering down 2014-04-16T08:39:22.964Z,1397637562.964 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:39:27.907Z,1397637567.907 [DataOverHttps](DEBUG): dataRead 2014-04-16T08:39:27.908Z,1397637567.908 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-16T08:39:27.908Z,1397637567.908 [DataOverHttps](DEBUG): disconnect 2014-04-16T08:39:27.933Z,1397637567.933 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:39:32.883Z,1397637572.884 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2014-04-16T08:39:32.884Z,1397637572.884 [DVL_micro] Data Fault, FailCount= 1 2014-04-16T08:39:32.884Z,1397637572.884 [DVL_micro](ERROR): Data Fault 2014-04-16T08:39:32.902Z,1397637572.902 [Radio_Freewave](INFO): Powering up 2014-04-16T08:39:32.931Z,1397637572.931 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:39:32.985Z,1397637572.985 [CBIT](ERROR): Data Fault in component: DVL_micro 2014-04-16T08:39:37.894Z,1397637577.894 [Depth_Keller](ERROR): Pressure reading out of range: 1830.256714 decibar 2014-04-16T08:39:37.966Z,1397637577.966 [DVL_micro](INFO): uninitialize:Powering down 2014-04-16T08:39:37.985Z,1397637577.985 [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-16T08:39:38.036Z,1397637578.036 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:39:42.896Z,1397637582.896 [DVL_micro](FAULT): LCB fault: Software Overcurrent. 2014-04-16T08:39:42.896Z,1397637582.896 [DVL_micro] Hardware Fault, FailCount= 1 2014-04-16T08:39:42.896Z,1397637582.896 [DVL_micro](ERROR): Hardware Fault 2014-04-16T08:39:42.911Z,1397637582.911 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:39:47.887Z,1397637587.887 [Depth_Keller](ERROR): Pressure reading out of range: 1830.231445 decibar 2014-04-16T08:39:47.895Z,1397637587.895 [DVL_micro](INFO): Initializing 2014-04-16T08:39:47.912Z,1397637587.912 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:39:47.933Z,1397637587.933 [CBIT](INFO): Clearing failed state for component DVL_micro 2014-04-16T08:39:47.934Z,1397637587.934 [DVL_micro] No Fault, FailCount= 1 2014-04-16T08:39:52.902Z,1397637592.902 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:39:57.882Z,1397637597.882 [Depth_Keller](ERROR): Pressure reading out of range: 1830.260254 decibar 2014-04-16T08:39:57.899Z,1397637597.899 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:40:02.893Z,1397637602.893 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T08:40:02.910Z,1397637602.910 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:40:07.880Z,1397637607.880 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T08:40:07.881Z,1397637607.881 [DataOverHttps](DEBUG): sslConnect 2014-04-16T08:40:07.882Z,1397637607.882 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:40:07.885Z,1397637607.885 [Depth_Keller](ERROR): Pressure reading out of range: 1830.262817 decibar 2014-04-16T08:40:07.922Z,1397637607.922 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:40:12.888Z,1397637612.888 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:40:13.430Z,1397637613.430 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:40:17.884Z,1397637617.884 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:40:17.886Z,1397637617.886 [DataOverHttps](DEBUG): dataWrite 2014-04-16T08:40:17.886Z,1397637617.886 [DataOverHttps](DEBUG): dataWriting 2014-04-16T08:40:17.888Z,1397637617.888 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-16T08:40:17.926Z,1397637617.926 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:40:22.884Z,1397637622.884 [DataOverHttps](DEBUG): dataRead 2014-04-16T08:40:22.905Z,1397637622.905 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:40:27.895Z,1397637627.895 [DataOverHttps](DEBUG): dataRead 2014-04-16T08:40:27.896Z,1397637627.896 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-16T08:40:27.896Z,1397637627.896 [DataOverHttps](DEBUG): disconnect 2014-04-16T08:40:27.936Z,1397637627.936 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:40:32.879Z,1397637632.879 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:40:37.888Z,1397637637.888 [Depth_Keller](ERROR): Pressure reading out of range: 1372.552490 decibar 2014-04-16T08:40:37.925Z,1397637637.925 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:40:42.904Z,1397637642.904 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:40:47.896Z,1397637647.896 [Depth_Keller](ERROR): Pressure reading out of range: 1372.562866 decibar 2014-04-16T08:40:47.932Z,1397637647.932 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:40:52.903Z,1397637652.903 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:40:57.887Z,1397637657.887 [Depth_Keller](ERROR): Pressure reading out of range: 1830.268066 decibar 2014-04-16T08:40:57.924Z,1397637657.924 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:41:02.918Z,1397637662.918 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T08:41:02.935Z,1397637662.935 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:41:07.885Z,1397637667.885 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T08:41:07.886Z,1397637667.886 [DataOverHttps](DEBUG): sslConnect 2014-04-16T08:41:07.887Z,1397637667.887 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:41:07.890Z,1397637667.890 [Depth_Keller](ERROR): Pressure reading out of range: 1830.244507 decibar 2014-04-16T08:41:07.927Z,1397637667.927 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:41:12.889Z,1397637672.889 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:41:13.362Z,1397637673.362 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:41:13.724Z,1397637673.724 [CommandLine](IMPORTANT): got command @ date -u -Iseconds 2014-04-16T08:41:17.881Z,1397637677.881 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:41:17.884Z,1397637677.884 [DataOverHttps](DEBUG): dataWrite 2014-04-16T08:41:17.884Z,1397637677.884 [DataOverHttps](DEBUG): dataWriting 2014-04-16T08:41:17.885Z,1397637677.885 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-16T08:41:17.929Z,1397637677.929 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:41:22.836Z,1397637682.836 [DataOverHttps](DEBUG): dataRead 2014-04-16T08:41:22.855Z,1397637682.855 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:41:27.920Z,1397637687.920 [DataOverHttps](DEBUG): dataRead 2014-04-16T08:41:27.921Z,1397637687.921 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-16T08:41:27.921Z,1397637687.921 [DataOverHttps](DEBUG): disconnect 2014-04-16T08:41:27.969Z,1397637687.969 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:41:32.873Z,1397637692.873 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:41:37.872Z,1397637697.872 [Depth_Keller](ERROR): Pressure reading out of range: 1830.261108 decibar 2014-04-16T08:41:37.909Z,1397637697.909 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:41:42.899Z,1397637702.899 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:41:47.867Z,1397637707.867 [Depth_Keller](ERROR): Pressure reading out of range: 1830.248047 decibar 2014-04-16T08:41:47.904Z,1397637707.904 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:41:52.907Z,1397637712.907 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:41:57.891Z,1397637717.891 [Depth_Keller](ERROR): Pressure reading out of range: 1830.276001 decibar 2014-04-16T08:41:57.928Z,1397637717.928 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:42:00.284Z,1397637720.284 [CommandLine](IMPORTANT): got command @ /etc/rc.d/init.d/settime restart 2014-04-16T08:42:02.950Z,1397637722.950 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T08:42:02.976Z,1397637722.976 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:42:07.894Z,1397637727.894 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T08:42:07.894Z,1397637727.894 [DataOverHttps](DEBUG): sslConnect 2014-04-16T08:42:07.895Z,1397637727.895 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:42:07.898Z,1397637727.898 [Depth_Keller](ERROR): Pressure reading out of range: 1830.245361 decibar 2014-04-16T08:42:07.937Z,1397637727.937 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:42:12.909Z,1397637732.909 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:42:13.384Z,1397637733.384 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:42:17.865Z,1397637737.865 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:42:17.867Z,1397637737.867 [DataOverHttps](DEBUG): dataWrite 2014-04-16T08:42:17.867Z,1397637737.867 [DataOverHttps](DEBUG): dataWriting 2014-04-16T08:42:17.868Z,1397637737.868 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-16T08:42:17.906Z,1397637737.906 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:42:22.917Z,1397637742.917 [DataOverHttps](DEBUG): dataRead 2014-04-16T08:42:22.935Z,1397637742.935 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:42:27.881Z,1397637747.881 [DataOverHttps](DEBUG): dataRead 2014-04-16T08:42:27.881Z,1397637747.881 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-16T08:42:27.881Z,1397637747.881 [DataOverHttps](DEBUG): disconnect 2014-04-16T08:42:27.886Z,1397637747.886 [Depth_Keller](ERROR): Pressure reading out of range: 1830.270752 decibar 2014-04-16T08:42:27.923Z,1397637747.923 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:42:32.901Z,1397637752.901 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:42:37.882Z,1397637757.882 [Depth_Keller](ERROR): Pressure reading out of range: 1830.230591 decibar 2014-04-16T08:42:37.919Z,1397637757.919 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:42:42.909Z,1397637762.909 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:42:47.881Z,1397637767.881 [Depth_Keller](ERROR): Pressure reading out of range: 1830.233154 decibar 2014-04-16T08:42:47.919Z,1397637767.919 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:42:52.900Z,1397637772.900 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:42:57.893Z,1397637777.893 [Depth_Keller](ERROR): Pressure reading out of range: 1830.256714 decibar 2014-04-16T08:42:57.930Z,1397637777.930 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:43:02.904Z,1397637782.904 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:43:02.917Z,1397637782.917 [Default:CallIridium] Running Loop=1 2014-04-16T08:43:02.917Z,1397637782.917 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2014-04-16T08:43:02.917Z,1397637782.917 [Default:CallIridium:A] Running Loop=1 2014-04-16T08:43:02.920Z,1397637782.920 [Default:CallIridium:A] Stopped 2014-04-16T08:43:02.920Z,1397637782.920 [Default:CallIridium:B] Running Loop=1 2014-04-16T08:43:02.920Z,1397637782.920 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2014-04-16T08:43:08.003Z,1397637788.003 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T08:43:08.020Z,1397637788.020 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2014-04-16T08:43:08.020Z,1397637788.020 [DVL_micro] Data Fault, FailCount= 1 2014-04-16T08:43:08.020Z,1397637788.020 [DVL_micro](ERROR): Data Fault 2014-04-16T08:43:08.054Z,1397637788.054 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:43:08.081Z,1397637788.081 [Default:Iridium] Running Loop=1 2014-04-16T08:43:08.081Z,1397637788.081 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2014-04-16T08:43:08.081Z,1397637788.081 [Default:Iridium:A.SetSpeed] Running Loop=1 2014-04-16T08:43:08.081Z,1397637788.081 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2014-04-16T08:43:08.081Z,1397637788.081 [Default:Iridium:B.GoToSurface] Running Loop=1 2014-04-16T08:43:08.081Z,1397637788.081 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-16T08:43:08.082Z,1397637788.082 [Default:Iridium:B.GoToSurface] Stopped 2014-04-16T08:43:08.086Z,1397637788.086 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-16T08:43:08.086Z,1397637788.086 [Default:Iridium:Read_Iridium] Running Loop=1 2014-04-16T08:43:08.087Z,1397637788.087 [Default:GPS] Running Loop=1 2014-04-16T08:43:08.087Z,1397637788.087 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2014-04-16T08:43:08.087Z,1397637788.087 [Default:GPS:A.SetSpeed] Running Loop=1 2014-04-16T08:43:08.087Z,1397637788.087 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2014-04-16T08:43:08.087Z,1397637788.087 [Default:GPS:B.GoToSurface] Running Loop=1 2014-04-16T08:43:08.087Z,1397637788.087 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-16T08:43:08.088Z,1397637788.088 [Default:GPS:B.GoToSurface] Stopped 2014-04-16T08:43:08.088Z,1397637788.088 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-16T08:43:08.089Z,1397637788.089 [Default:GPS:Read_GPS] Running Loop=1 2014-04-16T08:43:08.115Z,1397637788.115 [CBIT](ERROR): Data Fault in component: DVL_micro 2014-04-16T08:43:08.864Z,1397637788.864 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T08:43:08.864Z,1397637788.864 [DataOverHttps](DEBUG): sslConnect 2014-04-16T08:43:08.865Z,1397637788.865 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:43:08.940Z,1397637788.940 [DVL_micro](INFO): uninitialize:Powering down 2014-04-16T08:43:08.957Z,1397637788.957 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T08:43:10.328Z,1397637790.328 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T08:43:11.327Z,1397637791.327 [DVL_micro](FAULT): LCB fault: Software Overcurrent. 2014-04-16T08:43:11.327Z,1397637791.327 [DVL_micro] Hardware Fault, FailCount= 1 2014-04-16T08:43:11.327Z,1397637791.327 [DVL_micro](ERROR): Hardware Fault 2014-04-16T08:43:11.328Z,1397637791.328 [NAL9602](INFO): Powering up 2014-04