2014-04-16T16:54:12.700Z,1397667252.700 [Supervisor](DEBUG): Initializing supervisor. 2014-04-16T16:54:12.703Z,1397667252.703 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0 2014-04-16T16:54:12.703Z,1397667252.703 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2014-04-16T16:54:12.704Z,1397667252.704 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0 2014-04-16T16:54:12.708Z,1397667252.708 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2014-04-16T16:54:12.719Z,1397667252.719 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2014-04-16T16:54:12.720Z,1397667252.720 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0 2014-04-16T16:54:12.721Z,1397667252.721 [ComponentRegistry](DEBUG): SyncComponent "logger" handled in the control thread. 2014-04-16T16:54:12.723Z,1397667252.723 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2014-04-16T16:54:12.723Z,1397667252.723 [Supervisor](INFO): Looking for Config files in directory: Config/ 2014-04-16T16:54:12.724Z,1397667252.724 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2014-04-16T16:54:13.091Z,1397667253.091 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2014-04-16T16:54:13.092Z,1397667253.092 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2014-04-16T16:54:13.373Z,1397667253.373 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2014-04-16T16:54:13.373Z,1397667253.373 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2014-04-16T16:54:13.466Z,1397667253.466 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2014-04-16T16:54:13.467Z,1397667253.467 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2014-04-16T16:54:13.666Z,1397667253.666 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2014-04-16T16:54:13.667Z,1397667253.667 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2014-04-16T16:54:13.832Z,1397667253.832 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2014-04-16T16:54:13.833Z,1397667253.833 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2014-04-16T16:54:14.136Z,1397667254.136 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2014-04-16T16:54:14.137Z,1397667254.137 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2014-04-16T16:54:14.327Z,1397667254.327 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2014-04-16T16:54:14.327Z,1397667254.327 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2014-04-16T16:54:14.670Z,1397667254.670 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2014-04-16T16:54:14.671Z,1397667254.671 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2014-04-16T16:54:14.786Z,1397667254.786 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2014-04-16T16:54:14.787Z,1397667254.787 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2014-04-16T16:54:15.289Z,1397667255.289 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2014-04-16T16:54:15.290Z,1397667255.290 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2014-04-16T16:54:15.408Z,1397667255.408 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2014-04-16T16:54:15.409Z,1397667255.409 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2014-04-16T16:54:15.503Z,1397667255.503 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2014-04-16T16:54:15.617Z,1397667255.617 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2014-04-16T16:54:15.617Z,1397667255.617 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2014-04-16T16:54:15.728Z,1397667255.728 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2014-04-16T16:54:15.729Z,1397667255.729 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2014-04-16T16:54:15.875Z,1397667255.875 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2014-04-16T16:54:15.878Z,1397667255.878 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2014-04-16T16:54:15.878Z,1397667255.878 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2014-04-16T16:54:15.992Z,1397667255.992 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2014-04-16T16:54:16.129Z,1397667256.129 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2014-04-16T16:54:16.233Z,1397667256.233 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2014-04-16T16:54:16.332Z,1397667256.332 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2014-04-16T16:54:16.493Z,1397667256.493 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2014-04-16T16:54:16.617Z,1397667256.617 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2014-04-16T16:54:16.710Z,1397667256.710 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2014-04-16T16:54:16.821Z,1397667256.821 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2014-04-16T16:54:16.930Z,1397667256.930 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/LOGIN/ 2014-04-16T16:54:16.930Z,1397667256.930 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2014-04-16T16:54:16.932Z,1397667256.932 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2014-04-16T16:54:17.280Z,1397667257.280 [AHRS_sp3003D] Loaded 2014-04-16T16:54:17.280Z,1397667257.280 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread. 2014-04-16T16:54:17.580Z,1397667257.580 [Batt_Ocean_Server] Loaded 2014-04-16T16:54:17.580Z,1397667257.580 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread. 2014-04-16T16:54:17.654Z,1397667257.654 [DataOverHttps] Loaded 2014-04-16T16:54:17.654Z,1397667257.654 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2014-04-16T16:54:17.667Z,1397667257.667 [Depth_Keller] Loaded 2014-04-16T16:54:17.668Z,1397667257.668 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2014-04-16T16:54:17.673Z,1397667257.673 [DropWeight] Loaded 2014-04-16T16:54:17.673Z,1397667257.673 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2014-04-16T16:54:17.835Z,1397667257.835 [DVL_micro] Loaded 2014-04-16T16:54:17.835Z,1397667257.835 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2014-04-16T16:54:17.938Z,1397667257.938 [NAL9602] Loaded 2014-04-16T16:54:17.938Z,1397667257.938 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2014-04-16T16:54:17.990Z,1397667257.990 [Onboard] Loaded 2014-04-16T16:54:17.991Z,1397667257.991 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2014-04-16T16:54:17.998Z,1397667257.998 [Radio_Freewave] Loaded 2014-04-16T16:54:17.998Z,1397667257.998 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread. 2014-04-16T16:54:18.005Z,1397667258.005 [SCPI] Loaded 2014-04-16T16:54:18.005Z,1397667258.005 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread. 2014-04-16T16:54:18.006Z,1397667258.006 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2014-04-16T16:54:18.007Z,1397667258.007 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2014-04-16T16:54:18.166Z,1397667258.166 [InternalSim] Loaded 2014-04-16T16:54:18.167Z,1397667258.167 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread. 2014-04-16T16:54:18.167Z,1397667258.167 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2014-04-16T16:54:18.168Z,1397667258.168 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2014-04-16T16:54:18.423Z,1397667258.423 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2014-04-16T16:54:18.424Z,1397667258.424 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2014-04-16T16:54:18.430Z,1397667258.430 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator. 2014-04-16T16:54:18.435Z,1397667258.435 [AsyncPiEstimator] Loaded 2014-04-16T16:54:18.435Z,1397667258.435 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread. 2014-04-16T16:54:18.436Z,1397667258.436 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406714E0 2014-04-16T16:54:18.437Z,1397667258.437 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2014-04-16T16:54:18.438Z,1397667258.438 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2014-04-16T16:54:18.520Z,1397667258.520 [DeadReckonUsingMultipleVelocitySources] Loaded 2014-04-16T16:54:18.520Z,1397667258.520 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2014-04-16T16:54:18.566Z,1397667258.566 [DeadReckonWithRespectToWater] Loaded 2014-04-16T16:54:18.567Z,1397667258.567 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToWater" handled in the control thread. 2014-04-16T16:54:18.613Z,1397667258.613 [DeadReckonWithRespectToSeafloor] Loaded 2014-04-16T16:54:18.614Z,1397667258.614 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToSeafloor" handled in the control thread. 2014-04-16T16:54:18.661Z,1397667258.661 [DeadReckonUsingDVLWaterTrack] Loaded 2014-04-16T16:54:18.662Z,1397667258.662 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingDVLWaterTrack" handled in the control thread. 2014-04-16T16:54:18.710Z,1397667258.710 [DeadReckonUsingCompactModelForecast] Loaded 2014-04-16T16:54:18.711Z,1397667258.711 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingCompactModelForecast" handled in the control thread. 2014-04-16T16:54:18.727Z,1397667258.727 [NavChart] Loaded 2014-04-16T16:54:18.727Z,1397667258.727 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2014-04-16T16:54:18.732Z,1397667258.732 [UniversalFixResidualReporter] Loaded 2014-04-16T16:54:18.732Z,1397667258.732 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2014-04-16T16:54:18.732Z,1397667258.732 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2014-04-16T16:54:18.733Z,1397667258.733 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2014-04-16T16:54:18.781Z,1397667258.781 [VerticalControl](DEBUG): Construct VerticalControl. 2014-04-16T16:54:18.892Z,1397667258.892 [VerticalControl] Loaded 2014-04-16T16:54:18.893Z,1397667258.893 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2014-04-16T16:54:18.893Z,1397667258.893 [HorizontalControl](DEBUG): Construct HorizontalControl. 2014-04-16T16:54:18.962Z,1397667258.962 [HorizontalControl] Loaded 2014-04-16T16:54:18.962Z,1397667258.962 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2014-04-16T16:54:18.963Z,1397667258.963 [SpeedControl](DEBUG): Construct SpeedControl. 2014-04-16T16:54:18.964Z,1397667258.964 [SpeedControl] Loaded 2014-04-16T16:54:18.965Z,1397667258.965 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2014-04-16T16:54:18.965Z,1397667258.965 [LoopControl](DEBUG): Construct LoopControl. 2014-04-16T16:54:18.966Z,1397667258.966 [LoopControl] Loaded 2014-04-16T16:54:18.966Z,1397667258.966 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2014-04-16T16:54:18.967Z,1397667258.967 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2014-04-16T16:54:18.967Z,1397667258.967 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2014-04-16T16:54:19.004Z,1397667259.004 [DepthRateCalculator] Loaded 2014-04-16T16:54:19.004Z,1397667259.004 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2014-04-16T16:54:19.014Z,1397667259.014 [PitchRateCalculator] Loaded 2014-04-16T16:54:19.015Z,1397667259.015 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2014-04-16T16:54:19.033Z,1397667259.033 [SpeedCalculator] Loaded 2014-04-16T16:54:19.034Z,1397667259.034 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2014-04-16T16:54:19.055Z,1397667259.055 [TempGradientCalculator] Loaded 2014-04-16T16:54:19.056Z,1397667259.056 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2014-04-16T16:54:19.061Z,1397667259.061 [YawRateCalculator] Loaded 2014-04-16T16:54:19.061Z,1397667259.061 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2014-04-16T16:54:19.062Z,1397667259.062 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2014-04-16T16:54:19.062Z,1397667259.062 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2014-04-16T16:54:19.166Z,1397667259.166 [CTD_NeilBrown] Loaded 2014-04-16T16:54:19.166Z,1397667259.166 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2014-04-16T16:54:19.167Z,1397667259.167 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 407134E0 2014-04-16T16:54:19.180Z,1397667259.180 [ISUS] Loaded 2014-04-16T16:54:19.181Z,1397667259.181 [ComponentRegistry](DEBUG): SyncComponent "ISUS" handled in the control thread. 2014-04-16T16:54:19.196Z,1397667259.196 [PAR_Licor] Loaded 2014-04-16T16:54:19.196Z,1397667259.196 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2014-04-16T16:54:19.232Z,1397667259.232 [WetLabsBB2FL] Loaded 2014-04-16T16:54:19.233Z,1397667259.233 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2014-04-16T16:54:19.234Z,1397667259.234 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407434E0 2014-04-16T16:54:19.234Z,1397667259.234 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2014-04-16T16:54:19.235Z,1397667259.235 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2014-04-16T16:54:19.329Z,1397667259.329 [SBIT](DEBUG): Construct Startup Built In Test. 2014-04-16T16:54:19.341Z,1397667259.341 [SBIT] Loaded 2014-04-16T16:54:19.341Z,1397667259.341 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2014-04-16T16:54:19.342Z,1397667259.342 [IBIT](DEBUG): Construct Initiated Built In Test. 2014-04-16T16:54:19.355Z,1397667259.355 [IBIT] Loaded 2014-04-16T16:54:19.355Z,1397667259.355 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2014-04-16T16:54:19.357Z,1397667259.357 [CBIT](DEBUG): Construct CBIT Built In Test. 2014-04-16T16:54:19.427Z,1397667259.427 [CBIT] Loaded 2014-04-16T16:54:19.427Z,1397667259.427 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2014-04-16T16:54:19.428Z,1397667259.428 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2014-04-16T16:54:19.428Z,1397667259.428 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2014-04-16T16:54:24.027Z,1397667264.027 [HFRadarModelCalc] Loaded 2014-04-16T16:54:24.028Z,1397667264.028 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread. 2014-04-16T16:54:27.870Z,1397667267.870 [HFRadarCompactModelForecaster] Loaded 2014-04-16T16:54:27.870Z,1397667267.870 [ComponentRegistry](DEBUG): SyncComponent "HFRadarCompactModelForecaster" handled in the control thread. 2014-04-16T16:54:28.729Z,1397667268.729 [HFRCMSpaceInterpolator] Loaded 2014-04-16T16:54:28.730Z,1397667268.730 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSpaceInterpolator" handled in the control thread. 2014-04-16T16:54:28.732Z,1397667268.732 [HFRCMTimeInterpolator] Loaded 2014-04-16T16:54:28.732Z,1397667268.732 [ComponentRegistry](DEBUG): SyncComponent "HFRCMTimeInterpolator" handled in the control thread. 2014-04-16T16:54:28.746Z,1397667268.746 [HFRCMSurfaceCurrentAtVehicleLocation] Loaded 2014-04-16T16:54:28.746Z,1397667268.746 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSurfaceCurrentAtVehicleLocation" handled in the control thread. 2014-04-16T16:54:28.774Z,1397667268.774 [HFRCMVirtualSurfaceDrifter] Loaded 2014-04-16T16:54:28.774Z,1397667268.774 [ComponentRegistry](DEBUG): SyncComponent "HFRCMVirtualSurfaceDrifter" handled in the control thread. 2014-04-16T16:54:28.775Z,1397667268.775 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2014-04-16T16:54:28.775Z,1397667268.775 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2014-04-16T16:54:28.873Z,1397667268.873 [BuoyancyServo] Loaded 2014-04-16T16:54:28.873Z,1397667268.873 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2014-04-16T16:54:28.886Z,1397667268.886 [ElevatorServo] Loaded 2014-04-16T16:54:28.886Z,1397667268.886 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2014-04-16T16:54:28.898Z,1397667268.898 [MassServo] Loaded 2014-04-16T16:54:28.898Z,1397667268.898 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2014-04-16T16:54:28.910Z,1397667268.910 [RudderServo] Loaded 2014-04-16T16:54:28.910Z,1397667268.910 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2014-04-16T16:54:28.922Z,1397667268.922 [ThrusterServo] Loaded 2014-04-16T16:54:28.922Z,1397667268.922 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2014-04-16T16:54:28.923Z,1397667268.923 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2014-04-16T16:54:28.923Z,1397667268.923 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2014-04-16T16:54:28.947Z,1397667268.947 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2014-04-16T16:54:28.949Z,1397667268.949 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2014-04-16T16:54:28.950Z,1397667268.950 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2014-04-16T16:54:28.957Z,1397667268.957 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2014-04-16T16:54:28.958Z,1397667268.958 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A004E0 2014-04-16T16:54:28.963Z,1397667268.963 [Supervisor](DEBUG): Running supervisor. 2014-04-16T16:54:28.964Z,1397667268.964 [CommandLine](INFO): Thread ID is 5318 2014-04-16T16:54:28.967Z,1397667268.967 [controlThread](INFO): Thread ID is 5317 2014-04-16T16:54:28.967Z,1397667268.967 [controlThread](DEBUG): Initializing ControlThread 2014-04-16T16:54:28.967Z,1397667268.967 [CycleStarter](INFO): Thread ID is 5316 2014-04-16T16:54:28.971Z,1397667268.971 [AsyncPiEstimator](INFO): Thread ID is 5393 2014-04-16T16:54:28.971Z,1397667268.971 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator. 2014-04-16T16:54:28.981Z,1397667268.981 [CTD_NeilBrown](INFO): Thread ID is 5394 2014-04-16T16:54:28.981Z,1397667268.981 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown. 2014-04-16T16:54:28.984Z,1397667268.984 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4 2014-04-16T16:54:28.993Z,1397667268.993 [WetLabsBB2FL](INFO): Thread ID is 5395 2014-04-16T16:54:28.994Z,1397667268.994 [WetLabsBB2FL](INFO): Powering down 2014-04-16T16:54:29.013Z,1397667269.013 [NavChartDb](INFO): Thread ID is 5396 2014-04-16T16:54:29.015Z,1397667269.015 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources 2014-04-16T16:54:29.016Z,1397667269.016 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2014-04-16T16:54:29.016Z,1397667269.016 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2014-04-16T16:54:29.017Z,1397667269.017 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2014-04-16T16:54:29.017Z,1397667269.017 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2014-04-16T16:54:29.017Z,1397667269.017 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2014-04-16T16:54:29.017Z,1397667269.017 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2014-04-16T16:54:29.018Z,1397667269.018 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2014-04-16T16:54:29.018Z,1397667269.018 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2014-04-16T16:54:30.517Z,1397667270.517 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized 2014-04-16T16:54:30.547Z,1397667270.547 [InternalSim](DEBUG): InternalSim initializing... 2014-04-16T16:54:30.621Z,1397667270.621 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2014-04-16T16:54:30.622Z,1397667270.622 [DeadReckonWithRespectToWater](DEBUG): Initializing DeadReckonWithRespectToWater component. 2014-04-16T16:54:30.622Z,1397667270.622 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component. 2014-04-16T16:54:30.623Z,1397667270.623 [DeadReckonUsingDVLWaterTrack](DEBUG): Initializing DeadReckonUsingDVLWaterTrack component. 2014-04-16T16:54:30.623Z,1397667270.623 [DeadReckonUsingCompactModelForecast](DEBUG): Initializing DeadReckonUsingCompactModelForecast component. 2014-04-16T16:54:30.624Z,1397667270.624 [NavChart](DEBUG): Initialize NavChart Navigation. 2014-04-16T16:54:30.624Z,1397667270.624 [UniversalFixResidualReporter](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2014-04-16T16:54:30.628Z,1397667270.628 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2014-04-16T16:54:30.630Z,1397667270.630 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2014-04-16T16:54:30.631Z,1397667270.631 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2014-04-16T16:54:30.632Z,1397667270.632 [LoopControl](DEBUG): Initialize LoopControlComponent. 2014-04-16T16:54:30.632Z,1397667270.632 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2014-04-16T16:54:30.632Z,1397667270.632 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2014-04-16T16:54:30.633Z,1397667270.633 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2014-04-16T16:54:30.633Z,1397667270.633 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2014-04-16T16:54:30.634Z,1397667270.634 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2014-04-16T16:54:30.635Z,1397667270.635 [SBIT](INFO): Initialize SBIT Component. 2014-04-16T16:54:30.636Z,1397667270.636 [SBIT](IMPORTANT): Tethys CM Info: $Rev:11220 2014-04-16T16:54:30.636Z,1397667270.636 [SBIT](IMPORTANT): Kernel Release:2.6.27.8 2014-04-16T16:54:30.644Z,1397667270.644 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014 2014-04-16T16:54:30.644Z,1397667270.644 [IBIT](INFO): Initialize IBIT Component. 2014-04-16T16:54:30.650Z,1397667270.650 [CBIT](DEBUG): Initialize CBIT Component. 2014-04-16T16:54:30.650Z,1397667270.650 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL. 2014-04-16T16:54:30.651Z,1397667270.651 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2014-04-16T16:54:30.678Z,1397667270.678 [HFRCMSpaceInterpolator](DEBUG): Initializing HFRCMSpaceInterpolator component. 2014-04-16T16:54:30.679Z,1397667270.679 [HFRCMTimeInterpolator](DEBUG): Initializing HFRCMTimeInterpolator component. 2014-04-16T16:54:30.679Z,1397667270.679 [HFRCMSurfaceCurrentAtVehicleLocation](DEBUG): Initializing HFRCMSurfaceCurrentAtVehicleLocation component. 2014-04-16T16:54:30.680Z,1397667270.680 [HFRCMVirtualSurfaceDrifter](DEBUG): Initializing HFRCMVirtualSurfaceDrifter component. 2014-04-16T16:54:30.682Z,1397667270.682 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2014-04-16T16:54:30.697Z,1397667270.697 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-16T16:54:30.715Z,1397667270.715 [MissionManager](DEBUG): 2014-04-16T16:54:30.716Z,1397667270.716 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2014-04-16T16:54:30.772Z,1397667270.772 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool 2014-04-16T16:54:30.778Z,1397667270.778 [Default:GPS:A.SetSpeed](DEBUG): Construct. 2014-04-16T16:54:30.786Z,1397667270.786 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-16T16:54:30.803Z,1397667270.803 [Default:Iridium:A.SetSpeed](DEBUG): Construct. 2014-04-16T16:54:30.811Z,1397667270.811 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-16T16:54:30.826Z,1397667270.826 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2014-04-16T16:54:30.844Z,1397667270.844 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Construct. 2014-04-16T16:54:30.852Z,1397667270.852 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-16T16:54:30.868Z,1397667270.868 [MissionManager](DEBUG): 400 400 Burn 300 Dropped drop weight due to communications timeout 5.0 1.0 5 2014-04-16T16:54:30.874Z,1397667270.874 [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-16T16:54:30.923Z,1397667270.923 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2014-04-16T16:54:30.948Z,1397667270.948 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T16:54:31.095Z,1397667271.095 [DVL_micro](INFO): Initializing 2014-04-16T16:54:31.108Z,1397667271.108 [NAL9602](INFO): Powering up NAL9602 2014-04-16T16:54:31.178Z,1397667271.178 [Radio_Freewave](INFO): Powering up 2014-04-16T16:54:31.461Z,1397667271.461 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:54:31.626Z,1397667271.626 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2014-04-16T16:54:31.630Z,1397667271.630 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2014-04-16T16:54:31.641Z,1397667271.641 [ElevatorServo](DEBUG): Initializing EZServoServo. 2014-04-16T16:54:31.646Z,1397667271.646 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2014-04-16T16:54:31.653Z,1397667271.653 [MassServo](DEBUG): Initializing EZServoServo. 2014-04-16T16:54:31.658Z,1397667271.658 [MassServo](DEBUG): Initializing MassServo. 2014-04-16T16:54:31.665Z,1397667271.665 [RudderServo](DEBUG): Initializing EZServoServo. 2014-04-16T16:54:31.671Z,1397667271.671 [RudderServo](DEBUG): Initializing RudderServo. 2014-04-16T16:54:31.677Z,1397667271.677 [ThrusterServo](DEBUG): Initializing EZServoServo. 2014-04-16T16:54:31.683Z,1397667271.683 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2014-04-16T16:54:40.757Z,1397667280.757 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T16:54:40.758Z,1397667280.758 [DataOverHttps](DEBUG): sslConnect 2014-04-16T16:54:40.762Z,1397667280.762 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:54:40.823Z,1397667280.823 [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-16T16:54:40.864Z,1397667280.864 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:54:41.783Z,1397667281.783 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:54:42.731Z,1397667282.731 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:54:43.267Z,1397667283.267 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:54:43.270Z,1397667283.270 [DataOverHttps](DEBUG): dataWrite 2014-04-16T16:54:43.270Z,1397667283.270 [DataOverHttps](DEBUG): dataWriting 2014-04-16T16:54:43.272Z,1397667283.272 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-16T16:54:43.393Z,1397667283.393 [NAL9602](INFO): NAL9602 initialized 2014-04-16T16:54:43.445Z,1397667283.445 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:54:44.123Z,1397667284.123 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:54:44.223Z,1397667284.223 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:54:44.729Z,1397667284.729 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:54:44.730Z,1397667284.730 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-16T16:54:44.730Z,1397667284.730 [DataOverHttps](DEBUG): disconnect 2014-04-16T16:54:44.734Z,1397667284.734 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004106 2014-04-16T16:54:44.808Z,1397667284.808 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:54:45.570Z,1397667285.570 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:54:46.464Z,1397667286.464 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:54:46.579Z,1397667286.579 [SBIT](IMPORTANT): Beginning Startup BIT 2014-04-16T16:54:46.582Z,1397667286.582 [CBIT](IMPORTANT): Beginning GF scan 2014-04-16T16:54:47.201Z,1397667287.201 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:54:47.873Z,1397667287.873 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:54:48.499Z,1397667288.499 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:54:49.036Z,1397667289.036 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:54:49.621Z,1397667289.621 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:54:50.263Z,1397667290.263 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:54:51.091Z,1397667291.091 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:54:51.792Z,1397667291.792 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:54:52.365Z,1397667292.365 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:54:52.999Z,1397667292.999 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:54:53.607Z,1397667293.607 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:54:54.212Z,1397667294.212 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:54:54.857Z,1397667294.857 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:54:55.522Z,1397667295.522 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:54:56.225Z,1397667296.225 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:54:56.894Z,1397667296.894 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:54:57.509Z,1397667297.509 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:54:58.098Z,1397667298.098 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:54:58.727Z,1397667298.727 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:54:59.280Z,1397667299.280 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:54:59.870Z,1397667299.870 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:00.446Z,1397667300.446 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:01.104Z,1397667301.104 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:01.752Z,1397667301.752 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:02.385Z,1397667302.385 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:03.374Z,1397667303.374 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:04.019Z,1397667304.019 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:04.592Z,1397667304.592 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:05.197Z,1397667305.197 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:05.859Z,1397667305.859 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:06.573Z,1397667306.573 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:07.244Z,1397667307.244 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:07.801Z,1397667307.801 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:08.410Z,1397667308.410 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:09.039Z,1397667309.039 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:09.624Z,1397667309.624 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:10.177Z,1397667310.177 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:10.702Z,1397667310.702 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:11.395Z,1397667311.395 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:11.000Z,1397667312.000 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:12.696Z,1397667312.696 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:13.246Z,1397667313.246 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:13.829Z,1397667313.829 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:13.897Z,1397667313.897 [CBIT](IMPORTANT): No ground fault detected 2014-04-16T16:55:14.360Z,1397667314.360 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:14.868Z,1397667314.868 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:15.393Z,1397667315.393 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:16.011Z,1397667316.011 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:16.604Z,1397667316.604 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:17.133Z,1397667317.133 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:17.550Z,1397667317.550 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:17.962Z,1397667317.962 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:18.375Z,1397667318.375 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:18.807Z,1397667318.807 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:19.288Z,1397667319.288 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:19.717Z,1397667319.717 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:20.121Z,1397667320.121 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:20.538Z,1397667320.538 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:20.947Z,1397667320.947 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:21.364Z,1397667321.364 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:21.850Z,1397667321.850 [NAL9602](INFO): SBD MO Status=2, MOMSN=26190, MT Status=2, MTMSN=0 2014-04-16T16:55:21.850Z,1397667321.850 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2014-04-16T16:55:21.864Z,1397667321.864 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:22.379Z,1397667322.379 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:22.802Z,1397667322.802 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:23.214Z,1397667323.214 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:23.627Z,1397667323.627 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:24.048Z,1397667324.048 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:24.460Z,1397667324.460 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:24.884Z,1397667324.884 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:25.348Z,1397667325.348 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:25.833Z,1397667325.833 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:26.243Z,1397667326.243 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:26.709Z,1397667326.709 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:27.144Z,1397667327.144 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:27.561Z,1397667327.561 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:27.981Z,1397667327.981 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:28.416Z,1397667328.416 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:28.895Z,1397667328.895 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:29.524Z,1397667329.524 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:30.398Z,1397667330.398 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:30.919Z,1397667330.919 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:31.416Z,1397667331.416 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T16:55:31.453Z,1397667331.453 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:32.077Z,1397667332.077 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T16:55:32.077Z,1397667332.077 [DataOverHttps](DEBUG): sslConnect 2014-04-16T16:55:32.078Z,1397667332.078 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:55:32.100Z,1397667332.100 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:32.723Z,1397667332.723 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:55:33.203Z,1397667333.203 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:33.661Z,1397667333.661 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:55:33.663Z,1397667333.663 [DataOverHttps](DEBUG): dataWrite 2014-04-16T16:55:33.663Z,1397667333.663 [DataOverHttps](DEBUG): dataWriting 2014-04-16T16:55:33.664Z,1397667333.664 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-16T16:55:33.686Z,1397667333.686 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:34.130Z,1397667334.130 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:55:34.156Z,1397667334.156 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:34.611Z,1397667334.611 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:55:34.612Z,1397667334.612 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-16T16:55:34.612Z,1397667334.612 [DataOverHttps](DEBUG): disconnect 2014-04-16T16:55:34.650Z,1397667334.650 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:35.177Z,1397667335.177 [NAL9602](INFO): SBD MO Status=1, MOMSN=26190, MT Status=0, MTMSN=0 2014-04-16T16:55:35.177Z,1397667335.177 [NAL9602](INFO): No messages in MT queue 2014-04-16T16:55:35.191Z,1397667335.191 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:35.670Z,1397667335.670 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:36.137Z,1397667336.137 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:36.542Z,1397667336.542 [NAL9602](IMPORTANT): GPS fix at: 1397667335.00 2014-04-16T16:55:36.558Z,1397667336.558 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:37.110Z,1397667337.110 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:37.592Z,1397667337.592 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:38.127Z,1397667338.127 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:38.766Z,1397667338.766 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:39.317Z,1397667339.317 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:39.780Z,1397667339.780 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:40.235Z,1397667340.235 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:40.670Z,1397667340.670 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:40.688Z,1397667340.688 [SBIT](IMPORTANT): SBIT PASSED 2014-04-16T16:55:41.145Z,1397667341.145 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:41.164Z,1397667341.164 [MissionManager](IMPORTANT): Started mission Startup 2014-04-16T16:55:41.164Z,1397667341.164 [Startup] Running Loop=1 2014-04-16T16:55:41.164Z,1397667341.164 [Startup](INFO): Aggregate::initialize Startup 2014-04-16T16:55:41.164Z,1397667341.164 [Startup:A.GoToSurface] Running Loop=1 2014-04-16T16:55:41.164Z,1397667341.164 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-16T16:55:41.171Z,1397667341.171 [Startup:StartupSatComms] Running Loop=1 2014-04-16T16:55:41.171Z,1397667341.171 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms 2014-04-16T16:55:41.171Z,1397667341.171 [Startup:StartupSatComms:A] Running Loop=1 2014-04-16T16:55:41.772Z,1397667341.772 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:41.784Z,1397667341.784 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2014-04-16T16:55:42.429Z,1397667342.429 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:42.994Z,1397667342.994 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:43.520Z,1397667343.520 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:43.944Z,1397667343.944 [NAL9602](IMPORTANT): GPS fix at: 1397667343.00 2014-04-16T16:55:43.958Z,1397667343.958 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:43.973Z,1397667343.973 [Startup:StartupSatComms:A] Stopped 2014-04-16T16:55:43.973Z,1397667343.973 [Startup:StartupSatComms:B] Running Loop=1 2014-04-16T16:55:44.474Z,1397667344.474 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:44.489Z,1397667344.489 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2014-04-16T16:55:45.576Z,1397667345.576 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T16:55:45.618Z,1397667345.618 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:46.132Z,1397667346.132 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T16:55:46.133Z,1397667346.133 [DataOverHttps](DEBUG): sslConnect 2014-04-16T16:55:46.134Z,1397667346.134 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:55:46.158Z,1397667346.158 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:46.581Z,1397667346.581 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:55:47.106Z,1397667347.106 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:47.585Z,1397667347.585 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:55:47.587Z,1397667347.587 [DataOverHttps](DEBUG): dataWrite 2014-04-16T16:55:47.589Z,1397667347.589 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20140416T083547/Courier0008.lzma 2014-04-16T16:55:47.589Z,1397667347.589 [DataOverHttps](DEBUG): dataWriting 2014-04-16T16:55:47.591Z,1397667347.591 [DataOverHttps](DEBUG): Wrote 474 bytes 2014-04-16T16:55:47.608Z,1397667347.608 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:48.133Z,1397667348.133 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:55:48.156Z,1397667348.156 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:48.580Z,1397667348.580 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:55:48.581Z,1397667348.581 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=true&momsn=775205&filename=Logs%2F20140416T083547%2FCourier0008.lzma 2014-04-16T16:55:48.582Z,1397667348.582 [DataOverHttps](INFO): Moved sent file to Logs/20140416T083547/Courier0008.lzma.bak 2014-04-16T16:55:48.582Z,1397667348.582 [DataOverHttps](INFO): SBD MOMSN=775205 2014-04-16T16:55:48.582Z,1397667348.582 [DataOverHttps](DEBUG): disconnect 2014-04-16T16:55:48.605Z,1397667348.605 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:49.055Z,1397667349.055 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T16:55:49.091Z,1397667349.091 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:49.534Z,1397667349.534 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T16:55:49.534Z,1397667349.534 [DataOverHttps](DEBUG): sslConnect 2014-04-16T16:55:49.535Z,1397667349.535 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:55:49.560Z,1397667349.560 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:50.002Z,1397667350.002 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:55:50.530Z,1397667350.530 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:50.952Z,1397667350.952 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:55:50.954Z,1397667350.954 [DataOverHttps](DEBUG): dataWrite 2014-04-16T16:55:50.954Z,1397667350.954 [DataOverHttps](DEBUG): dataWriting 2014-04-16T16:55:50.955Z,1397667350.955 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-16T16:55:50.979Z,1397667350.979 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:51.434Z,1397667351.434 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:55:51.440Z,1397667351.440 [NAL9602](INFO): Powering down 2014-04-16T16:55:51.460Z,1397667351.460 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:51.955Z,1397667351.955 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:55:51.956Z,1397667351.956 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-16T16:55:51.956Z,1397667351.956 [DataOverHttps](DEBUG): disconnect 2014-04-16T16:55:51.977Z,1397667351.977 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:52.430Z,1397667352.430 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T16:55:52.486Z,1397667352.486 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:52.935Z,1397667352.935 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T16:55:52.935Z,1397667352.935 [DataOverHttps](DEBUG): sslConnect 2014-04-16T16:55:52.936Z,1397667352.936 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:55:52.960Z,1397667352.960 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:53.383Z,1397667353.383 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:55:53.890Z,1397667353.890 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:54.351Z,1397667354.351 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:55:54.353Z,1397667354.353 [DataOverHttps](DEBUG): dataWrite 2014-04-16T16:55:54.356Z,1397667354.356 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20140416T083547/Courier0012.lzma 2014-04-16T16:55:54.356Z,1397667354.356 [DataOverHttps](DEBUG): dataWriting 2014-04-16T16:55:54.360Z,1397667354.360 [DataOverHttps](DEBUG): Wrote 326 bytes 2014-04-16T16:55:54.380Z,1397667354.380 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:54.842Z,1397667354.842 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:55:54.892Z,1397667354.892 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:55.318Z,1397667355.318 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:55:55.319Z,1397667355.319 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=true&momsn=783933&filename=Logs%2F20140416T083547%2FCourier0012.lzma 2014-04-16T16:55:55.320Z,1397667355.320 [DataOverHttps](INFO): Moved sent file to Logs/20140416T083547/Courier0012.lzma.bak 2014-04-16T16:55:55.320Z,1397667355.320 [DataOverHttps](INFO): SBD MOMSN=783933 2014-04-16T16:55:55.321Z,1397667355.321 [DataOverHttps](DEBUG): disconnect 2014-04-16T16:55:55.343Z,1397667355.343 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:55.770Z,1397667355.770 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T16:55:55.812Z,1397667355.812 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:56.256Z,1397667356.256 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T16:55:56.256Z,1397667356.256 [DataOverHttps](DEBUG): sslConnect 2014-04-16T16:55:56.257Z,1397667356.257 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:55:56.281Z,1397667356.281 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:56.697Z,1397667356.697 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:55:57.167Z,1397667357.167 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:57.696Z,1397667357.696 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:55:57.698Z,1397667357.698 [DataOverHttps](DEBUG): dataWrite 2014-04-16T16:55:57.698Z,1397667357.698 [DataOverHttps](DEBUG): dataWriting 2014-04-16T16:55:57.701Z,1397667357.701 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-16T16:55:57.717Z,1397667357.717 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:58.159Z,1397667358.159 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:55:58.184Z,1397667358.184 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:58.600Z,1397667358.600 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:55:58.600Z,1397667358.600 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-16T16:55:58.601Z,1397667358.601 [DataOverHttps](DEBUG): disconnect 2014-04-16T16:55:58.624Z,1397667358.624 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:59.040Z,1397667359.040 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T16:55:59.081Z,1397667359.081 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:59.529Z,1397667359.529 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T16:55:59.529Z,1397667359.529 [DataOverHttps](DEBUG): sslConnect 2014-04-16T16:55:59.530Z,1397667359.530 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:55:59.554Z,1397667359.554 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:55:59.976Z,1397667359.976 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:00.474Z,1397667360.474 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:00.933Z,1397667360.933 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:00.935Z,1397667360.935 [DataOverHttps](DEBUG): dataWrite 2014-04-16T16:56:00.937Z,1397667360.937 [DataOverHttps](INFO): Sending 292 bytes from file Logs/20140416T165412/Courier0000.lzma 2014-04-16T16:56:00.938Z,1397667360.938 [DataOverHttps](DEBUG): dataWriting 2014-04-16T16:56:00.940Z,1397667360.940 [DataOverHttps](DEBUG): Wrote 1005 bytes 2014-04-16T16:56:00.956Z,1397667360.956 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:01.388Z,1397667361.388 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:56:01.413Z,1397667361.413 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:01.830Z,1397667361.830 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:56:01.832Z,1397667361.832 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=true&momsn=783935&filename=Logs%2F20140416T165412%2FCourier0000.lzma 2014-04-16T16:56:01.833Z,1397667361.833 [DataOverHttps](INFO): Moved sent file to Logs/20140416T165412/Courier0000.lzma.bak 2014-04-16T16:56:01.833Z,1397667361.833 [DataOverHttps](INFO): SBD MOMSN=783935 2014-04-16T16:56:01.833Z,1397667361.833 [DataOverHttps](DEBUG): disconnect 2014-04-16T16:56:01.858Z,1397667361.858 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:02.442Z,1397667362.442 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T16:56:02.483Z,1397667362.483 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:02.954Z,1397667362.954 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T16:56:02.955Z,1397667362.955 [DataOverHttps](DEBUG): sslConnect 2014-04-16T16:56:02.956Z,1397667362.956 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:02.982Z,1397667362.982 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:03.395Z,1397667363.395 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:03.865Z,1397667363.865 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:04.334Z,1397667364.334 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:04.336Z,1397667364.336 [DataOverHttps](DEBUG): dataWrite 2014-04-16T16:56:04.337Z,1397667364.337 [DataOverHttps](DEBUG): dataWriting 2014-04-16T16:56:04.338Z,1397667364.338 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-16T16:56:04.354Z,1397667364.354 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:04.805Z,1397667364.805 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:56:04.830Z,1397667364.830 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:05.282Z,1397667365.282 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:56:05.283Z,1397667365.283 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-16T16:56:05.283Z,1397667365.283 [DataOverHttps](DEBUG): disconnect 2014-04-16T16:56:05.335Z,1397667365.335 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:05.775Z,1397667365.775 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T16:56:05.815Z,1397667365.815 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:06.275Z,1397667366.275 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T16:56:06.276Z,1397667366.276 [DataOverHttps](DEBUG): sslConnect 2014-04-16T16:56:06.277Z,1397667366.277 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:06.300Z,1397667366.300 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:06.720Z,1397667366.720 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:07.209Z,1397667367.209 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:07.744Z,1397667367.744 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:07.746Z,1397667367.746 [DataOverHttps](DEBUG): dataWrite 2014-04-16T16:56:07.749Z,1397667367.749 [DataOverHttps](INFO): Sending 467 bytes from file Logs/20140416T083547/Express0009.lzma 2014-04-16T16:56:07.749Z,1397667367.749 [DataOverHttps](DEBUG): dataWriting 2014-04-16T16:56:07.751Z,1397667367.751 [DataOverHttps](DEBUG): Wrote 1449 bytes 2014-04-16T16:56:07.770Z,1397667367.770 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:08.218Z,1397667368.218 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:56:08.244Z,1397667368.244 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:08.663Z,1397667368.663 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:56:08.664Z,1397667368.664 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=true&momsn=783938&filename=Logs%2F20140416T083547%2FExpress0009.lzma 2014-04-16T16:56:08.665Z,1397667368.665 [DataOverHttps](INFO): Moved sent file to Logs/20140416T083547/Express0009.lzma.bak 2014-04-16T16:56:08.665Z,1397667368.665 [DataOverHttps](INFO): SBD MOMSN=783938 2014-04-16T16:56:08.665Z,1397667368.665 [DataOverHttps](DEBUG): disconnect 2014-04-16T16:56:08.688Z,1397667368.688 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:09.108Z,1397667369.108 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T16:56:09.149Z,1397667369.149 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:09.601Z,1397667369.601 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T16:56:09.601Z,1397667369.601 [DataOverHttps](DEBUG): sslConnect 2014-04-16T16:56:09.602Z,1397667369.602 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:09.625Z,1397667369.625 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:10.045Z,1397667370.045 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:10.518Z,1397667370.518 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:10.981Z,1397667370.981 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:10.983Z,1397667370.983 [DataOverHttps](DEBUG): dataWrite 2014-04-16T16:56:10.983Z,1397667370.983 [DataOverHttps](DEBUG): dataWriting 2014-04-16T16:56:10.984Z,1397667370.984 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-16T16:56:11.001Z,1397667371.001 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:11.432Z,1397667371.432 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:56:11.456Z,1397667371.456 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:11.869Z,1397667371.869 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:56:11.870Z,1397667371.870 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-16T16:56:11.870Z,1397667371.870 [DataOverHttps](DEBUG): disconnect 2014-04-16T16:56:11.893Z,1397667371.893 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:12.325Z,1397667372.325 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T16:56:12.367Z,1397667372.367 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:12.872Z,1397667372.872 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T16:56:12.872Z,1397667372.872 [DataOverHttps](DEBUG): sslConnect 2014-04-16T16:56:12.873Z,1397667372.873 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:12.899Z,1397667372.899 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:13.330Z,1397667373.330 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:13.819Z,1397667373.819 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:14.278Z,1397667374.278 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:14.280Z,1397667374.280 [DataOverHttps](DEBUG): dataWrite 2014-04-16T16:56:14.282Z,1397667374.282 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20140416T083547/Express0013.lzma 2014-04-16T16:56:14.282Z,1397667374.282 [DataOverHttps](DEBUG): dataWriting 2014-04-16T16:56:14.283Z,1397667374.283 [DataOverHttps](DEBUG): Wrote 326 bytes 2014-04-16T16:56:14.305Z,1397667374.305 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:14.741Z,1397667374.741 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:56:14.765Z,1397667374.765 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:15.177Z,1397667375.177 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:56:15.178Z,1397667375.178 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=true&momsn=783948&filename=Logs%2F20140416T083547%2FExpress0013.lzma 2014-04-16T16:56:15.179Z,1397667375.179 [DataOverHttps](INFO): Moved sent file to Logs/20140416T083547/Express0013.lzma.bak 2014-04-16T16:56:15.179Z,1397667375.179 [DataOverHttps](INFO): SBD MOMSN=783948 2014-04-16T16:56:15.179Z,1397667375.179 [DataOverHttps](DEBUG): disconnect 2014-04-16T16:56:15.202Z,1397667375.202 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:15.631Z,1397667375.631 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T16:56:15.681Z,1397667375.681 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:16.131Z,1397667376.131 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T16:56:16.131Z,1397667376.131 [DataOverHttps](DEBUG): sslConnect 2014-04-16T16:56:16.132Z,1397667376.132 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:16.156Z,1397667376.156 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:16.575Z,1397667376.575 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:17.053Z,1397667377.053 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:17.515Z,1397667377.515 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:17.517Z,1397667377.517 [DataOverHttps](DEBUG): dataWrite 2014-04-16T16:56:17.517Z,1397667377.517 [DataOverHttps](DEBUG): dataWriting 2014-04-16T16:56:17.518Z,1397667377.518 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-16T16:56:17.542Z,1397667377.542 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:18.024Z,1397667378.024 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:56:18.041Z,1397667378.041 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:18.482Z,1397667378.482 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:56:18.483Z,1397667378.483 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-16T16:56:18.483Z,1397667378.483 [DataOverHttps](DEBUG): disconnect 2014-04-16T16:56:18.507Z,1397667378.507 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:18.923Z,1397667378.923 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T16:56:18.964Z,1397667378.964 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:19.412Z,1397667379.412 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T16:56:19.412Z,1397667379.412 [DataOverHttps](DEBUG): sslConnect 2014-04-16T16:56:19.413Z,1397667379.413 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:19.437Z,1397667379.437 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:19.852Z,1397667379.852 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:20.335Z,1397667380.335 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:20.792Z,1397667380.792 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:20.794Z,1397667380.794 [DataOverHttps](DEBUG): dataWrite 2014-04-16T16:56:20.797Z,1397667380.797 [DataOverHttps](INFO): Sending 712 bytes from file Logs/20140416T165412/Express0001.lzma 2014-04-16T16:56:20.797Z,1397667380.797 [DataOverHttps](DEBUG): dataWriting 2014-04-16T16:56:20.801Z,1397667380.801 [DataOverHttps](DEBUG): Wrote 2086 bytes 2014-04-16T16:56:20.823Z,1397667380.823 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:21.279Z,1397667381.279 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:56:21.366Z,1397667381.366 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:21.779Z,1397667381.779 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:56:21.780Z,1397667381.780 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=true&momsn=783950&filename=Logs%2F20140416T165412%2FExpress0001.lzma 2014-04-16T16:56:21.782Z,1397667381.782 [DataOverHttps](INFO): Moved sent file to Logs/20140416T165412/Express0001.lzma.bak 2014-04-16T16:56:21.782Z,1397667381.782 [DataOverHttps](INFO): SBD MOMSN=783950 2014-04-16T16:56:21.782Z,1397667381.782 [DataOverHttps](DEBUG): disconnect 2014-04-16T16:56:21.808Z,1397667381.808 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:22.238Z,1397667382.238 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T16:56:22.282Z,1397667382.282 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:22.283Z,1397667382.283 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:22.296Z,1397667382.296 [Startup:StartupSatComms:B] Stopped 2014-04-16T16:56:22.296Z,1397667382.296 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2014-04-16T16:56:22.296Z,1397667382.296 [Startup:StartupSatComms] Stopped 2014-04-16T16:56:22.296Z,1397667382.296 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms 2014-04-16T16:56:22.297Z,1397667382.297 [Startup](INFO): Completed Startup 2014-04-16T16:56:22.297Z,1397667382.297 [Startup] Stopped 2014-04-16T16:56:22.298Z,1397667382.298 [Startup](INFO): Aggregate::uninitialize Startup 2014-04-16T16:56:22.298Z,1397667382.298 [Startup:A.GoToSurface] Stopped 2014-04-16T16:56:22.298Z,1397667382.298 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-16T16:56:22.765Z,1397667382.765 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T16:56:22.765Z,1397667382.765 [DataOverHttps](DEBUG): sslConnect 2014-04-16T16:56:22.766Z,1397667382.766 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:22.790Z,1397667382.790 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:22.802Z,1397667382.802 [MissionManager](IMPORTANT): Started mission Default 2014-04-16T16:56:22.802Z,1397667382.802 [Default] Running Loop=1 2014-04-16T16:56:22.802Z,1397667382.802 [Default](INFO): Aggregate::initialize Default 2014-04-16T16:56:22.803Z,1397667382.803 [Default:Iridium] Running Loop=1 2014-04-16T16:56:22.803Z,1397667382.803 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2014-04-16T16:56:22.803Z,1397667382.803 [Default:Iridium:A.SetSpeed] Running Loop=1 2014-04-16T16:56:22.803Z,1397667382.803 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2014-04-16T16:56:22.803Z,1397667382.803 [Default:Iridium:B.GoToSurface] Running Loop=1 2014-04-16T16:56:22.803Z,1397667382.803 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-16T16:56:22.809Z,1397667382.809 [Default:Iridium:B.GoToSurface] Stopped 2014-04-16T16:56:22.809Z,1397667382.809 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-16T16:56:22.809Z,1397667382.809 [Default:Iridium:Read_Iridium] Running Loop=1 2014-04-16T16:56:22.809Z,1397667382.809 [Default:Iridium:A.SetSpeed] Running Loop=1 2014-04-16T16:56:22.815Z,1397667382.815 [Default:GPS] Running Loop=1 2014-04-16T16:56:22.815Z,1397667382.815 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2014-04-16T16:56:22.815Z,1397667382.815 [Default:GPS:A.SetSpeed] Running Loop=1 2014-04-16T16:56:22.815Z,1397667382.815 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2014-04-16T16:56:22.815Z,1397667382.815 [Default:GPS:B.GoToSurface] Running Loop=1 2014-04-16T16:56:22.815Z,1397667382.815 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-16T16:56:22.821Z,1397667382.821 [Default:GPS:B.GoToSurface] Stopped 2014-04-16T16:56:22.821Z,1397667382.821 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-16T16:56:22.821Z,1397667382.821 [Default:GPS:Read_GPS] Running Loop=1 2014-04-16T16:56:22.821Z,1397667382.821 [Default:GPS:A.SetSpeed] Running Loop=1 2014-04-16T16:56:23.144Z,1397667383.144 [CommandLine](IMPORTANT): got command ibit 2014-04-16T16:56:23.372Z,1397667383.372 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:23.850Z,1397667383.850 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:23.863Z,1397667383.863 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2014-04-16T16:56:23.866Z,1397667383.866 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2014-04-16T16:56:23.876Z,1397667383.876 [IBIT](IMPORTANT): Beginning Initiated BIT 2014-04-16T16:56:23.876Z,1397667383.876 [IBIT](IMPORTANT): Beginning control surface checks. 2014-04-16T16:56:23.878Z,1397667383.878 [CBIT](IMPORTANT): Beginning GF scan 2014-04-16T16:56:24.773Z,1397667384.773 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:24.775Z,1397667384.775 [DataOverHttps](DEBUG): dataWrite 2014-04-16T16:56:24.775Z,1397667384.775 [DataOverHttps](DEBUG): dataWriting 2014-04-16T16:56:24.776Z,1397667384.776 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-16T16:56:24.780Z,1397667384.780 [NAL9602](INFO): Powering up 2014-04-16T16:56:24.793Z,1397667384.793 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:25.225Z,1397667385.225 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:56:25.262Z,1397667385.262 [Radio_Freewave](INFO): Powering down 2014-04-16T16:56:25.284Z,1397667385.284 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:25.818Z,1397667385.818 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:56:25.819Z,1397667385.819 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-16T16:56:25.820Z,1397667385.820 [DataOverHttps](DEBUG): disconnect 2014-04-16T16:56:25.869Z,1397667385.869 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:26.323Z,1397667386.323 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T16:56:26.349Z,1397667386.349 [Radio_Freewave](INFO): Powering up 2014-04-16T16:56:26.370Z,1397667386.370 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:26.918Z,1397667386.918 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T16:56:26.918Z,1397667386.918 [DataOverHttps](DEBUG): sslConnect 2014-04-16T16:56:26.920Z,1397667386.920 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:26.939Z,1397667386.939 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:27.521Z,1397667387.521 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:27.990Z,1397667387.990 [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-16T16:56:28.027Z,1397667388.027 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:28.660Z,1397667388.660 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:28.663Z,1397667388.663 [DataOverHttps](DEBUG): dataWrite 2014-04-16T16:56:28.665Z,1397667388.665 [DataOverHttps](INFO): Sending 47 bytes from file Logs/20140416T165412/Courier0004.lzma 2014-04-16T16:56:28.665Z,1397667388.665 [DataOverHttps](DEBUG): dataWriting 2014-04-16T16:56:28.666Z,1397667388.666 [DataOverHttps](DEBUG): Wrote 397 bytes 2014-04-16T16:56:28.684Z,1397667388.684 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:29.225Z,1397667389.225 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:56:29.288Z,1397667389.288 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:29.832Z,1397667389.832 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:56:29.834Z,1397667389.834 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=true&momsn=783965&filename=Logs%2F20140416T165412%2FCourier0004.lzma 2014-04-16T16:56:29.835Z,1397667389.835 [DataOverHttps](INFO): Moved sent file to Logs/20140416T165412/Courier0004.lzma.bak 2014-04-16T16:56:29.835Z,1397667389.835 [DataOverHttps](INFO): SBD MOMSN=783965 2014-04-16T16:56:29.835Z,1397667389.835 [DataOverHttps](DEBUG): disconnect 2014-04-16T16:56:29.861Z,1397667389.861 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:30.448Z,1397667390.448 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T16:56:30.468Z,1397667390.468 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:30.990Z,1397667390.990 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T16:56:30.990Z,1397667390.990 [DataOverHttps](DEBUG): sslConnect 2014-04-16T16:56:30.991Z,1397667390.991 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:31.014Z,1397667391.014 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:31.519Z,1397667391.519 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:31.997Z,1397667391.997 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:32.508Z,1397667392.508 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:32.510Z,1397667392.510 [DataOverHttps](DEBUG): dataWrite 2014-04-16T16:56:32.510Z,1397667392.510 [DataOverHttps](DEBUG): dataWriting 2014-04-16T16:56:32.512Z,1397667392.512 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-16T16:56:32.553Z,1397667392.553 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:33.143Z,1397667393.143 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:56:33.166Z,1397667393.166 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:33.720Z,1397667393.720 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:56:33.721Z,1397667393.721 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-16T16:56:33.721Z,1397667393.721 [DataOverHttps](DEBUG): disconnect 2014-04-16T16:56:33.739Z,1397667393.739 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:34.255Z,1397667394.255 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T16:56:34.280Z,1397667394.280 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:34.788Z,1397667394.788 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T16:56:34.788Z,1397667394.788 [DataOverHttps](DEBUG): sslConnect 2014-04-16T16:56:34.789Z,1397667394.789 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:34.813Z,1397667394.813 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:35.313Z,1397667395.313 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:35.839Z,1397667395.839 [NAL9602](INFO): NAL9602 initialized 2014-04-16T16:56:35.857Z,1397667395.857 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:36.410Z,1397667396.410 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:36.412Z,1397667396.412 [DataOverHttps](DEBUG): dataWrite 2014-04-16T16:56:36.414Z,1397667396.414 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20140416T165412/Express0005.lzma 2014-04-16T16:56:36.415Z,1397667396.415 [DataOverHttps](DEBUG): dataWriting 2014-04-16T16:56:36.417Z,1397667396.417 [DataOverHttps](DEBUG): Wrote 788 bytes 2014-04-16T16:56:36.440Z,1397667396.440 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:36.976Z,1397667396.976 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:56:37.019Z,1397667397.019 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:37.532Z,1397667397.532 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:56:37.533Z,1397667397.533 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=true&momsn=783967&filename=Logs%2F20140416T165412%2FExpress0005.lzma 2014-04-16T16:56:37.534Z,1397667397.534 [DataOverHttps](INFO): Moved sent file to Logs/20140416T165412/Express0005.lzma.bak 2014-04-16T16:56:37.534Z,1397667397.534 [DataOverHttps](INFO): SBD MOMSN=783967 2014-04-16T16:56:37.534Z,1397667397.534 [DataOverHttps](DEBUG): disconnect 2014-04-16T16:56:37.576Z,1397667397.576 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:38.098Z,1397667398.098 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T16:56:38.145Z,1397667398.145 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:38.147Z,1397667398.147 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:38.720Z,1397667398.720 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T16:56:38.720Z,1397667398.720 [DataOverHttps](DEBUG): sslConnect 2014-04-16T16:56:38.721Z,1397667398.721 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:38.742Z,1397667398.742 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:38.743Z,1397667398.743 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:39.323Z,1397667399.323 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:39.844Z,1397667399.844 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:39.845Z,1397667399.845 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:40.451Z,1397667400.451 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:40.453Z,1397667400.453 [DataOverHttps](DEBUG): dataWrite 2014-04-16T16:56:40.453Z,1397667400.453 [DataOverHttps](DEBUG): dataWriting 2014-04-16T16:56:40.459Z,1397667400.459 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-16T16:56:40.476Z,1397667400.476 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:40.477Z,1397667400.477 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:40.998Z,1397667400.998 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:56:41.024Z,1397667401.024 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:41.027Z,1397667401.027 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:41.539Z,1397667401.539 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:56:41.540Z,1397667401.540 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-16T16:56:41.540Z,1397667401.540 [DataOverHttps](DEBUG): disconnect 2014-04-16T16:56:41.565Z,1397667401.565 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:41.566Z,1397667401.566 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:42.024Z,1397667402.024 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T16:56:42.049Z,1397667402.049 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:42.050Z,1397667402.050 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:42.604Z,1397667402.604 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T16:56:42.605Z,1397667402.605 [DataOverHttps](DEBUG): sslConnect 2014-04-16T16:56:42.606Z,1397667402.606 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:42.630Z,1397667402.630 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:42.631Z,1397667402.631 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:43.223Z,1397667403.223 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:43.718Z,1397667403.718 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:43.719Z,1397667403.719 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:44.315Z,1397667404.315 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:44.318Z,1397667404.318 [DataOverHttps](DEBUG): dataWrite 2014-04-16T16:56:44.319Z,1397667404.319 [DataOverHttps](DEBUG): dataWriting 2014-04-16T16:56:44.320Z,1397667404.320 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-16T16:56:44.338Z,1397667404.338 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:44.339Z,1397667404.339 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:44.840Z,1397667404.840 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:56:44.867Z,1397667404.867 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:44.868Z,1397667404.868 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:45.345Z,1397667405.345 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:56:45.346Z,1397667405.346 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-16T16:56:45.346Z,1397667405.346 [DataOverHttps](DEBUG): disconnect 2014-04-16T16:56:45.371Z,1397667405.371 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:45.372Z,1397667405.372 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:45.865Z,1397667405.865 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T16:56:45.891Z,1397667405.891 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:45.892Z,1397667405.892 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:46.400Z,1397667406.400 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T16:56:46.400Z,1397667406.400 [DataOverHttps](DEBUG): sslConnect 2014-04-16T16:56:46.401Z,1397667406.401 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:46.428Z,1397667406.428 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:46.429Z,1397667406.429 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:46.987Z,1397667406.987 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:47.475Z,1397667407.475 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:47.476Z,1397667407.476 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:47.969Z,1397667407.969 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:47.971Z,1397667407.971 [DataOverHttps](DEBUG): dataWrite 2014-04-16T16:56:47.971Z,1397667407.971 [DataOverHttps](DEBUG): dataWriting 2014-04-16T16:56:47.973Z,1397667407.973 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-16T16:56:47.998Z,1397667407.998 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:47.999Z,1397667407.999 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:48.563Z,1397667408.563 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:56:48.613Z,1397667408.613 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:48.614Z,1397667408.614 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:49.055Z,1397667409.055 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:56:49.056Z,1397667409.056 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-16T16:56:49.056Z,1397667409.056 [DataOverHttps](DEBUG): disconnect 2014-04-16T16:56:49.084Z,1397667409.084 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:49.085Z,1397667409.085 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:49.503Z,1397667409.503 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T16:56:49.528Z,1397667409.528 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:49.529Z,1397667409.529 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:49.981Z,1397667409.981 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T16:56:49.982Z,1397667409.982 [DataOverHttps](DEBUG): sslConnect 2014-04-16T16:56:49.983Z,1397667409.983 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:50.001Z,1397667410.001 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:50.002Z,1397667410.002 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:50.436Z,1397667410.436 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:50.941Z,1397667410.941 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:50.942Z,1397667410.942 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:51.406Z,1397667411.406 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:51.408Z,1397667411.408 [DataOverHttps](DEBUG): dataWrite 2014-04-16T16:56:51.408Z,1397667411.408 [DataOverHttps](DEBUG): dataWriting 2014-04-16T16:56:51.410Z,1397667411.410 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-16T16:56:51.432Z,1397667411.432 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:51.433Z,1397667411.433 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:51.455Z,1397667411.455 [CBIT](IMPORTANT): No ground fault detected 2014-04-16T16:56:51.867Z,1397667411.867 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:56:51.892Z,1397667411.892 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:51.893Z,1397667411.893 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:52.324Z,1397667412.324 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:56:52.325Z,1397667412.325 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-16T16:56:52.325Z,1397667412.325 [DataOverHttps](DEBUG): disconnect 2014-04-16T16:56:52.349Z,1397667412.349 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:52.350Z,1397667412.350 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:52.772Z,1397667412.772 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T16:56:52.797Z,1397667412.797 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:52.798Z,1397667412.798 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:53.251Z,1397667413.251 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T16:56:53.251Z,1397667413.251 [DataOverHttps](DEBUG): sslConnect 2014-04-16T16:56:53.252Z,1397667413.252 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:53.337Z,1397667413.337 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:53.338Z,1397667413.338 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:53.835Z,1397667413.835 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:54.384Z,1397667414.384 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:54.385Z,1397667414.385 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:54.900Z,1397667414.900 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:54.902Z,1397667414.902 [DataOverHttps](DEBUG): dataWrite 2014-04-16T16:56:54.902Z,1397667414.902 [DataOverHttps](DEBUG): dataWriting 2014-04-16T16:56:54.903Z,1397667414.903 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-16T16:56:54.921Z,1397667414.921 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:54.922Z,1397667414.922 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:55.364Z,1397667415.364 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:56:55.389Z,1397667415.389 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:55.390Z,1397667415.390 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:55.813Z,1397667415.813 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:56:55.814Z,1397667415.814 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-16T16:56:55.814Z,1397667415.814 [DataOverHttps](DEBUG): disconnect 2014-04-16T16:56:55.838Z,1397667415.838 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:55.839Z,1397667415.839 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:56.296Z,1397667416.296 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T16:56:56.316Z,1397667416.316 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:56.317Z,1397667416.317 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:56.746Z,1397667416.746 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T16:56:56.746Z,1397667416.746 [DataOverHttps](DEBUG): sslConnect 2014-04-16T16:56:56.747Z,1397667416.747 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:56.771Z,1397667416.771 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:56.772Z,1397667416.772 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:57.199Z,1397667417.199 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:57.713Z,1397667417.713 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:57.714Z,1397667417.714 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:58.181Z,1397667418.181 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:56:58.183Z,1397667418.183 [DataOverHttps](DEBUG): dataWrite 2014-04-16T16:56:58.183Z,1397667418.183 [DataOverHttps](DEBUG): dataWriting 2014-04-16T16:56:58.184Z,1397667418.184 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-16T16:56:58.206Z,1397667418.206 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:58.207Z,1397667418.207 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:58.851Z,1397667418.851 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:56:58.878Z,1397667418.878 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:58.879Z,1397667418.879 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:59.370Z,1397667419.370 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:56:59.371Z,1397667419.371 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-16T16:56:59.371Z,1397667419.371 [DataOverHttps](DEBUG): disconnect 2014-04-16T16:56:59.396Z,1397667419.396 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:59.397Z,1397667419.397 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:56:59.917Z,1397667419.917 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T16:56:59.941Z,1397667419.941 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:56:59.942Z,1397667419.942 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:00.436Z,1397667420.436 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T16:57:00.436Z,1397667420.436 [DataOverHttps](DEBUG): sslConnect 2014-04-16T16:57:00.437Z,1397667420.437 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:57:00.463Z,1397667420.463 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:00.464Z,1397667420.464 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:00.945Z,1397667420.945 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:57:01.441Z,1397667421.441 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:01.442Z,1397667421.442 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:02.075Z,1397667422.075 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:57:02.077Z,1397667422.077 [DataOverHttps](DEBUG): dataWrite 2014-04-16T16:57:02.077Z,1397667422.077 [DataOverHttps](DEBUG): dataWriting 2014-04-16T16:57:02.078Z,1397667422.078 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-16T16:57:02.100Z,1397667422.100 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:02.101Z,1397667422.101 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:02.527Z,1397667422.527 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:57:02.540Z,1397667422.540 [NAL9602](INFO): SBD MO Status=2, MOMSN=26191, MT Status=2, MTMSN=0 2014-04-16T16:57:02.540Z,1397667422.540 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2014-04-16T16:57:02.554Z,1397667422.554 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:02.555Z,1397667422.555 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:03.018Z,1397667423.018 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:57:03.019Z,1397667423.019 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-16T16:57:03.019Z,1397667423.019 [DataOverHttps](DEBUG): disconnect 2014-04-16T16:57:03.064Z,1397667423.064 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:03.065Z,1397667423.065 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:03.497Z,1397667423.497 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T16:57:03.522Z,1397667423.522 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:03.523Z,1397667423.523 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:03.999Z,1397667423.999 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T16:57:03.000Z,1397667424.000 [DataOverHttps](DEBUG): sslConnect 2014-04-16T16:57:04.001Z,1397667424.001 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:57:04.024Z,1397667424.024 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:04.025Z,1397667424.025 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:04.470Z,1397667424.470 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:57:04.976Z,1397667424.976 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:04.977Z,1397667424.977 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:05.436Z,1397667425.436 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:57:05.438Z,1397667425.438 [DataOverHttps](DEBUG): dataWrite 2014-04-16T16:57:05.438Z,1397667425.438 [DataOverHttps](DEBUG): dataWriting 2014-04-16T16:57:05.440Z,1397667425.440 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-16T16:57:05.457Z,1397667425.457 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:05.458Z,1397667425.458 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:05.914Z,1397667425.914 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:57:05.932Z,1397667425.932 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:05.933Z,1397667425.933 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:06.365Z,1397667426.365 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:57:06.366Z,1397667426.366 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-16T16:57:06.366Z,1397667426.366 [DataOverHttps](DEBUG): disconnect 2014-04-16T16:57:06.391Z,1397667426.391 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:06.392Z,1397667426.392 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:06.818Z,1397667426.818 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T16:57:06.877Z,1397667426.877 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:06.878Z,1397667426.878 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:07.299Z,1397667427.299 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T16:57:07.299Z,1397667427.299 [DataOverHttps](DEBUG): sslConnect 2014-04-16T16:57:07.300Z,1397667427.300 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:57:07.327Z,1397667427.327 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:07.328Z,1397667427.328 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:07.747Z,1397667427.747 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:57:08.252Z,1397667428.252 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:08.253Z,1397667428.253 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:08.771Z,1397667428.771 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:57:08.773Z,1397667428.773 [DataOverHttps](DEBUG): dataWrite 2014-04-16T16:57:08.773Z,1397667428.773 [DataOverHttps](DEBUG): dataWriting 2014-04-16T16:57:08.775Z,1397667428.775 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-16T16:57:08.799Z,1397667428.799 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:08.800Z,1397667428.800 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:09.318Z,1397667429.318 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:57:09.371Z,1397667429.371 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:09.372Z,1397667429.372 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:09.799Z,1397667429.799 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:57:09.800Z,1397667429.800 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-16T16:57:09.800Z,1397667429.800 [DataOverHttps](DEBUG): disconnect 2014-04-16T16:57:09.824Z,1397667429.824 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:09.825Z,1397667429.825 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:10.251Z,1397667430.251 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T16:57:10.276Z,1397667430.276 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:10.277Z,1397667430.277 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:10.700Z,1397667430.700 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T16:57:10.700Z,1397667430.700 [DataOverHttps](DEBUG): sslConnect 2014-04-16T16:57:10.701Z,1397667430.701 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:57:10.726Z,1397667430.726 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:10.727Z,1397667430.727 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:11.153Z,1397667431.153 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:57:11.684Z,1397667431.684 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:11.685Z,1397667431.685 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:12.146Z,1397667432.146 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:57:12.148Z,1397667432.148 [DataOverHttps](DEBUG): dataWrite 2014-04-16T16:57:12.149Z,1397667432.149 [DataOverHttps](DEBUG): dataWriting 2014-04-16T16:57:12.150Z,1397667432.150 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-16T16:57:12.168Z,1397667432.168 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:12.169Z,1397667432.169 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:12.621Z,1397667432.621 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:57:12.642Z,1397667432.642 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:12.643Z,1397667432.643 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:13.067Z,1397667433.067 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:57:13.068Z,1397667433.068 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-16T16:57:13.068Z,1397667433.068 [DataOverHttps](DEBUG): disconnect 2014-04-16T16:57:13.093Z,1397667433.093 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:13.094Z,1397667433.094 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:13.508Z,1397667433.508 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T16:57:13.534Z,1397667433.534 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:13.535Z,1397667433.535 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:14.011Z,1397667434.011 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T16:57:14.011Z,1397667434.011 [DataOverHttps](DEBUG): sslConnect 2014-04-16T16:57:14.012Z,1397667434.012 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:57:14.039Z,1397667434.039 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:14.040Z,1397667434.040 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:14.478Z,1397667434.478 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:57:14.998Z,1397667434.998 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:14.999Z,1397667434.999 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:15.456Z,1397667435.456 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:57:15.458Z,1397667435.458 [DataOverHttps](DEBUG): dataWrite 2014-04-16T16:57:15.458Z,1397667435.458 [DataOverHttps](DEBUG): dataWriting 2014-04-16T16:57:15.459Z,1397667435.459 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-16T16:57:15.484Z,1397667435.484 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:15.485Z,1397667435.485 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:15.938Z,1397667435.938 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:57:15.956Z,1397667435.956 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:15.956Z,1397667435.956 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:16.381Z,1397667436.381 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:57:16.382Z,1397667436.382 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-16T16:57:16.382Z,1397667436.382 [DataOverHttps](DEBUG): disconnect 2014-04-16T16:57:16.406Z,1397667436.406 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:16.407Z,1397667436.407 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:16.829Z,1397667436.829 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T16:57:16.854Z,1397667436.854 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:16.857Z,1397667436.857 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:17.278Z,1397667437.278 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T16:57:17.278Z,1397667437.278 [DataOverHttps](DEBUG): sslConnect 2014-04-16T16:57:17.279Z,1397667437.279 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:57:17.292Z,1397667437.292 [NAL9602](INFO): SBD MO Status=0, MOMSN=26191, MT Status=0, MTMSN=0 2014-04-16T16:57:17.292Z,1397667437.292 [NAL9602](INFO): No messages in MT queue 2014-04-16T16:57:17.305Z,1397667437.305 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:17.306Z,1397667437.306 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:17.735Z,1397667437.735 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:57:18.237Z,1397667438.237 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:18.238Z,1397667438.238 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:18.697Z,1397667438.697 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:57:18.699Z,1397667438.699 [DataOverHttps](DEBUG): dataWrite 2014-04-16T16:57:18.699Z,1397667438.699 [DataOverHttps](DEBUG): dataWriting 2014-04-16T16:57:18.700Z,1397667438.700 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-16T16:57:18.736Z,1397667438.736 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:18.737Z,1397667438.737 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:19.191Z,1397667439.191 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#7 STATUS: 65535 2014-04-16T16:57:19.243Z,1397667439.243 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:57:19.251Z,1397667439.251 [NAL9602](IMPORTANT): GPS fix at: 1397667437.00 2014-04-16T16:57:19.267Z,1397667439.267 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:19.268Z,1397667439.268 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:19.291Z,1397667439.291 [IBIT](IMPORTANT): Communications Status: Fix Status: 1 Iridium Signal Strength: 2 Latitude: 33.616695 Longitude: -117.917839 2014-04-16T16:57:19.734Z,1397667439.734 [DataOverHttps](DEBUG): dataRead 2014-04-16T16:57:19.735Z,1397667439.735 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-16T16:57:19.735Z,1397667439.735 [DataOverHttps](DEBUG): disconnect 2014-04-16T16:57:19.778Z,1397667439.778 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:19.779Z,1397667439.779 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:19.802Z,1397667439.802 [IBIT](IMPORTANT): Battery Status: Battery Charge (AH): 238.140015 Voltage: 16.250813 2014-04-16T16:57:19.802Z,1397667439.802 [IBIT](IMPORTANT): batteryCapacityThreshold: 5.000000 Ah 2014-04-16T16:57:19.802Z,1397667439.802 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.500000 V 2014-04-16T16:57:20.227Z,1397667440.227 [DataOverHttps](DEBUG): tcpConnect 2014-04-16T16:57:20.252Z,1397667440.252 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:20.253Z,1397667440.253 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:20.272Z,1397667440.272 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2014-04-16T16:57:20.273Z,1397667440.273 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2014-04-16T16:57:20.273Z,1397667440.273 [IBIT](IMPORTANT): Pressure:11.265132 PSI 2014-04-16T16:57:20.273Z,1397667440.273 [IBIT](IMPORTANT): Humidity:9.065008 % 2014-04-16T16:57:20.691Z,1397667440.691 [DataOverHttps](DEBUG): tcpConnecting 2014-04-16T16:57:20.691Z,1397667440.691 [DataOverHttps](DEBUG): sslConnect 2014-04-16T16:57:20.692Z,1397667440.692 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:57:20.719Z,1397667440.719 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:20.720Z,1397667440.720 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:20.739Z,1397667440.739 [IBIT](IMPORTANT): surfaceThreshold: 0.500000 m 2014-04-16T16:57:20.740Z,1397667440.740 [IBIT](IMPORTANT): buoyancyNeutral: 300.000000 cc 2014-04-16T16:57:20.740Z,1397667440.740 [IBIT](IMPORTANT): massDefault: 0.000000 cm 2014-04-16T16:57:20.740Z,1397667440.740 [IBIT](IMPORTANT): stopDepth: 112.000000 m 2014-04-16T16:57:20.741Z,1397667440.741 [IBIT](IMPORTANT): abortDepth: 130.000000 m 2014-04-16T16:57:20.741Z,1397667440.741 [IBIT](IMPORTANT): IBIT PASSED 2014-04-16T16:57:21.176Z,1397667441.176 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:57:21.714Z,1397667441.714 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2014-04-16T16:57:21.715Z,1397667441.715 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:21.728Z,1397667441.728 [Default:Iridium:Read_Iridium] Stopped 2014-04-16T16:57:21.729Z,1397667441.729 [Default:Iridium](INFO): Completed Default:Iridium 2014-04-16T16:57:21.729Z,1397667441.729 [Default:Iridium] Stopped 2014-04-16T16:57:21.729Z,1397667441.729 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2014-04-16T16:57:21.729Z,1397667441.729 [Default:Iridium:A.SetSpeed] Stopped 2014-04-16T16:57:21.729Z,1397667441.729 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2014-04-16T16:57:21.729Z,1397667441.729 [Default:WaitAtTheSurface] Running Loop=1 2014-04-16T16:57:21.729Z,1397667441.729 [Default:WaitAtTheSurface](INFO): Aggregate::initialize Default:WaitAtTheSurface 2014-04-16T16:57:21.729Z,1397667441.729 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Running Loop=1 2014-04-16T16:57:21.729Z,1397667441.729 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Initialize. 2014-04-16T16:57:21.729Z,1397667441.729 [Default:WaitAtTheSurface:B.GoToSurface] Running Loop=1 2014-04-16T16:57:21.730Z,1397667441.730 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-16T16:57:21.730Z,1397667441.730 [Default:GPS:Read_GPS] Stopped 2014-04-16T16:57:21.730Z,1397667441.730 [Default:GPS:D] Running Loop=1 2014-04-16T16:57:22.251Z,1397667442.251 [DataOverHttps](DEBUG): sslConnecting 2014-04-16T16:57:22.253Z,1397667442.253 [DataOverHttps](DEBUG): dataWrite 2014-04-16T16:57:22.253Z,1397667442.253 [DataOverHttps](DEBUG): dataWriting 2014-04-16T16:57:22.255Z,1397667442.255 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-16T16:57:22.298Z,1397667442.298 [HFRCMTimeInterpolator](DEBUG): no valid forecast 2014-04-16T16:57:22.313Z,1397667442.313 [Default:WaitAtTheSurface:B.GoToSurface] Running Loop=1 2014-04-16T16:57:22.319Z,1397667442.319 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Running Loop=1 2014-04-16T16:57:22.326Z,1397667442.326 [Default:GPS:D] Stopped 2014-04-16T16:57:22.327Z,1397667442.327 [Default:GPS](INFO): Completed Default:GPS 2014-04-16T16:57:22.327Z,1397667442.327 [Default:GPS] Stopped 2014-04-16T16:57:22.327Z,1397667442.327 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2014-04-16T16:57:22.327Z,1397667442.327 [Default:GPS:A.SetSpeed] Stopped 2014-04-16T16:57:22.327Z,1397667442.327 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2014-04-16T16: