2014-04-17T05:31:27.578Z,1397712687.578 [Supervisor](DEBUG): Initializing supervisor.
2014-04-17T05:31:27.584Z,1397712687.584 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0
2014-04-17T05:31:27.584Z,1397712687.584 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2014-04-17T05:31:27.587Z,1397712687.587 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0
2014-04-17T05:31:27.591Z,1397712687.591 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2014-04-17T05:31:27.602Z,1397712687.602 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2014-04-17T05:31:27.604Z,1397712687.604 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0
2014-04-17T05:31:27.605Z,1397712687.605 [ComponentRegistry](DEBUG): SyncComponent "logger" handled in the control thread.
2014-04-17T05:31:27.606Z,1397712687.606 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2014-04-17T05:31:27.607Z,1397712687.607 [Supervisor](INFO): Looking for Config files in directory: Config/
2014-04-17T05:31:27.611Z,1397712687.611 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2014-04-17T05:31:28.029Z,1397712688.029 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2014-04-17T05:31:28.030Z,1397712688.030 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2014-04-17T05:31:28.346Z,1397712688.346 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2014-04-17T05:31:28.347Z,1397712688.347 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2014-04-17T05:31:28.444Z,1397712688.444 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2014-04-17T05:31:28.446Z,1397712688.446 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2014-04-17T05:31:28.675Z,1397712688.675 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2014-04-17T05:31:28.675Z,1397712688.675 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2014-04-17T05:31:28.858Z,1397712688.858 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2014-04-17T05:31:28.861Z,1397712688.861 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2014-04-17T05:31:29.203Z,1397712689.203 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2014-04-17T05:31:29.204Z,1397712689.204 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2014-04-17T05:31:29.410Z,1397712689.410 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2014-04-17T05:31:29.412Z,1397712689.412 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2014-04-17T05:31:29.805Z,1397712689.805 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2014-04-17T05:31:29.807Z,1397712689.807 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2014-04-17T05:31:29.932Z,1397712689.932 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2014-04-17T05:31:29.933Z,1397712689.933 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2014-04-17T05:31:30.494Z,1397712690.494 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2014-04-17T05:31:30.494Z,1397712690.494 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2014-04-17T05:31:30.621Z,1397712690.621 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2014-04-17T05:31:30.622Z,1397712690.622 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2014-04-17T05:31:30.722Z,1397712690.722 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2014-04-17T05:31:30.892Z,1397712690.892 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2014-04-17T05:31:30.894Z,1397712690.894 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2014-04-17T05:31:31.010Z,1397712691.010 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2014-04-17T05:31:31.011Z,1397712691.011 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2014-04-17T05:31:31.166Z,1397712691.166 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2014-04-17T05:31:31.168Z,1397712691.168 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2014-04-17T05:31:31.172Z,1397712691.172 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2014-04-17T05:31:31.291Z,1397712691.291 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2014-04-17T05:31:31.437Z,1397712691.437 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2014-04-17T05:31:31.547Z,1397712691.547 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2014-04-17T05:31:31.651Z,1397712691.651 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2014-04-17T05:31:31.828Z,1397712691.828 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2014-04-17T05:31:31.964Z,1397712691.964 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2014-04-17T05:31:32.064Z,1397712692.064 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2014-04-17T05:31:32.176Z,1397712692.176 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2014-04-17T05:31:32.288Z,1397712692.288 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2014-04-17T05:31:32.291Z,1397712692.291 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2014-04-17T05:31:32.899Z,1397712692.899 [AHRS_sp3003D] Loaded
2014-04-17T05:31:32.899Z,1397712692.899 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2014-04-17T05:31:33.225Z,1397712693.225 [Batt_Ocean_Server] Loaded
2014-04-17T05:31:33.226Z,1397712693.226 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2014-04-17T05:31:33.411Z,1397712693.411 [DataOverHttps] Loaded
2014-04-17T05:31:33.411Z,1397712693.411 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2014-04-17T05:31:33.424Z,1397712693.424 [Depth_Keller] Loaded
2014-04-17T05:31:33.425Z,1397712693.425 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2014-04-17T05:31:33.434Z,1397712693.434 [DropWeight] Loaded
2014-04-17T05:31:33.434Z,1397712693.434 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2014-04-17T05:31:33.586Z,1397712693.586 [DVL_micro] Loaded
2014-04-17T05:31:33.586Z,1397712693.586 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2014-04-17T05:31:33.698Z,1397712693.698 [NAL9602] Loaded
2014-04-17T05:31:33.699Z,1397712693.699 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2014-04-17T05:31:33.755Z,1397712693.755 [Onboard] Loaded
2014-04-17T05:31:33.755Z,1397712693.755 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2014-04-17T05:31:33.766Z,1397712693.766 [Radio_Freewave] Loaded
2014-04-17T05:31:33.766Z,1397712693.766 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread.
2014-04-17T05:31:33.773Z,1397712693.773 [SCPI] Loaded
2014-04-17T05:31:33.774Z,1397712693.774 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread.
2014-04-17T05:31:33.774Z,1397712693.774 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2014-04-17T05:31:33.775Z,1397712693.775 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2014-04-17T05:31:33.990Z,1397712693.990 [InternalSim] Loaded
2014-04-17T05:31:33.990Z,1397712693.990 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2014-04-17T05:31:33.991Z,1397712693.991 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2014-04-17T05:31:33.991Z,1397712693.991 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2014-04-17T05:31:34.290Z,1397712694.290 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2014-04-17T05:31:34.291Z,1397712694.291 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2014-04-17T05:31:34.300Z,1397712694.300 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator.
2014-04-17T05:31:34.305Z,1397712694.305 [AsyncPiEstimator] Loaded
2014-04-17T05:31:34.305Z,1397712694.305 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread.
2014-04-17T05:31:34.310Z,1397712694.310 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406714E0
2014-04-17T05:31:34.311Z,1397712694.311 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2014-04-17T05:31:34.311Z,1397712694.311 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2014-04-17T05:31:34.416Z,1397712694.416 [DeadReckonUsingMultipleVelocitySources] Loaded
2014-04-17T05:31:34.416Z,1397712694.416 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2014-04-17T05:31:34.465Z,1397712694.465 [DeadReckonWithRespectToWater] Loaded
2014-04-17T05:31:34.466Z,1397712694.466 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToWater" handled in the control thread.
2014-04-17T05:31:34.520Z,1397712694.520 [DeadReckonWithRespectToSeafloor] Loaded
2014-04-17T05:31:34.520Z,1397712694.520 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToSeafloor" handled in the control thread.
2014-04-17T05:31:34.572Z,1397712694.572 [DeadReckonUsingDVLWaterTrack] Loaded
2014-04-17T05:31:34.572Z,1397712694.572 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingDVLWaterTrack" handled in the control thread.
2014-04-17T05:31:34.624Z,1397712694.624 [DeadReckonUsingCompactModelForecast] Loaded
2014-04-17T05:31:34.624Z,1397712694.624 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingCompactModelForecast" handled in the control thread.
2014-04-17T05:31:34.641Z,1397712694.641 [NavChart] Loaded
2014-04-17T05:31:34.641Z,1397712694.641 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2014-04-17T05:31:34.649Z,1397712694.649 [UniversalFixResidualReporter] Loaded
2014-04-17T05:31:34.649Z,1397712694.649 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2014-04-17T05:31:34.650Z,1397712694.650 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2014-04-17T05:31:34.651Z,1397712694.651 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2014-04-17T05:31:34.723Z,1397712694.723 [VerticalControl](DEBUG): Construct VerticalControl.
2014-04-17T05:31:34.844Z,1397712694.844 [VerticalControl] Loaded
2014-04-17T05:31:34.845Z,1397712694.845 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2014-04-17T05:31:34.845Z,1397712694.845 [HorizontalControl](DEBUG): Construct HorizontalControl.
2014-04-17T05:31:34.921Z,1397712694.921 [HorizontalControl] Loaded
2014-04-17T05:31:34.921Z,1397712694.921 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2014-04-17T05:31:34.922Z,1397712694.922 [SpeedControl](DEBUG): Construct SpeedControl.
2014-04-17T05:31:34.924Z,1397712694.924 [SpeedControl] Loaded
2014-04-17T05:31:34.924Z,1397712694.924 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2014-04-17T05:31:34.925Z,1397712694.925 [LoopControl](DEBUG): Construct LoopControl.
2014-04-17T05:31:34.925Z,1397712694.925 [LoopControl] Loaded
2014-04-17T05:31:34.925Z,1397712694.925 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2014-04-17T05:31:34.926Z,1397712694.926 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2014-04-17T05:31:34.927Z,1397712694.927 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2014-04-17T05:31:34.957Z,1397712694.957 [DepthRateCalculator] Loaded
2014-04-17T05:31:34.957Z,1397712694.957 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2014-04-17T05:31:34.962Z,1397712694.962 [PitchRateCalculator] Loaded
2014-04-17T05:31:34.963Z,1397712694.963 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2014-04-17T05:31:34.970Z,1397712694.970 [SpeedCalculator] Loaded
2014-04-17T05:31:34.970Z,1397712694.970 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2014-04-17T05:31:34.991Z,1397712694.991 [TempGradientCalculator] Loaded
2014-04-17T05:31:34.991Z,1397712694.991 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2014-04-17T05:31:34.996Z,1397712694.996 [YawRateCalculator] Loaded
2014-04-17T05:31:34.996Z,1397712694.996 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2014-04-17T05:31:34.997Z,1397712694.997 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2014-04-17T05:31:34.998Z,1397712694.998 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2014-04-17T05:31:35.136Z,1397712695.136 [CTD_NeilBrown] Loaded
2014-04-17T05:31:35.137Z,1397712695.137 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2014-04-17T05:31:35.139Z,1397712695.139 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 407134E0
2014-04-17T05:31:35.152Z,1397712695.152 [ISUS] Loaded
2014-04-17T05:31:35.153Z,1397712695.153 [ComponentRegistry](DEBUG): SyncComponent "ISUS" handled in the control thread.
2014-04-17T05:31:35.171Z,1397712695.171 [PAR_Licor] Loaded
2014-04-17T05:31:35.172Z,1397712695.172 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2014-04-17T05:31:35.211Z,1397712695.211 [WetLabsBB2FL] Loaded
2014-04-17T05:31:35.212Z,1397712695.212 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2014-04-17T05:31:35.215Z,1397712695.215 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407434E0
2014-04-17T05:31:35.216Z,1397712695.216 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2014-04-17T05:31:35.218Z,1397712695.218 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2014-04-17T05:31:35.344Z,1397712695.344 [SBIT](DEBUG): Construct Startup Built In Test.
2014-04-17T05:31:35.360Z,1397712695.360 [SBIT] Loaded
2014-04-17T05:31:35.360Z,1397712695.360 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2014-04-17T05:31:35.361Z,1397712695.361 [IBIT](DEBUG): Construct Initiated Built In Test.
2014-04-17T05:31:35.374Z,1397712695.374 [IBIT] Loaded
2014-04-17T05:31:35.374Z,1397712695.374 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2014-04-17T05:31:35.376Z,1397712695.376 [CBIT](DEBUG): Construct CBIT Built In Test.
2014-04-17T05:31:35.453Z,1397712695.453 [CBIT] Loaded
2014-04-17T05:31:35.454Z,1397712695.454 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2014-04-17T05:31:35.454Z,1397712695.454 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2014-04-17T05:31:35.456Z,1397712695.456 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2014-04-17T05:31:41.293Z,1397712701.293 [HFRadarModelCalc] Loaded
2014-04-17T05:31:41.294Z,1397712701.294 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2014-04-17T05:31:46.083Z,1397712706.083 [HFRadarCompactModelForecaster] Loaded
2014-04-17T05:31:46.083Z,1397712706.083 [ComponentRegistry](DEBUG): SyncComponent "HFRadarCompactModelForecaster" handled in the control thread.
2014-04-17T05:31:47.203Z,1397712707.203 [HFRCMSpaceInterpolator] Loaded
2014-04-17T05:31:47.203Z,1397712707.203 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSpaceInterpolator" handled in the control thread.
2014-04-17T05:31:47.205Z,1397712707.205 [HFRCMTimeInterpolator] Loaded
2014-04-17T05:31:47.206Z,1397712707.206 [ComponentRegistry](DEBUG): SyncComponent "HFRCMTimeInterpolator" handled in the control thread.
2014-04-17T05:31:47.219Z,1397712707.219 [HFRCMSurfaceCurrentAtVehicleLocation] Loaded
2014-04-17T05:31:47.219Z,1397712707.219 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSurfaceCurrentAtVehicleLocation" handled in the control thread.
2014-04-17T05:31:47.250Z,1397712707.250 [HFRCMVirtualSurfaceDrifter] Loaded
2014-04-17T05:31:47.250Z,1397712707.250 [ComponentRegistry](DEBUG): SyncComponent "HFRCMVirtualSurfaceDrifter" handled in the control thread.
2014-04-17T05:31:47.251Z,1397712707.251 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2014-04-17T05:31:47.252Z,1397712707.252 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2014-04-17T05:31:47.387Z,1397712707.387 [BuoyancyServo] Loaded
2014-04-17T05:31:47.387Z,1397712707.387 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2014-04-17T05:31:47.400Z,1397712707.400 [ElevatorServo] Loaded
2014-04-17T05:31:47.400Z,1397712707.400 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2014-04-17T05:31:47.411Z,1397712707.411 [MassServo] Loaded
2014-04-17T05:31:47.412Z,1397712707.412 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2014-04-17T05:31:47.428Z,1397712707.428 [RudderServo] Loaded
2014-04-17T05:31:47.428Z,1397712707.428 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2014-04-17T05:31:47.439Z,1397712707.439 [ThrusterServo] Loaded
2014-04-17T05:31:47.440Z,1397712707.440 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2014-04-17T05:31:47.440Z,1397712707.440 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2014-04-17T05:31:47.441Z,1397712707.441 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2014-04-17T05:31:47.480Z,1397712707.480 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2014-04-17T05:31:47.482Z,1397712707.482 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2014-04-17T05:31:47.487Z,1397712707.487 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2014-04-17T05:31:47.493Z,1397712707.493 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2014-04-17T05:31:47.494Z,1397712707.494 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A004E0
2014-04-17T05:31:47.499Z,1397712707.499 [Supervisor](DEBUG): Running supervisor.
2014-04-17T05:31:47.500Z,1397712707.500 [CommandLine](INFO): Thread ID is 778
2014-04-17T05:31:47.507Z,1397712707.507 [controlThread](INFO): Thread ID is 777
2014-04-17T05:31:47.507Z,1397712707.507 [controlThread](DEBUG): Initializing ControlThread
2014-04-17T05:31:47.508Z,1397712707.508 [CycleStarter](INFO): Thread ID is 776
2014-04-17T05:31:47.515Z,1397712707.515 [AsyncPiEstimator](INFO): Thread ID is 851
2014-04-17T05:31:47.515Z,1397712707.515 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator.
2014-04-17T05:31:47.527Z,1397712707.527 [CTD_NeilBrown](INFO): Thread ID is 852
2014-04-17T05:31:47.528Z,1397712707.528 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2014-04-17T05:31:47.529Z,1397712707.529 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2014-04-17T05:31:47.543Z,1397712707.543 [WetLabsBB2FL](INFO): Thread ID is 853
2014-04-17T05:31:47.544Z,1397712707.544 [WetLabsBB2FL](INFO): Powering down
2014-04-17T05:31:47.570Z,1397712707.570 [NavChartDb](INFO): Thread ID is 854
2014-04-17T05:31:47.583Z,1397712707.583 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2014-04-17T05:31:47.584Z,1397712707.584 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2014-04-17T05:31:47.584Z,1397712707.584 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2014-04-17T05:31:47.584Z,1397712707.584 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2014-04-17T05:31:47.585Z,1397712707.585 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2014-04-17T05:31:47.585Z,1397712707.585 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2014-04-17T05:31:47.585Z,1397712707.585 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2014-04-17T05:31:47.585Z,1397712707.585 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2014-04-17T05:31:47.586Z,1397712707.586 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2014-04-17T05:31:48.476Z,1397712708.476 [Batt_Ocean_Server](ERROR): Batt_Ocean_Server A initialization uart error: serial timeout
2014-04-17T05:31:48.477Z,1397712708.477 [Batt_Ocean_Server](ERROR): Ocean Server Batteries failed to initialize. Re-initializing
2014-04-17T05:31:48.477Z,1397712708.477 [Batt_Ocean_Server] Communications Fault, FailCount= 1
2014-04-17T05:31:48.477Z,1397712708.477 [Batt_Ocean_Server](ERROR): Communications Fault
2014-04-17T05:31:48.483Z,1397712708.483 [InternalSim](DEBUG):  InternalSim initializing...
2014-04-17T05:31:48.736Z,1397712708.736 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2014-04-17T05:31:48.737Z,1397712708.737 [DeadReckonWithRespectToWater](DEBUG): Initializing DeadReckonWithRespectToWater component.
2014-04-17T05:31:48.737Z,1397712708.737 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component.
2014-04-17T05:31:48.738Z,1397712708.738 [DeadReckonUsingDVLWaterTrack](DEBUG): Initializing DeadReckonUsingDVLWaterTrack component.
2014-04-17T05:31:48.738Z,1397712708.738 [DeadReckonUsingCompactModelForecast](DEBUG): Initializing DeadReckonUsingCompactModelForecast component.
2014-04-17T05:31:48.739Z,1397712708.739 [NavChart](DEBUG): Initialize NavChart Navigation.
2014-04-17T05:31:48.739Z,1397712708.739 [UniversalFixResidualReporter](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2014-04-17T05:31:48.739Z,1397712708.739 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2014-04-17T05:31:48.753Z,1397712708.753 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2014-04-17T05:31:48.753Z,1397712708.753 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2014-04-17T05:31:48.754Z,1397712708.754 [LoopControl](DEBUG): Initialize LoopControlComponent.
2014-04-17T05:31:48.754Z,1397712708.754 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2014-04-17T05:31:48.755Z,1397712708.755 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2014-04-17T05:31:48.755Z,1397712708.755 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2014-04-17T05:31:48.755Z,1397712708.755 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2014-04-17T05:31:48.756Z,1397712708.756 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2014-04-17T05:31:48.761Z,1397712708.761 [SBIT](INFO): Initialize SBIT Component.
2014-04-17T05:31:48.761Z,1397712708.761 [SBIT](IMPORTANT): Tethys CM Info: 
 $Rev:11220
2014-04-17T05:31:48.762Z,1397712708.762 [SBIT](IMPORTANT): Kernel Release:2.6.27.8
2014-04-17T05:31:48.762Z,1397712708.762 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2014-04-17T05:31:48.763Z,1397712708.763 [IBIT](INFO): Initialize IBIT Component.
2014-04-17T05:31:48.763Z,1397712708.763 [CBIT](DEBUG): Initialize CBIT Component.
2014-04-17T05:31:48.764Z,1397712708.764 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2014-04-17T05:31:48.764Z,1397712708.764 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2014-04-17T05:31:48.789Z,1397712708.789 [HFRCMSpaceInterpolator](DEBUG): Initializing HFRCMSpaceInterpolator component.
2014-04-17T05:31:48.791Z,1397712708.791 [HFRCMTimeInterpolator](DEBUG): Initializing HFRCMTimeInterpolator component.
2014-04-17T05:31:48.791Z,1397712708.791 [HFRCMSurfaceCurrentAtVehicleLocation](DEBUG): Initializing HFRCMSurfaceCurrentAtVehicleLocation component.
2014-04-17T05:31:48.792Z,1397712708.792 [HFRCMVirtualSurfaceDrifter](DEBUG): Initializing HFRCMVirtualSurfaceDrifter component.
2014-04-17T05:31:48.794Z,1397712708.794 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2014-04-17T05:31:48.858Z,1397712708.858 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2014-04-17T05:31:48.867Z,1397712708.867 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://aosn.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2014-04-17T05:31:48.868Z,1397712708.868 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2014-04-17T05:31:48.930Z,1397712708.930 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2014-04-17T05:31:48.949Z,1397712708.949 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2014-04-17T05:31:48.952Z,1397712708.952 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-04-17T05:31:48.973Z,1397712708.973 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2014-04-17T05:31:48.977Z,1397712708.977 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-04-17T05:31:48.996Z,1397712708.996 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2014-04-17T05:31:49.023Z,1397712709.023 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Construct.
2014-04-17T05:31:49.026Z,1397712709.026 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-04-17T05:31:49.043Z,1397712709.043 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
xmlns:Control="Tethys/Control"
xmlns:Guidance="Tethys/Guidance" 
xmlns:Units="Tethys/Units"
xmlns:Universal="Tethys/Universal"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="Tethys http://aosn.mbari.org/tethys/Xml/Tethys.xsd
Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
Id="Default">

    <DefineArg Name="NeedGPS"><True/></DefineArg>

    <Aggregate Id="GPS">

        <When>
            <Arg Name="NeedGPS"/>
        </When>

<!-- Run at high speed -->

        <Guidance:SetSpeed>
            <Parallel/>
            <Setting><Guidance:SetSpeed.period/><Units:millisecond/><Value>400</Value></Setting>
        </Guidance:SetSpeed>

<!-- Get to the surface -->

        <Guidance:GoToSurface>
            <Sequence/>
        </Guidance:GoToSurface>

<!-- Get GPS fix -->

        <ReadDatum Id="Read_GPS">
            <Universal:latitude_fix/>
        </ReadDatum>

        <Assign><Sequence/><Arg Name="NeedGPS"/><False/></Assign>

    </Aggregate>

    <Aggregate Id="Iridium">

        <Sequence/>

<!-- Run at high speed -->

        <Guidance:SetSpeed>
            <Parallel/>
            <Setting><Guidance:SetSpeed.period/><Units:millisecond/><Value>400</Value></Setting>
        </Guidance:SetSpeed>

<!-- Get to the surface -->

        <Guidance:GoToSurface>
            <Sequence/>
        </Guidance:GoToSurface>

<!-- Do data comms -->

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn 300</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped drop weight due to communications timeout</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

    <Aggregate Id="CallIridium">

        <When>
            <Elapsed><Universal:platform_communications/></Elapsed>
            <Gt><Units:minute/><Value>5.0</Value></Gt>
            <And><Universal:platform_conversation/><Eq><True/></Eq></And>
            <Or><Elapsed><Universal:platform_communications/></Elapsed><Gt><Units:hour/><Value>1.0</Value></Gt></Or>
        </When>

        <Assign><Sequence/><Arg Name="NeedGPS"/><True/></Assign>

        <Call RefId="Iridium"/>

    </Aggregate>

    <Aggregate Id="WaitAtTheSurface">

        <Sequence/>

        <Guidance:SetSpeed Id="RunAtLowSpeed">
            <Parallel/>
            <Setting><Guidance:SetSpeed.period/><Units:second/><Value>5</Value></Setting>
        </Guidance:SetSpeed>

        <Guidance:GoToSurface>
            <Parallel/>
        </Guidance:GoToSurface>

    </Aggregate>

</Mission>


2014-04-17T05:31:49.050Z,1397712709.050 [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-17T05:31:49.133Z,1397712709.133 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2014-04-17T05:31:49.148Z,1397712709.148 [DataOverHttps](DEBUG): tcpConnect
2014-04-17T05:31:49.281Z,1397712709.281 [DVL_micro](INFO): Initializing
2014-04-17T05:31:49.296Z,1397712709.296 [NAL9602](INFO): Powering up NAL9602
2014-04-17T05:31:49.374Z,1397712709.374 [Radio_Freewave](INFO): Powering up
2014-04-17T05:31:49.677Z,1397712709.677 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:31:49.858Z,1397712709.858 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2014-04-17T05:31:49.870Z,1397712709.870 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2014-04-17T05:31:49.877Z,1397712709.877 [ElevatorServo](DEBUG): Initializing EZServoServo.
2014-04-17T05:31:49.882Z,1397712709.882 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2014-04-17T05:31:49.889Z,1397712709.889 [MassServo](DEBUG): Initializing EZServoServo.
2014-04-17T05:31:49.894Z,1397712709.894 [MassServo](DEBUG): Initializing MassServo.
2014-04-17T05:31:49.912Z,1397712709.912 [RudderServo](DEBUG): Initializing EZServoServo.
2014-04-17T05:31:49.918Z,1397712709.918 [RudderServo](DEBUG): Initializing RudderServo.
2014-04-17T05:31:49.925Z,1397712709.925 [ThrusterServo](DEBUG): Initializing EZServoServo.
2014-04-17T05:31:49.930Z,1397712709.930 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2014-04-17T05:31:49.961Z,1397712709.961 [CBIT](ERROR): Communications Fault in component: Batt_Ocean_Server
2014-04-17T05:31:49.961Z,1397712709.961 [CBIT](INFO): Clearing failed state for component Batt_Ocean_Server
2014-04-17T05:31:49.962Z,1397712709.962 [Batt_Ocean_Server] No Fault, FailCount= 1
2014-04-17T05:32:00.907Z,1397712720.907 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2014-04-17T05:32:00.932Z,1397712720.932 [DataOverHttps](DEBUG): tcpConnecting
2014-04-17T05:32:00.932Z,1397712720.932 [DataOverHttps](DEBUG): sslConnect
2014-04-17T05:32:00.936Z,1397712720.936 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:32:00.966Z,1397712720.966 [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-17T05:32:01.059Z,1397712721.059 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:02.039Z,1397712722.039 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:32:03.255Z,1397712723.255 [NAL9602](INFO): NAL9602 initialized
2014-04-17T05:32:03.282Z,1397712723.282 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:03.920Z,1397712723.920 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:32:03.923Z,1397712723.923 [DataOverHttps](DEBUG): dataWrite
2014-04-17T05:32:03.923Z,1397712723.923 [DataOverHttps](DEBUG): dataWriting
2014-04-17T05:32:03.925Z,1397712723.925 [DataOverHttps](DEBUG): Wrote 206 bytes
2014-04-17T05:32:04.045Z,1397712724.045 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:04.712Z,1397712724.712 [DataOverHttps](DEBUG): dataRead
2014-04-17T05:32:04.768Z,1397712724.768 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:04.799Z,1397712724.799 [SBIT](IMPORTANT): Beginning Startup BIT
2014-04-17T05:32:04.805Z,1397712724.805 [CBIT](IMPORTANT): Beginning GF scan
2014-04-17T05:32:05.351Z,1397712725.351 [DataOverHttps](DEBUG): dataRead
2014-04-17T05:32:05.351Z,1397712725.351 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false
2014-04-17T05:32:05.352Z,1397712725.352 [DataOverHttps](DEBUG): disconnect
2014-04-17T05:32:05.356Z,1397712725.356 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004206
2014-04-17T05:32:05.485Z,1397712725.485 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:06.458Z,1397712726.458 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:07.401Z,1397712727.401 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:08.125Z,1397712728.125 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:08.841Z,1397712728.841 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:09.562Z,1397712729.562 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:10.268Z,1397712730.268 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:10.974Z,1397712730.974 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:11.821Z,1397712731.821 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:12.558Z,1397712732.558 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:13.253Z,1397712733.253 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:13.873Z,1397712733.873 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:14.479Z,1397712734.479 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:15.235Z,1397712735.235 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:15.876Z,1397712735.876 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:16.635Z,1397712736.635 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:17.373Z,1397712737.373 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:18.021Z,1397712738.021 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:18.788Z,1397712738.788 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:19.407Z,1397712739.407 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:20.118Z,1397712740.118 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:20.725Z,1397712740.725 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:21.873Z,1397712741.873 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:22.692Z,1397712742.692 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:23.313Z,1397712743.313 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:23.950Z,1397712743.950 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:24.623Z,1397712744.623 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:25.324Z,1397712745.324 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:25.955Z,1397712745.955 [NAL9602](INFO): SBD MO Status=0, MOMSN=26346, MT Status=0, MTMSN=0
2014-04-17T05:32:25.955Z,1397712745.955 [NAL9602](INFO): No messages in MT queue
2014-04-17T05:32:25.989Z,1397712745.989 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:26.662Z,1397712746.662 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:27.387Z,1397712747.387 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:28.044Z,1397712748.044 [NAL9602](IMPORTANT): GPS fix at: 1397712746.00
2014-04-17T05:32:28.083Z,1397712748.083 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:28.869Z,1397712748.869 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:29.669Z,1397712749.669 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:30.283Z,1397712750.283 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:30.876Z,1397712750.876 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:31.453Z,1397712751.453 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:32.228Z,1397712752.228 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:33.046Z,1397712753.046 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:33.080Z,1397712753.080 [CBIT](IMPORTANT): No ground fault detected
2014-04-17T05:32:33.594Z,1397712753.594 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:34.275Z,1397712754.275 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:34.819Z,1397712754.819 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:35.331Z,1397712755.331 [NAL9602](INFO): Powering down
2014-04-17T05:32:35.406Z,1397712755.406 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:36.005Z,1397712756.005 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:36.666Z,1397712756.666 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:37.295Z,1397712757.295 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:37.868Z,1397712757.868 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:38.396Z,1397712758.396 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:39.015Z,1397712759.015 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:39.595Z,1397712759.595 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:40.237Z,1397712760.237 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:40.760Z,1397712760.760 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:41.345Z,1397712761.345 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:41.920Z,1397712761.920 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:42.370Z,1397712762.370 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:42.819Z,1397712762.819 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:43.284Z,1397712763.284 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:43.753Z,1397712763.753 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:44.192Z,1397712764.192 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:44.622Z,1397712764.622 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:45.055Z,1397712765.055 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:45.487Z,1397712765.487 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:45.977Z,1397712765.977 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:46.450Z,1397712766.450 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:46.941Z,1397712766.941 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:47.378Z,1397712767.378 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:48.024Z,1397712768.024 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:48.976Z,1397712768.976 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:49.513Z,1397712769.513 [DataOverHttps](DEBUG): tcpConnect
2014-04-17T05:32:49.557Z,1397712769.557 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:50.134Z,1397712770.134 [DataOverHttps](DEBUG): tcpConnecting
2014-04-17T05:32:50.134Z,1397712770.134 [DataOverHttps](DEBUG): sslConnect
2014-04-17T05:32:50.135Z,1397712770.135 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:32:50.156Z,1397712770.156 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:50.701Z,1397712770.701 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:32:51.176Z,1397712771.176 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:51.669Z,1397712771.669 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:32:51.671Z,1397712771.671 [DataOverHttps](DEBUG): dataWrite
2014-04-17T05:32:51.671Z,1397712771.671 [DataOverHttps](DEBUG): dataWriting
2014-04-17T05:32:51.672Z,1397712771.672 [DataOverHttps](DEBUG): Wrote 206 bytes
2014-04-17T05:32:51.694Z,1397712771.694 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:52.215Z,1397712772.215 [DataOverHttps](DEBUG): dataRead
2014-04-17T05:32:52.233Z,1397712772.233 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:52.710Z,1397712772.710 [DataOverHttps](DEBUG): dataRead
2014-04-17T05:32:52.711Z,1397712772.711 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false
2014-04-17T05:32:52.711Z,1397712772.711 [DataOverHttps](DEBUG): disconnect
2014-04-17T05:32:52.756Z,1397712772.756 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:53.312Z,1397712773.312 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:53.809Z,1397712773.809 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:54.281Z,1397712774.281 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:54.714Z,1397712774.714 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:55.147Z,1397712775.147 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:55.619Z,1397712775.619 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:56.075Z,1397712776.075 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:56.548Z,1397712776.548 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:56.978Z,1397712776.978 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:57.456Z,1397712777.456 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:57.939Z,1397712777.939 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:58.384Z,1397712778.384 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:58.816Z,1397712778.816 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:59.270Z,1397712779.270 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:59.289Z,1397712779.289 [SBIT](IMPORTANT): SBIT PASSED
2014-04-17T05:32:59.744Z,1397712779.744 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:32:59.756Z,1397712779.756 [MissionManager](IMPORTANT): Started mission Startup
2014-04-17T05:32:59.757Z,1397712779.757 [Startup] Running Loop=1
2014-04-17T05:32:59.757Z,1397712779.757 [Startup](INFO): Aggregate::initialize Startup
2014-04-17T05:32:59.757Z,1397712779.757 [Startup:A.GoToSurface] Running Loop=1
2014-04-17T05:32:59.757Z,1397712779.757 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-17T05:32:59.763Z,1397712779.763 [Startup:StartupSatComms] Running Loop=1
2014-04-17T05:32:59.764Z,1397712779.764 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2014-04-17T05:32:59.764Z,1397712779.764 [Startup:StartupSatComms:A] Running Loop=1
2014-04-17T05:33:00.247Z,1397712780.247 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:00.259Z,1397712780.259 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2014-04-17T05:33:00.669Z,1397712780.669 [NAL9602](INFO): Powering up
2014-04-17T05:33:00.683Z,1397712780.683 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:01.120Z,1397712781.120 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:01.556Z,1397712781.556 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:01.998Z,1397712781.998 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:02.508Z,1397712782.508 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:03.023Z,1397712783.023 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:03.464Z,1397712783.464 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:03.900Z,1397712783.900 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:04.329Z,1397712784.329 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:04.762Z,1397712784.762 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:05.258Z,1397712785.258 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:05.715Z,1397712785.715 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:06.184Z,1397712786.184 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:06.616Z,1397712786.616 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:07.058Z,1397712787.058 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:07.576Z,1397712787.576 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:08.034Z,1397712788.034 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:08.467Z,1397712788.467 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:08.921Z,1397712788.921 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:09.389Z,1397712789.389 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:09.860Z,1397712789.860 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:10.294Z,1397712790.294 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:10.727Z,1397712790.727 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:11.200Z,1397712791.200 [NAL9602](ERROR): NAL9602 initialize error - Can't enter command mode:
+CIEV:1,1
2014-04-17T05:33:11.201Z,1397712791.201 [NAL9602] Communications Fault, FailCount= 1
2014-04-17T05:33:11.201Z,1397712791.201 [NAL9602](ERROR): Communications Fault
2014-04-17T05:33:11.214Z,1397712791.214 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:11.235Z,1397712791.235 [CBIT](ERROR): Communications Fault in component: NAL9602
2014-04-17T05:33:11.655Z,1397712791.655 [NAL9602](INFO): Powering down
2014-04-17T05:33:11.669Z,1397712791.669 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:12.173Z,1397712792.173 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:12.699Z,1397712792.699 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:12.721Z,1397712792.721 [CBIT](INFO): Clearing failed state for component NAL9602
2014-04-17T05:33:12.721Z,1397712792.721 [NAL9602] No Fault, FailCount= 1
2014-04-17T05:33:13.155Z,1397712793.155 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:13.591Z,1397712793.591 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:14.015Z,1397712794.015 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:14.445Z,1397712794.445 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:14.917Z,1397712794.917 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:15.371Z,1397712795.371 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:15.835Z,1397712795.835 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:16.272Z,1397712796.272 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:16.687Z,1397712796.687 [NAL9602](INFO): Powering up NAL9602
2014-04-17T05:33:16.701Z,1397712796.701 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:17.173Z,1397712797.173 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:17.675Z,1397712797.675 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:18.123Z,1397712798.123 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:18.579Z,1397712798.579 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:19.044Z,1397712799.044 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:19.509Z,1397712799.509 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:19.949Z,1397712799.949 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:20.378Z,1397712800.378 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:20.802Z,1397712800.802 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:21.239Z,1397712801.239 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:21.696Z,1397712801.696 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:22.200Z,1397712802.200 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:22.701Z,1397712802.701 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:23.143Z,1397712803.143 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:23.583Z,1397712803.583 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:24.011Z,1397712804.011 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:24.476Z,1397712804.476 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:24.947Z,1397712804.947 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:25.405Z,1397712805.405 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:25.830Z,1397712805.830 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:26.271Z,1397712806.271 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:26.700Z,1397712806.700 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:27.169Z,1397712807.169 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:27.806Z,1397712807.806 [NAL9602](INFO): NAL9602 initialized
2014-04-17T05:33:27.825Z,1397712807.825 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:28.319Z,1397712808.319 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:28.811Z,1397712808.811 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:29.262Z,1397712809.262 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:29.742Z,1397712809.742 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:30.181Z,1397712810.181 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:30.620Z,1397712810.620 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:31.066Z,1397712811.066 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:31.523Z,1397712811.523 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:32.025Z,1397712812.025 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:32.469Z,1397712812.469 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:32.970Z,1397712812.970 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:33.414Z,1397712813.414 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:33.854Z,1397712813.854 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:34.323Z,1397712814.323 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:34.781Z,1397712814.781 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:35.269Z,1397712815.269 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:35.707Z,1397712815.707 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:36.154Z,1397712816.154 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:36.628Z,1397712816.628 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:37.069Z,1397712817.069 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:37.500Z,1397712817.500 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:38.014Z,1397712818.014 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:38.498Z,1397712818.498 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:39.002Z,1397712819.002 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:39.440Z,1397712819.440 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:39.880Z,1397712819.880 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:40.312Z,1397712820.312 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:40.737Z,1397712820.737 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:41.194Z,1397712821.194 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:41.695Z,1397712821.695 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:42.133Z,1397712822.133 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:42.569Z,1397712822.569 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:43.059Z,1397712823.059 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:43.503Z,1397712823.503 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:43.963Z,1397712823.963 [NAL9602](INFO): SBD MO Status=0, MOMSN=26347, MT Status=0, MTMSN=0
2014-04-17T05:33:43.963Z,1397712823.963 [NAL9602](INFO): No messages in MT queue
2014-04-17T05:33:43.977Z,1397712823.977 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:44.447Z,1397712824.447 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:44.947Z,1397712824.947 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:45.401Z,1397712825.401 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:45.849Z,1397712825.849 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:46.312Z,1397712826.312 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:46.751Z,1397712826.751 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:47.187Z,1397712827.187 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:47.639Z,1397712827.639 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:48.165Z,1397712828.165 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:48.669Z,1397712828.669 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:49.130Z,1397712829.130 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:49.542Z,1397712829.542 [DataOverHttps](DEBUG): tcpConnect
2014-04-17T05:33:49.582Z,1397712829.582 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:49.999Z,1397712829.999 [DataOverHttps](DEBUG): tcpConnecting
2014-04-17T05:33:49.999Z,1397712829.999 [DataOverHttps](DEBUG): sslConnect
2014-04-17T05:33:49.000Z,1397712830.000 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:33:50.018Z,1397712830.018 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:50.436Z,1397712830.436 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:33:50.963Z,1397712830.963 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:51.451Z,1397712831.451 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:33:51.453Z,1397712831.453 [DataOverHttps](DEBUG): dataWrite
2014-04-17T05:33:51.453Z,1397712831.453 [DataOverHttps](DEBUG): dataWriting
2014-04-17T05:33:51.455Z,1397712831.455 [DataOverHttps](DEBUG): Wrote 206 bytes
2014-04-17T05:33:51.473Z,1397712831.473 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:51.902Z,1397712831.902 [DataOverHttps](DEBUG): dataRead
2014-04-17T05:33:51.946Z,1397712831.946 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:52.363Z,1397712832.363 [DataOverHttps](DEBUG): dataRead
2014-04-17T05:33:52.363Z,1397712832.363 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false
2014-04-17T05:33:52.363Z,1397712832.363 [DataOverHttps](DEBUG): disconnect
2014-04-17T05:33:52.401Z,1397712832.401 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:52.858Z,1397712832.858 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:53.388Z,1397712833.388 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:53.841Z,1397712833.841 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:54.322Z,1397712834.322 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:54.804Z,1397712834.804 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:55.255Z,1397712835.255 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:55.725Z,1397712835.725 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:56.161Z,1397712836.161 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:56.597Z,1397712836.597 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:57.027Z,1397712837.027 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:57.497Z,1397712837.497 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:57.959Z,1397712837.959 [NAL9602](IMPORTANT): GPS fix at: 1397712836.00
2014-04-17T05:33:57.973Z,1397712837.973 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:57.988Z,1397712837.988 [Startup:StartupSatComms:A] Stopped
2014-04-17T05:33:57.988Z,1397712837.988 [Startup:StartupSatComms:B] Running Loop=1
2014-04-17T05:33:58.585Z,1397712838.585 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:33:58.600Z,1397712838.600 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2014-04-17T05:33:59.699Z,1397712839.699 [DataOverHttps](DEBUG): tcpConnect
2014-04-17T05:33:59.735Z,1397712839.735 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:00.263Z,1397712840.263 [DataOverHttps](DEBUG): tcpConnecting
2014-04-17T05:34:00.263Z,1397712840.263 [DataOverHttps](DEBUG): sslConnect
2014-04-17T05:34:00.265Z,1397712840.265 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:34:00.322Z,1397712840.322 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:00.882Z,1397712840.882 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:34:01.409Z,1397712841.409 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:01.886Z,1397712841.886 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:34:01.888Z,1397712841.888 [DataOverHttps](DEBUG): dataWrite
2014-04-17T05:34:01.890Z,1397712841.890 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20140416T165412/Courier0008.lzma
2014-04-17T05:34:01.890Z,1397712841.890 [DataOverHttps](DEBUG): dataWriting
2014-04-17T05:34:01.892Z,1397712841.892 [DataOverHttps](DEBUG): Wrote 326 bytes
2014-04-17T05:34:01.914Z,1397712841.914 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:02.338Z,1397712842.338 [DataOverHttps](DEBUG): dataRead
2014-04-17T05:34:02.360Z,1397712842.360 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:02.821Z,1397712842.821 [DataOverHttps](DEBUG): dataRead
2014-04-17T05:34:02.822Z,1397712842.822 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=true&momsn=784521&filename=Logs%2F20140416T165412%2FCourier0008.lzma
2014-04-17T05:34:02.822Z,1397712842.822 [DataOverHttps](INFO): Moved sent file to Logs/20140416T165412/Courier0008.lzma.bak
2014-04-17T05:34:02.823Z,1397712842.823 [DataOverHttps](INFO): SBD MOMSN=784521
2014-04-17T05:34:02.823Z,1397712842.823 [DataOverHttps](DEBUG): disconnect
2014-04-17T05:34:02.847Z,1397712842.847 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:03.449Z,1397712843.449 [DataOverHttps](DEBUG): tcpConnect
2014-04-17T05:34:03.538Z,1397712843.538 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:04.033Z,1397712844.033 [DataOverHttps](DEBUG): tcpConnecting
2014-04-17T05:34:04.033Z,1397712844.033 [DataOverHttps](DEBUG): sslConnect
2014-04-17T05:34:04.034Z,1397712844.034 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:34:04.069Z,1397712844.069 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:04.594Z,1397712844.594 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:34:05.314Z,1397712845.314 [NAL9602](INFO): Powering down
2014-04-17T05:34:05.330Z,1397712845.330 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:05.833Z,1397712845.833 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:34:05.835Z,1397712845.835 [DataOverHttps](DEBUG): dataWrite
2014-04-17T05:34:05.836Z,1397712845.836 [DataOverHttps](DEBUG): dataWriting
2014-04-17T05:34:05.837Z,1397712845.837 [DataOverHttps](DEBUG): Wrote 206 bytes
2014-04-17T05:34:05.856Z,1397712845.856 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:06.324Z,1397712846.324 [DataOverHttps](DEBUG): dataRead
2014-04-17T05:34:06.349Z,1397712846.349 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:06.869Z,1397712846.869 [DataOverHttps](DEBUG): dataRead
2014-04-17T05:34:06.870Z,1397712846.870 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false
2014-04-17T05:34:06.870Z,1397712846.870 [DataOverHttps](DEBUG): disconnect
2014-04-17T05:34:06.889Z,1397712846.889 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:07.314Z,1397712847.314 [DataOverHttps](DEBUG): tcpConnect
2014-04-17T05:34:07.339Z,1397712847.339 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:07.813Z,1397712847.813 [DataOverHttps](DEBUG): tcpConnecting
2014-04-17T05:34:07.813Z,1397712847.813 [DataOverHttps](DEBUG): sslConnect
2014-04-17T05:34:07.814Z,1397712847.814 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:34:07.835Z,1397712847.835 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:08.259Z,1397712848.259 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:34:08.821Z,1397712848.821 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:09.343Z,1397712849.343 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:34:09.345Z,1397712849.345 [DataOverHttps](DEBUG): dataWrite
2014-04-17T05:34:09.347Z,1397712849.347 [DataOverHttps](INFO): Sending 294 bytes from file Logs/20140417T053127/Courier0000.lzma
2014-04-17T05:34:09.347Z,1397712849.347 [DataOverHttps](DEBUG): dataWriting
2014-04-17T05:34:09.349Z,1397712849.349 [DataOverHttps](DEBUG): Wrote 1013 bytes
2014-04-17T05:34:09.366Z,1397712849.366 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:09.826Z,1397712849.826 [DataOverHttps](DEBUG): dataRead
2014-04-17T05:34:09.850Z,1397712849.850 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:10.308Z,1397712850.308 [DataOverHttps](DEBUG): dataRead
2014-04-17T05:34:10.309Z,1397712850.309 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=true&momsn=784523&filename=Logs%2F20140417T053127%2FCourier0000.lzma
2014-04-17T05:34:10.310Z,1397712850.310 [DataOverHttps](INFO): Moved sent file to Logs/20140417T053127/Courier0000.lzma.bak
2014-04-17T05:34:10.310Z,1397712850.310 [DataOverHttps](INFO): SBD MOMSN=784523
2014-04-17T05:34:10.310Z,1397712850.310 [DataOverHttps](DEBUG): disconnect
2014-04-17T05:34:10.329Z,1397712850.329 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:10.914Z,1397712850.914 [DataOverHttps](DEBUG): tcpConnect
2014-04-17T05:34:10.931Z,1397712850.931 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:11.360Z,1397712851.360 [DataOverHttps](DEBUG): tcpConnecting
2014-04-17T05:34:11.360Z,1397712851.360 [DataOverHttps](DEBUG): sslConnect
2014-04-17T05:34:11.361Z,1397712851.361 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:34:11.385Z,1397712851.385 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:11.801Z,1397712851.801 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:34:12.343Z,1397712852.343 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:12.880Z,1397712852.880 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:34:12.882Z,1397712852.882 [DataOverHttps](DEBUG): dataWrite
2014-04-17T05:34:12.882Z,1397712852.882 [DataOverHttps](DEBUG): dataWriting
2014-04-17T05:34:12.884Z,1397712852.884 [DataOverHttps](DEBUG): Wrote 206 bytes
2014-04-17T05:34:12.900Z,1397712852.900 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:13.335Z,1397712853.335 [DataOverHttps](DEBUG): dataRead
2014-04-17T05:34:13.360Z,1397712853.360 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:13.834Z,1397712853.834 [DataOverHttps](DEBUG): dataRead
2014-04-17T05:34:13.835Z,1397712853.835 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false
2014-04-17T05:34:13.835Z,1397712853.835 [DataOverHttps](DEBUG): disconnect
2014-04-17T05:34:13.856Z,1397712853.856 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:14.301Z,1397712854.301 [DataOverHttps](DEBUG): tcpConnect
2014-04-17T05:34:14.318Z,1397712854.318 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:14.771Z,1397712854.771 [DataOverHttps](DEBUG): tcpConnecting
2014-04-17T05:34:14.771Z,1397712854.771 [DataOverHttps](DEBUG): sslConnect
2014-04-17T05:34:14.772Z,1397712854.772 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:34:14.794Z,1397712854.794 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:15.226Z,1397712855.226 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:34:15.727Z,1397712855.727 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:16.196Z,1397712856.196 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:34:16.198Z,1397712856.198 [DataOverHttps](DEBUG): dataWrite
2014-04-17T05:34:16.199Z,1397712856.199 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20140416T165412/Express0009.lzma
2014-04-17T05:34:16.200Z,1397712856.200 [DataOverHttps](DEBUG): dataWriting
2014-04-17T05:34:16.201Z,1397712856.201 [DataOverHttps](DEBUG): Wrote 326 bytes
2014-04-17T05:34:16.218Z,1397712856.218 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:16.640Z,1397712856.640 [DataOverHttps](DEBUG): dataRead
2014-04-17T05:34:16.665Z,1397712856.665 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:17.119Z,1397712857.119 [DataOverHttps](DEBUG): dataRead
2014-04-17T05:34:17.120Z,1397712857.120 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=true&momsn=784527&filename=Logs%2F20140416T165412%2FExpress0009.lzma
2014-04-17T05:34:17.121Z,1397712857.121 [DataOverHttps](INFO): Moved sent file to Logs/20140416T165412/Express0009.lzma.bak
2014-04-17T05:34:17.121Z,1397712857.121 [DataOverHttps](INFO): SBD MOMSN=784527
2014-04-17T05:34:17.121Z,1397712857.121 [DataOverHttps](DEBUG): disconnect
2014-04-17T05:34:17.140Z,1397712857.140 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:17.584Z,1397712857.584 [DataOverHttps](DEBUG): tcpConnect
2014-04-17T05:34:17.601Z,1397712857.601 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:18.018Z,1397712858.018 [DataOverHttps](DEBUG): tcpConnecting
2014-04-17T05:34:18.019Z,1397712858.019 [DataOverHttps](DEBUG): sslConnect
2014-04-17T05:34:18.020Z,1397712858.020 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:34:18.043Z,1397712858.043 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:18.467Z,1397712858.467 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:34:19.014Z,1397712859.014 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:19.555Z,1397712859.555 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:34:19.557Z,1397712859.557 [DataOverHttps](DEBUG): dataWrite
2014-04-17T05:34:19.557Z,1397712859.557 [DataOverHttps](DEBUG): dataWriting
2014-04-17T05:34:19.563Z,1397712859.563 [DataOverHttps](DEBUG): Wrote 206 bytes
2014-04-17T05:34:19.579Z,1397712859.579 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:20.026Z,1397712860.026 [DataOverHttps](DEBUG): dataRead
2014-04-17T05:34:20.050Z,1397712860.050 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:20.466Z,1397712860.466 [DataOverHttps](DEBUG): dataRead
2014-04-17T05:34:20.467Z,1397712860.467 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false
2014-04-17T05:34:20.467Z,1397712860.467 [DataOverHttps](DEBUG): disconnect
2014-04-17T05:34:20.486Z,1397712860.486 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:20.903Z,1397712860.903 [DataOverHttps](DEBUG): tcpConnect
2014-04-17T05:34:20.920Z,1397712860.920 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:21.336Z,1397712861.336 [DataOverHttps](DEBUG): tcpConnecting
2014-04-17T05:34:21.336Z,1397712861.336 [DataOverHttps](DEBUG): sslConnect
2014-04-17T05:34:21.337Z,1397712861.337 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:34:21.360Z,1397712861.360 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:21.780Z,1397712861.780 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:34:22.289Z,1397712862.289 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:22.816Z,1397712862.816 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:34:22.818Z,1397712862.818 [DataOverHttps](DEBUG): dataWrite
2014-04-17T05:34:22.821Z,1397712862.821 [DataOverHttps](INFO): Sending 730 bytes from file Logs/20140417T053127/Express0001.lzma
2014-04-17T05:34:22.821Z,1397712862.821 [DataOverHttps](DEBUG): dataWriting
2014-04-17T05:34:22.825Z,1397712862.825 [DataOverHttps](DEBUG): Wrote 2120 bytes
2014-04-17T05:34:22.843Z,1397712862.843 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:23.287Z,1397712863.287 [DataOverHttps](DEBUG): dataRead
2014-04-17T05:34:23.312Z,1397712863.312 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:23.735Z,1397712863.735 [DataOverHttps](DEBUG): dataRead
2014-04-17T05:34:23.736Z,1397712863.736 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=true&momsn=784529&filename=Logs%2F20140417T053127%2FExpress0001.lzma
2014-04-17T05:34:23.737Z,1397712863.737 [DataOverHttps](INFO): Moved sent file to Logs/20140417T053127/Express0001.lzma.bak
2014-04-17T05:34:23.737Z,1397712863.737 [DataOverHttps](INFO): SBD MOMSN=784529
2014-04-17T05:34:23.737Z,1397712863.737 [DataOverHttps](DEBUG): disconnect
2014-04-17T05:34:23.761Z,1397712863.761 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:24.261Z,1397712864.261 [DataOverHttps](DEBUG): tcpConnect
2014-04-17T05:34:24.282Z,1397712864.282 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients.
2014-04-17T05:34:24.283Z,1397712864.283 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:24.295Z,1397712864.295 [Startup:StartupSatComms:B] Stopped
2014-04-17T05:34:24.296Z,1397712864.296 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2014-04-17T05:34:24.296Z,1397712864.296 [Startup:StartupSatComms] Stopped
2014-04-17T05:34:24.296Z,1397712864.296 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2014-04-17T05:34:24.297Z,1397712864.297 [Startup](INFO): Completed Startup
2014-04-17T05:34:24.297Z,1397712864.297 [Startup] Stopped
2014-04-17T05:34:24.297Z,1397712864.297 [Startup](INFO): Aggregate::uninitialize Startup
2014-04-17T05:34:24.297Z,1397712864.297 [Startup:A.GoToSurface] Stopped
2014-04-17T05:34:24.297Z,1397712864.297 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-17T05:34:24.799Z,1397712864.799 [DataOverHttps](DEBUG): tcpConnecting
2014-04-17T05:34:24.799Z,1397712864.799 [DataOverHttps](DEBUG): sslConnect
2014-04-17T05:34:24.800Z,1397712864.800 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:34:24.839Z,1397712864.839 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:24.854Z,1397712864.854 [MissionManager](IMPORTANT): Started mission Default
2014-04-17T05:34:24.854Z,1397712864.854 [Default] Running Loop=1
2014-04-17T05:34:24.854Z,1397712864.854 [Default](INFO): Aggregate::initialize Default
2014-04-17T05:34:24.854Z,1397712864.854 [Default:Iridium] Running Loop=1
2014-04-17T05:34:24.855Z,1397712864.855 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-04-17T05:34:24.855Z,1397712864.855 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-04-17T05:34:24.855Z,1397712864.855 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-04-17T05:34:24.855Z,1397712864.855 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-04-17T05:34:24.855Z,1397712864.855 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-17T05:34:24.861Z,1397712864.861 [Default:Iridium:B.GoToSurface] Stopped
2014-04-17T05:34:24.861Z,1397712864.861 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-17T05:34:24.861Z,1397712864.861 [Default:Iridium:Read_Iridium] Running Loop=1
2014-04-17T05:34:24.861Z,1397712864.861 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-04-17T05:34:24.866Z,1397712864.866 [Default:GPS] Running Loop=1
2014-04-17T05:34:24.867Z,1397712864.867 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-04-17T05:34:24.867Z,1397712864.867 [Default:GPS:A.SetSpeed] Running Loop=1
2014-04-17T05:34:24.867Z,1397712864.867 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-04-17T05:34:24.867Z,1397712864.867 [Default:GPS:B.GoToSurface] Running Loop=1
2014-04-17T05:34:24.867Z,1397712864.867 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-17T05:34:24.873Z,1397712864.873 [Default:GPS:B.GoToSurface] Stopped
2014-04-17T05:34:24.873Z,1397712864.873 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-17T05:34:24.873Z,1397712864.873 [Default:GPS:Read_GPS] Running Loop=1
2014-04-17T05:34:24.873Z,1397712864.873 [Default:GPS:A.SetSpeed] Running Loop=1
2014-04-17T05:34:25.365Z,1397712865.365 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:34:25.880Z,1397712865.880 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:25.894Z,1397712865.894 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2014-04-17T05:34:25.897Z,1397712865.897 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2014-04-17T05:34:26.793Z,1397712866.793 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:34:26.795Z,1397712866.795 [DataOverHttps](DEBUG): dataWrite
2014-04-17T05:34:26.796Z,1397712866.796 [DataOverHttps](DEBUG): dataWriting
2014-04-17T05:34:26.797Z,1397712866.797 [DataOverHttps](DEBUG): Wrote 206 bytes
2014-04-17T05:34:26.800Z,1397712866.800 [NAL9602](INFO): Powering up
2014-04-17T05:34:26.814Z,1397712866.814 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:27.245Z,1397712867.245 [DataOverHttps](DEBUG): dataRead
2014-04-17T05:34:27.262Z,1397712867.262 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:27.678Z,1397712867.678 [DataOverHttps](DEBUG): dataRead
2014-04-17T05:34:27.678Z,1397712867.678 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false
2014-04-17T05:34:27.679Z,1397712867.679 [DataOverHttps](DEBUG): disconnect
2014-04-17T05:34:27.707Z,1397712867.707 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:28.122Z,1397712868.122 [DataOverHttps](DEBUG): tcpConnect
2014-04-17T05:34:28.143Z,1397712868.143 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:28.559Z,1397712868.559 [DataOverHttps](DEBUG): tcpConnecting
2014-04-17T05:34:28.559Z,1397712868.559 [DataOverHttps](DEBUG): sslConnect
2014-04-17T05:34:28.560Z,1397712868.560 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:34:28.584Z,1397712868.584 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:29.057Z,1397712869.057 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:34:29.570Z,1397712869.570 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:30.075Z,1397712870.075 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:34:30.077Z,1397712870.077 [DataOverHttps](DEBUG): dataWrite
2014-04-17T05:34:30.079Z,1397712870.079 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20140417T053127/Courier0004.lzma
2014-04-17T05:34:30.079Z,1397712870.079 [DataOverHttps](DEBUG): dataWriting
2014-04-17T05:34:30.081Z,1397712870.081 [DataOverHttps](DEBUG): Wrote 391 bytes
2014-04-17T05:34:30.097Z,1397712870.097 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:30.534Z,1397712870.534 [DataOverHttps](DEBUG): dataRead
2014-04-17T05:34:30.558Z,1397712870.558 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:30.971Z,1397712870.971 [DataOverHttps](DEBUG): dataRead
2014-04-17T05:34:30.971Z,1397712870.971 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=true&momsn=784544&filename=Logs%2F20140417T053127%2FCourier0004.lzma
2014-04-17T05:34:30.972Z,1397712870.972 [DataOverHttps](INFO): Moved sent file to Logs/20140417T053127/Courier0004.lzma.bak
2014-04-17T05:34:30.972Z,1397712870.972 [DataOverHttps](INFO): SBD MOMSN=784544
2014-04-17T05:34:30.973Z,1397712870.973 [DataOverHttps](DEBUG): disconnect
2014-04-17T05:34:31.000Z,1397712871.000 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:31.430Z,1397712871.430 [DataOverHttps](DEBUG): tcpConnect
2014-04-17T05:34:31.452Z,1397712871.452 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:31.906Z,1397712871.906 [DataOverHttps](DEBUG): tcpConnecting
2014-04-17T05:34:31.906Z,1397712871.906 [DataOverHttps](DEBUG): sslConnect
2014-04-17T05:34:31.907Z,1397712871.907 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:34:31.925Z,1397712871.925 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:32.349Z,1397712872.349 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:34:32.858Z,1397712872.858 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:33.310Z,1397712873.310 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:34:33.312Z,1397712873.312 [DataOverHttps](DEBUG): dataWrite
2014-04-17T05:34:33.312Z,1397712873.312 [DataOverHttps](DEBUG): dataWriting
2014-04-17T05:34:33.314Z,1397712873.314 [DataOverHttps](DEBUG): Wrote 206 bytes
2014-04-17T05:34:33.335Z,1397712873.335 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:33.755Z,1397712873.755 [DataOverHttps](DEBUG): dataRead
2014-04-17T05:34:33.780Z,1397712873.780 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:34.282Z,1397712874.282 [DataOverHttps](DEBUG): dataRead
2014-04-17T05:34:34.283Z,1397712874.283 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false
2014-04-17T05:34:34.283Z,1397712874.283 [DataOverHttps](DEBUG): disconnect
2014-04-17T05:34:34.302Z,1397712874.302 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:34.740Z,1397712874.740 [DataOverHttps](DEBUG): tcpConnect
2014-04-17T05:34:34.764Z,1397712874.764 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:35.181Z,1397712875.181 [DataOverHttps](DEBUG): tcpConnecting
2014-04-17T05:34:35.181Z,1397712875.181 [DataOverHttps](DEBUG): sslConnect
2014-04-17T05:34:35.185Z,1397712875.185 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:34:35.209Z,1397712875.209 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:35.626Z,1397712875.626 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:34:36.129Z,1397712876.129 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:36.617Z,1397712876.617 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:34:36.619Z,1397712876.619 [DataOverHttps](DEBUG): dataWrite
2014-04-17T05:34:36.622Z,1397712876.622 [DataOverHttps](INFO): Sending 93 bytes from file Logs/20140417T053127/Express0005.lzma
2014-04-17T05:34:36.622Z,1397712876.622 [DataOverHttps](DEBUG): dataWriting
2014-04-17T05:34:36.624Z,1397712876.624 [DataOverHttps](DEBUG): Wrote 505 bytes
2014-04-17T05:34:36.640Z,1397712876.640 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:37.080Z,1397712877.080 [DataOverHttps](DEBUG): dataRead
2014-04-17T05:34:37.112Z,1397712877.112 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:37.529Z,1397712877.529 [DataOverHttps](DEBUG): dataRead
2014-04-17T05:34:37.530Z,1397712877.530 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=true&momsn=784546&filename=Logs%2F20140417T053127%2FExpress0005.lzma
2014-04-17T05:34:37.530Z,1397712877.530 [DataOverHttps](INFO): Moved sent file to Logs/20140417T053127/Express0005.lzma.bak
2014-04-17T05:34:37.531Z,1397712877.531 [DataOverHttps](INFO): SBD MOMSN=784546
2014-04-17T05:34:37.531Z,1397712877.531 [DataOverHttps](DEBUG): disconnect
2014-04-17T05:34:37.574Z,1397712877.574 [NAL9602](INFO): NAL9602 initialized
2014-04-17T05:34:37.593Z,1397712877.593 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:38.032Z,1397712878.032 [DataOverHttps](DEBUG): tcpConnect
2014-04-17T05:34:38.055Z,1397712878.055 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients.
2014-04-17T05:34:38.056Z,1397712878.056 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:38.070Z,1397712878.070 [Default:Iridium:Read_Iridium] Stopped
2014-04-17T05:34:38.070Z,1397712878.070 [Default:Iridium](INFO): Completed Default:Iridium
2014-04-17T05:34:38.070Z,1397712878.070 [Default:Iridium] Stopped
2014-04-17T05:34:38.070Z,1397712878.070 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-04-17T05:34:38.071Z,1397712878.071 [Default:Iridium:A.SetSpeed] Stopped
2014-04-17T05:34:38.071Z,1397712878.071 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-04-17T05:34:38.071Z,1397712878.071 [Default:WaitAtTheSurface] Running Loop=1
2014-04-17T05:34:38.071Z,1397712878.071 [Default:WaitAtTheSurface](INFO): Aggregate::initialize Default:WaitAtTheSurface
2014-04-17T05:34:38.071Z,1397712878.071 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Running Loop=1
2014-04-17T05:34:38.071Z,1397712878.071 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Initialize.
2014-04-17T05:34:38.071Z,1397712878.071 [Default:WaitAtTheSurface:B.GoToSurface] Running Loop=1
2014-04-17T05:34:38.071Z,1397712878.071 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-17T05:34:38.526Z,1397712878.526 [DataOverHttps](DEBUG): tcpConnecting
2014-04-17T05:34:38.527Z,1397712878.527 [DataOverHttps](DEBUG): sslConnect
2014-04-17T05:34:38.528Z,1397712878.528 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:34:38.570Z,1397712878.570 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:38.583Z,1397712878.583 [Default:WaitAtTheSurface:B.GoToSurface] Running Loop=1
2014-04-17T05:34:38.589Z,1397712878.589 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Running Loop=1
2014-04-17T05:34:39.041Z,1397712879.041 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:34:39.564Z,1397712879.564 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:40.099Z,1397712880.099 [DataOverHttps](DEBUG): sslConnecting
2014-04-17T05:34:40.101Z,1397712880.101 [DataOverHttps](DEBUG): dataWrite
2014-04-17T05:34:40.101Z,1397712880.101 [DataOverHttps](DEBUG): dataWriting
2014-04-17T05:34:40.102Z,1397712880.102 [DataOverHttps](DEBUG): Wrote 206 bytes
2014-04-17T05:34:40.137Z,1397712880.137 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:40.577Z,1397712880.577 [DataOverHttps](DEBUG): dataRead
2014-04-17T05:34:40.603Z,1397712880.603 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:41.064Z,1397712881.064 [DataOverHttps](DEBUG): dataRead
2014-04-17T05:34:41.065Z,1397712881.065 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false
2014-04-17T05:34:41.065Z,1397712881.065 [DataOverHttps](DEBUG): disconnect
2014-04-17T05:34:41.084Z,1397712881.084 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:41.550Z,1397712881.550 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:42.032Z,1397712882.032 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:42.469Z,1397712882.469 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:42.930Z,1397712882.930 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:43.403Z,1397712883.403 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:43.876Z,1397712883.876 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:44.376Z,1397712884.376 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:44.833Z,1397712884.833 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:45.274Z,1397712885.274 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:45.707Z,1397712885.707 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:46.202Z,1397712886.202 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:46.705Z,1397712886.705 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:47.142Z,1397712887.142 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:47.584Z,1397712887.584 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:48.027Z,1397712888.027 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:48.499Z,1397712888.499 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:48.947Z,1397712888.947 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:49.453Z,1397712889.453 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:49.941Z,1397712889.941 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:50.380Z,1397712890.380 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:50.853Z,1397712890.853 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:51.295Z,1397712891.295 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:51.737Z,1397712891.737 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:52.169Z,1397712892.169 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:52.625Z,1397712892.625 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:53.143Z,1397712893.143 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:53.579Z,1397712893.579 [NAL9602](INFO): SBD MO Status=0, MOMSN=26348, MT Status=0, MTMSN=0
2014-04-17T05:34:53.579Z,1397712893.579 [NAL9602](INFO): No messages in MT queue
2014-04-17T05:34:53.593Z,1397712893.593 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:54.039Z,1397712894.039 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:54.495Z,1397712894.495 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:55.004Z,1397712895.004 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:55.508Z,1397712895.508 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:55.990Z,1397712895.990 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:56.524Z,1397712896.524 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:56.967Z,1397712896.967 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:57.435Z,1397712897.435 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:57.927Z,1397712897.927 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:58.409Z,1397712898.409 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:58.847Z,1397712898.847 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:59.308Z,1397712899.308 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:34:59.787Z,1397712899.787 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:35:00.318Z,1397712900.318 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:35:00.789Z,1397712900.789 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:35:01.249Z,1397712901.249 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:35:01.697Z,1397712901.697 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:35:02.127Z,1397712902.127 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:35:02.628Z,1397712902.628 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:35:03.118Z,1397712903.118 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:35:03.585Z,1397712903.585 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:35:04.016Z,1397712904.016 [NAL9602](IMPORTANT): GPS fix at: 1397712902.00
2014-04-17T05:35:04.030Z,1397712904.030 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:35:04.046Z,1397712904.046 [Default:GPS:Read_GPS] Stopped
2014-04-17T05:35:04.046Z,1397712904.046 [Default:GPS:D] Running Loop=1
2014-04-17T05:35:04.507Z,1397712904.507 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:35:04.527Z,1397712904.527 [Default:GPS:D] Stopped
2014-04-17T05:35:04.528Z,1397712904.528 [Default:GPS](INFO): Completed Default:GPS
2014-04-17T05:35:04.528Z,1397712904.528 [Default:GPS] Stopped
2014-04-17T05:35:04.528Z,1397712904.528 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-04-17T05:35:04.528Z,1397712904.528 [Default:GPS:A.SetSpeed] Stopped
2014-04-17T05:35:04.528Z,1397712904.528 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-04-17T05:35:05.092Z,1397712905.092 [HFRCMTimeInterpolator](DEBUG): no valid forecast
2014-04-17T05:35:10.140Z,13