2014-05-28T17:14:55.026Z,1401297295.026 [Supervisor](DEBUG): Initializing supervisor.
2014-05-28T17:14:55.029Z,1401297295.029 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0
2014-05-28T17:14:55.029Z,1401297295.029 [SyncHandler](INFO): Protected caller Thread ID is 768
2014-05-28T17:14:55.030Z,1401297295.030 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2014-05-28T17:14:55.052Z,1401297295.052 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0
2014-05-28T17:14:55.053Z,1401297295.053 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 769
2014-05-28T17:14:55.056Z,1401297295.056 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2014-05-28T17:14:55.067Z,1401297295.067 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2014-05-28T17:14:55.100Z,1401297295.100 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0
2014-05-28T17:14:55.101Z,1401297295.101 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 770
2014-05-28T17:14:55.102Z,1401297295.102 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2014-05-28T17:14:55.112Z,1401297295.112 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0
2014-05-28T17:14:55.113Z,1401297295.113 [logger ThreadHandler](INFO): Protected caller Thread ID is 771
2014-05-28T17:14:55.115Z,1401297295.115 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2014-05-28T17:14:55.116Z,1401297295.116 [Supervisor](INFO): Looking for Config files in directory: Config/
2014-05-28T17:14:55.130Z,1401297295.130 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2014-05-28T17:14:55.922Z,1401297295.922 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2014-05-28T17:14:55.923Z,1401297295.923 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2014-05-28T17:14:56.461Z,1401297296.461 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2014-05-28T17:14:56.470Z,1401297296.470 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2014-05-28T17:14:56.616Z,1401297296.616 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2014-05-28T17:14:56.621Z,1401297296.621 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2014-05-28T17:14:56.924Z,1401297296.924 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2014-05-28T17:14:56.925Z,1401297296.925 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2014-05-28T17:14:57.192Z,1401297297.192 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2014-05-28T17:14:57.200Z,1401297297.200 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2014-05-28T17:14:57.669Z,1401297297.669 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2014-05-28T17:14:57.670Z,1401297297.670 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2014-05-28T17:14:57.981Z,1401297297.981 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2014-05-28T17:14:57.982Z,1401297297.982 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2014-05-28T17:14:58.575Z,1401297298.575 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2014-05-28T17:14:58.577Z,1401297298.577 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2014-05-28T17:14:58.763Z,1401297298.763 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2014-05-28T17:14:58.763Z,1401297298.763 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2014-05-28T17:14:59.687Z,1401297299.687 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2014-05-28T17:14:59.687Z,1401297299.687 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2014-05-28T17:14:59.812Z,1401297299.812 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2014-05-28T17:14:59.813Z,1401297299.813 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2014-05-28T17:14:59.913Z,1401297299.913 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2014-05-28T17:15:00.040Z,1401297300.040 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2014-05-28T17:15:00.041Z,1401297300.041 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2014-05-28T17:15:00.156Z,1401297300.156 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2014-05-28T17:15:00.158Z,1401297300.158 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2014-05-28T17:15:00.313Z,1401297300.313 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2014-05-28T17:15:00.315Z,1401297300.315 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2014-05-28T17:15:00.319Z,1401297300.319 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2014-05-28T17:15:00.442Z,1401297300.442 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2014-05-28T17:15:00.594Z,1401297300.594 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2014-05-28T17:15:00.706Z,1401297300.706 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2014-05-28T17:15:00.811Z,1401297300.811 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2014-05-28T17:15:00.984Z,1401297300.984 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2014-05-28T17:15:01.124Z,1401297301.124 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2014-05-28T17:15:01.222Z,1401297301.222 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2014-05-28T17:15:01.342Z,1401297301.342 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2014-05-28T17:15:01.460Z,1401297301.460 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2014-05-28T17:15:01.573Z,1401297301.573 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2014-05-28T17:15:01.674Z,1401297301.674 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Estimation.cfg
2014-05-28T17:15:01.788Z,1401297301.788 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2014-05-28T17:15:01.793Z,1401297301.793 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2014-05-28T17:15:02.702Z,1401297302.702 [AHRS_sp3003D] Loaded
2014-05-28T17:15:02.702Z,1401297302.702 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2014-05-28T17:15:03.336Z,1401297303.336 [Batt_Ocean_Server] Loaded
2014-05-28T17:15:03.336Z,1401297303.336 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2014-05-28T17:15:03.788Z,1401297303.788 [DataOverHttps] Loaded
2014-05-28T17:15:03.789Z,1401297303.789 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2014-05-28T17:15:03.831Z,1401297303.831 [Depth_Keller] Loaded
2014-05-28T17:15:03.832Z,1401297303.832 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2014-05-28T17:15:03.837Z,1401297303.837 [DropWeight] Loaded
2014-05-28T17:15:03.837Z,1401297303.837 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2014-05-28T17:15:04.181Z,1401297304.181 [DVL_micro] Loaded
2014-05-28T17:15:04.181Z,1401297304.181 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2014-05-28T17:15:04.313Z,1401297304.313 [NAL9602] Loaded
2014-05-28T17:15:04.313Z,1401297304.313 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2014-05-28T17:15:04.376Z,1401297304.376 [Onboard] Loaded
2014-05-28T17:15:04.377Z,1401297304.377 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2014-05-28T17:15:04.384Z,1401297304.384 [Radio_Freewave] Loaded
2014-05-28T17:15:04.384Z,1401297304.384 [ComponentRegistry](DEBUG): Component "Radio_Freewave" handled in its own thread.
2014-05-28T17:15:04.387Z,1401297304.387 [Radio_Freewave ThreadHandler](DEBUG): Created PCaller Thread at 4060F4E0
2014-05-28T17:15:04.387Z,1401297304.387 [Radio_Freewave ThreadHandler](INFO): Protected caller Thread ID is 866
2014-05-28T17:15:04.394Z,1401297304.394 [SCPI] Loaded
2014-05-28T17:15:04.394Z,1401297304.394 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread.
2014-05-28T17:15:04.395Z,1401297304.395 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2014-05-28T17:15:04.396Z,1401297304.396 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2014-05-28T17:15:06.171Z,1401297306.171 [InternalSim] Loaded
2014-05-28T17:15:06.171Z,1401297306.171 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2014-05-28T17:15:06.172Z,1401297306.172 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2014-05-28T17:15:06.178Z,1401297306.178 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2014-05-28T17:15:06.608Z,1401297306.608 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2014-05-28T17:15:06.611Z,1401297306.611 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2014-05-28T17:15:06.620Z,1401297306.620 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2014-05-28T17:15:06.622Z,1401297306.622 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2014-05-28T17:15:06.790Z,1401297306.790 [DeadReckonUsingMultipleVelocitySources] Loaded
2014-05-28T17:15:06.791Z,1401297306.791 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2014-05-28T17:15:06.868Z,1401297306.868 [DeadReckonWithRespectToWater] Loaded
2014-05-28T17:15:06.869Z,1401297306.869 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToWater" handled in the control thread.
2014-05-28T17:15:06.931Z,1401297306.931 [DeadReckonWithRespectToSeafloor] Loaded
2014-05-28T17:15:06.932Z,1401297306.932 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToSeafloor" handled in the control thread.
2014-05-28T17:15:06.991Z,1401297306.991 [DeadReckonUsingDVLWaterTrack] Loaded
2014-05-28T17:15:06.992Z,1401297306.992 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingDVLWaterTrack" handled in the control thread.
2014-05-28T17:15:07.061Z,1401297307.061 [DeadReckonUsingCompactModelForecast] Loaded
2014-05-28T17:15:07.062Z,1401297307.062 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingCompactModelForecast" handled in the control thread.
2014-05-28T17:15:07.079Z,1401297307.079 [NavChart] Loaded
2014-05-28T17:15:07.079Z,1401297307.079 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2014-05-28T17:15:07.089Z,1401297307.089 [UniversalFixResidualReporter] Loaded
2014-05-28T17:15:07.090Z,1401297307.090 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2014-05-28T17:15:07.090Z,1401297307.090 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2014-05-28T17:15:07.094Z,1401297307.094 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2014-05-28T17:15:07.171Z,1401297307.171 [VerticalControl](DEBUG): Construct VerticalControl.
2014-05-28T17:15:07.334Z,1401297307.334 [VerticalControl] Loaded
2014-05-28T17:15:07.334Z,1401297307.334 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2014-05-28T17:15:07.335Z,1401297307.335 [HorizontalControl](DEBUG): Construct HorizontalControl.
2014-05-28T17:15:07.443Z,1401297307.443 [HorizontalControl] Loaded
2014-05-28T17:15:07.443Z,1401297307.443 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2014-05-28T17:15:07.444Z,1401297307.444 [SpeedControl](DEBUG): Construct SpeedControl.
2014-05-28T17:15:07.446Z,1401297307.446 [SpeedControl] Loaded
2014-05-28T17:15:07.446Z,1401297307.446 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2014-05-28T17:15:07.447Z,1401297307.447 [LoopControl](DEBUG): Construct LoopControl.
2014-05-28T17:15:07.447Z,1401297307.447 [LoopControl] Loaded
2014-05-28T17:15:07.448Z,1401297307.448 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2014-05-28T17:15:07.450Z,1401297307.450 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2014-05-28T17:15:07.456Z,1401297307.456 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2014-05-28T17:15:07.484Z,1401297307.484 [DepthRateCalculator] Loaded
2014-05-28T17:15:07.484Z,1401297307.484 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2014-05-28T17:15:07.496Z,1401297307.496 [PitchRateCalculator] Loaded
2014-05-28T17:15:07.496Z,1401297307.496 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2014-05-28T17:15:07.541Z,1401297307.541 [SpeedCalculator] Loaded
2014-05-28T17:15:07.542Z,1401297307.542 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2014-05-28T17:15:07.564Z,1401297307.564 [TempGradientCalculator] Loaded
2014-05-28T17:15:07.565Z,1401297307.565 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2014-05-28T17:15:07.570Z,1401297307.570 [YawRateCalculator] Loaded
2014-05-28T17:15:07.571Z,1401297307.571 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2014-05-28T17:15:07.571Z,1401297307.571 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2014-05-28T17:15:07.573Z,1401297307.573 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2014-05-28T17:15:07.751Z,1401297307.751 [CTD_NeilBrown] Loaded
2014-05-28T17:15:07.751Z,1401297307.751 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2014-05-28T17:15:07.752Z,1401297307.752 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4075E4E0
2014-05-28T17:15:07.753Z,1401297307.753 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 867
2014-05-28T17:15:07.774Z,1401297307.774 [ISUS] Loaded
2014-05-28T17:15:07.775Z,1401297307.775 [ComponentRegistry](DEBUG): SyncComponent "ISUS" handled in the control thread.
2014-05-28T17:15:07.790Z,1401297307.790 [PAR_Licor] Loaded
2014-05-28T17:15:07.791Z,1401297307.791 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2014-05-28T17:15:07.886Z,1401297307.886 [WetLabsBB2FL] Loaded
2014-05-28T17:15:07.886Z,1401297307.886 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2014-05-28T17:15:07.887Z,1401297307.887 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4078E4E0
2014-05-28T17:15:07.888Z,1401297307.888 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 868
2014-05-28T17:15:07.890Z,1401297307.890 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2014-05-28T17:15:07.893Z,1401297307.893 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2014-05-28T17:15:08.047Z,1401297308.047 [SBIT](DEBUG): Construct Startup Built In Test.
2014-05-28T17:15:08.060Z,1401297308.060 [SBIT] Loaded
2014-05-28T17:15:08.060Z,1401297308.060 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2014-05-28T17:15:08.061Z,1401297308.061 [IBIT](DEBUG): Construct Initiated Built In Test.
2014-05-28T17:15:08.089Z,1401297308.089 [IBIT] Loaded
2014-05-28T17:15:08.089Z,1401297308.089 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2014-05-28T17:15:08.091Z,1401297308.091 [CBIT](DEBUG): Construct CBIT Built In Test.
2014-05-28T17:15:08.183Z,1401297308.183 [CBIT] Loaded
2014-05-28T17:15:08.183Z,1401297308.183 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2014-05-28T17:15:08.184Z,1401297308.184 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2014-05-28T17:15:08.184Z,1401297308.184 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2014-05-28T17:15:16.349Z,1401297316.349 [HFRadarModelCalc] Loaded
2014-05-28T17:15:16.350Z,1401297316.350 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2014-05-28T17:15:22.110Z,1401297322.110 [HFRadarCompactModelForecaster] Loaded
2014-05-28T17:15:22.110Z,1401297322.110 [ComponentRegistry](DEBUG): SyncComponent "HFRadarCompactModelForecaster" handled in the control thread.
2014-05-28T17:15:24.521Z,1401297324.521 [HFRCMSpaceInterpolator] Loaded
2014-05-28T17:15:24.521Z,1401297324.521 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSpaceInterpolator" handled in the control thread.
2014-05-28T17:15:24.523Z,1401297324.523 [HFRCMTimeInterpolator] Loaded
2014-05-28T17:15:24.524Z,1401297324.524 [ComponentRegistry](DEBUG): SyncComponent "HFRCMTimeInterpolator" handled in the control thread.
2014-05-28T17:15:24.549Z,1401297324.549 [HFRCMSurfaceCurrentAtVehicleLocation] Loaded
2014-05-28T17:15:24.566Z,1401297324.566 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSurfaceCurrentAtVehicleLocation" handled in the control thread.
2014-05-28T17:15:24.623Z,1401297324.623 [HFRCMVirtualSurfaceDrifter] Loaded
2014-05-28T17:15:24.624Z,1401297324.624 [ComponentRegistry](DEBUG): SyncComponent "HFRCMVirtualSurfaceDrifter" handled in the control thread.
2014-05-28T17:15:24.624Z,1401297324.624 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2014-05-28T17:15:24.625Z,1401297324.625 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2014-05-28T17:15:24.907Z,1401297324.907 [BuoyancyServo] Loaded
2014-05-28T17:15:24.908Z,1401297324.908 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2014-05-28T17:15:24.937Z,1401297324.937 [ElevatorServo] Loaded
2014-05-28T17:15:24.937Z,1401297324.937 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2014-05-28T17:15:24.962Z,1401297324.962 [MassServo] Loaded
2014-05-28T17:15:24.962Z,1401297324.962 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2014-05-28T17:15:24.987Z,1401297324.987 [RudderServo] Loaded
2014-05-28T17:15:24.987Z,1401297324.987 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2014-05-28T17:15:25.021Z,1401297325.021 [ThrusterServo] Loaded
2014-05-28T17:15:25.021Z,1401297325.021 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2014-05-28T17:15:25.022Z,1401297325.022 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2014-05-28T17:15:25.039Z,1401297325.039 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2014-05-28T17:15:25.119Z,1401297325.119 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2014-05-28T17:15:25.121Z,1401297325.121 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2014-05-28T17:15:25.122Z,1401297325.122 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2014-05-28T17:15:25.129Z,1401297325.129 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2014-05-28T17:15:25.135Z,1401297325.135 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A4F4E0
2014-05-28T17:15:25.135Z,1401297325.135 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 869
2014-05-28T17:15:25.140Z,1401297325.140 [Supervisor](INFO): Main Thread ID is 766
2014-05-28T17:15:25.140Z,1401297325.140 [Supervisor](DEBUG): Running supervisor.
2014-05-28T17:15:25.141Z,1401297325.141 [CommandLine ThreadHandler](INFO): Handler Thread ID is 870
2014-05-28T17:15:25.149Z,1401297325.149 [controlThread ThreadHandler](INFO): Handler Thread ID is 871
2014-05-28T17:15:25.150Z,1401297325.150 [controlThread](DEBUG): Initializing ControlThread
2014-05-28T17:15:25.176Z,1401297325.176 [logger ThreadHandler](INFO): Handler Thread ID is 872
2014-05-28T17:15:25.212Z,1401297325.212 [Radio_Freewave ThreadHandler](INFO): Handler Thread ID is 873
2014-05-28T17:15:25.235Z,1401297325.235 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 874
2014-05-28T17:15:25.236Z,1401297325.236 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2014-05-28T17:15:25.244Z,1401297325.244 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 876
2014-05-28T17:15:25.245Z,1401297325.245 [WetLabsBB2FL](INFO): Powering down
2014-05-28T17:15:25.263Z,1401297325.263 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2014-05-28T17:15:25.284Z,1401297325.284 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 877
2014-05-28T17:15:25.293Z,1401297325.293 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2014-05-28T17:15:25.294Z,1401297325.294 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2014-05-28T17:15:25.294Z,1401297325.294 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2014-05-28T17:15:25.294Z,1401297325.294 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2014-05-28T17:15:25.295Z,1401297325.295 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2014-05-28T17:15:25.295Z,1401297325.295 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2014-05-28T17:15:25.295Z,1401297325.295 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2014-05-28T17:15:25.296Z,1401297325.296 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2014-05-28T17:15:25.296Z,1401297325.296 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2014-05-28T17:15:26.877Z,1401297326.877 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2014-05-28T17:15:26.929Z,1401297326.929 [InternalSim](DEBUG):  InternalSim initializing...
2014-05-28T17:15:27.596Z,1401297327.596 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2014-05-28T17:15:27.596Z,1401297327.596 [DeadReckonWithRespectToWater](DEBUG): Initializing DeadReckonWithRespectToWater component.
2014-05-28T17:15:27.596Z,1401297327.596 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component.
2014-05-28T17:15:27.597Z,1401297327.597 [DeadReckonUsingDVLWaterTrack](DEBUG): Initializing DeadReckonUsingDVLWaterTrack component.
2014-05-28T17:15:27.597Z,1401297327.597 [DeadReckonUsingCompactModelForecast](DEBUG): Initializing DeadReckonUsingCompactModelForecast component.
2014-05-28T17:15:27.598Z,1401297327.598 [NavChart](DEBUG): Initialize NavChart Navigation.
2014-05-28T17:15:27.598Z,1401297327.598 [UniversalFixResidualReporter](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2014-05-28T17:15:27.599Z,1401297327.599 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2014-05-28T17:15:27.600Z,1401297327.600 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2014-05-28T17:15:27.601Z,1401297327.601 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2014-05-28T17:15:27.602Z,1401297327.602 [LoopControl](DEBUG): Initialize LoopControlComponent.
2014-05-28T17:15:27.602Z,1401297327.602 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2014-05-28T17:15:27.602Z,1401297327.602 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2014-05-28T17:15:27.603Z,1401297327.603 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2014-05-28T17:15:27.603Z,1401297327.603 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2014-05-28T17:15:27.604Z,1401297327.604 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2014-05-28T17:15:27.619Z,1401297327.619 [SBIT](INFO): Initialize SBIT Component.
2014-05-28T17:15:27.620Z,1401297327.620 [SBIT](IMPORTANT): Tethys CM Info: 
 $Rev:11330
2014-05-28T17:15:27.620Z,1401297327.620 [SBIT](IMPORTANT): Kernel Release:2.6.27.8
2014-05-28T17:15:27.620Z,1401297327.620 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2014-05-28T17:15:27.621Z,1401297327.621 [IBIT](INFO): Initialize IBIT Component.
2014-05-28T17:15:27.622Z,1401297327.622 [CBIT](DEBUG): Initialize CBIT Component.
2014-05-28T17:15:27.622Z,1401297327.622 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2014-05-28T17:15:27.622Z,1401297327.622 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2014-05-28T17:15:27.761Z,1401297327.761 [HFRadarCompactModelForecaster](DEBUG): Found new ECs!
2014-05-28T17:15:28.033Z,1401297328.033 [Radio_Freewave](INFO): Powering up
2014-05-28T17:15:28.842Z,1401297328.842 [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-05-28T17:15:40.984Z,1401297340.984 [HFRadarCompactModelForecaster](IMPORTANT): Forecast time 201405281400: published 50 modes in rows, 61 hours in columns, 3050 elements.
2014-05-28T17:15:41.015Z,1401297341.015 [HFRCMSpaceInterpolator](DEBUG): Initializing HFRCMSpaceInterpolator component.
2014-05-28T17:15:41.017Z,1401297341.017 [HFRCMTimeInterpolator](DEBUG): Initializing HFRCMTimeInterpolator component.
2014-05-28T17:15:41.018Z,1401297341.018 [HFRCMSurfaceCurrentAtVehicleLocation](DEBUG): Initializing HFRCMSurfaceCurrentAtVehicleLocation component.
2014-05-28T17:15:41.018Z,1401297341.018 [HFRCMVirtualSurfaceDrifter](DEBUG): Initializing HFRCMVirtualSurfaceDrifter component.
2014-05-28T17:15:41.020Z,1401297341.020 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2014-05-28T17:15:41.068Z,1401297341.068 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2014-05-28T17:15:41.095Z,1401297341.095 [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-05-28T17:15:41.128Z,1401297341.128 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2014-05-28T17:15:41.232Z,1401297341.232 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2014-05-28T17:15:41.234Z,1401297341.234 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2014-05-28T17:15:41.272Z,1401297341.272 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-05-28T17:15:41.306Z,1401297341.306 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2014-05-28T17:15:41.323Z,1401297341.323 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-05-28T17:15:41.366Z,1401297341.366 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2014-05-28T17:15:41.417Z,1401297341.417 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Construct.
2014-05-28T17:15:41.440Z,1401297341.440 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-05-28T17:15:41.476Z,1401297341.476 [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-05-28T17:15:41.484Z,1401297341.484 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,DataOverHttps,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,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,LogSplitter,
2014-05-28T17:15:41.685Z,1401297341.685 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2014-05-28T17:15:42.593Z,1401297342.593 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar
2014-05-28T17:15:42.690Z,1401297342.690 [DVL_micro](INFO): Initializing
2014-05-28T17:15:42.713Z,1401297342.713 [NAL9602](INFO): Powering up NAL9602
2014-05-28T17:15:43.488Z,1401297343.488 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2014-05-28T17:15:43.496Z,1401297343.496 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2014-05-28T17:15:43.522Z,1401297343.522 [ElevatorServo](DEBUG): Initializing EZServoServo.
2014-05-28T17:15:43.528Z,1401297343.528 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2014-05-28T17:15:43.546Z,1401297343.546 [MassServo](DEBUG): Initializing EZServoServo.
2014-05-28T17:15:43.556Z,1401297343.556 [MassServo](DEBUG): Initializing MassServo.
2014-05-28T17:15:43.592Z,1401297343.592 [RudderServo](DEBUG): Initializing EZServoServo.
2014-05-28T17:15:43.604Z,1401297343.604 [RudderServo](DEBUG): Initializing RudderServo.
2014-05-28T17:15:43.621Z,1401297343.621 [ThrusterServo](DEBUG): Initializing EZServoServo.
2014-05-28T17:15:43.632Z,1401297343.632 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2014-05-28T17:15:44.854Z,1401297344.854 [SBIT](IMPORTANT): Beginning Startup BIT
2014-05-28T17:15:44.857Z,1401297344.857 [CBIT](IMPORTANT): Beginning GF scan
2014-05-28T17:15:49.248Z,1401297349.248 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.008213
2014-05-28T17:15:54.048Z,1401297354.048 [NAL9602](INFO): NAL9602 initialized
2014-05-28T17:16:12.846Z,1401297372.846 [CBIT](FAULT): Chan 4 High side GF detected
mA:
CHAN 5 (24V): 0.061887
CHAN 4 (Batt): 0.011096
CHAN 2 (12V): 0.004496
CHAN 1 (5V): 0.000574
CHAN 0 (3.3V): 0.000670
OPEN: 0.000765
Full Scale Calc: 0.392
2014-05-28T17:16:38.861Z,1401297398.861 [SBIT](IMPORTANT): SBIT PASSED
2014-05-28T17:16:39.331Z,1401297399.331 [MissionManager](IMPORTANT): Started mission Startup
2014-05-28T17:16:39.331Z,1401297399.331 [Startup] Running Loop=1
2014-05-28T17:16:39.331Z,1401297399.331 [Startup](INFO): Aggregate::initialize Startup
2014-05-28T17:16:39.331Z,1401297399.331 [Startup:A.GoToSurface] Running Loop=1
2014-05-28T17:16:39.331Z,1401297399.331 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-28T17:16:39.374Z,1401297399.374 [Startup:StartupSatComms] Running Loop=1
2014-05-28T17:16:39.374Z,1401297399.374 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2014-05-28T17:16:39.374Z,1401297399.374 [Startup:StartupSatComms:A] Running Loop=1
2014-05-28T17:16:39.893Z,1401297399.893 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2014-05-28T17:17:39.664Z,1401297459.664 [Startup:StartupSatComms:A](INFO): Timed out from 2014-05-28T17:16:39.4Z
2014-05-28T17:17:39.664Z,1401297459.664 [Startup:StartupSatComms:A] Stopped
2014-05-28T17:17:39.665Z,1401297459.665 [Startup:StartupSatComms:B] Running Loop=1
2014-05-28T17:17:40.123Z,1401297460.123 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2014-05-28T17:17:44.217Z,1401297464.217 [DataOverHttps](INFO): Sending 47 bytes from file Logs/20140528T154413/Courier0028.lzma
2014-05-28T17:18:06.290Z,1401297486.290 [DataOverHttps](INFO): Moved sent file to Logs/20140528T154413/Courier0028.lzma.bak
2014-05-28T17:18:06.290Z,1401297486.290 [DataOverHttps](INFO): SBD MOMSN=980468
2014-05-28T17:18:17.892Z,1401297497.892 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20140528T154413/Courier0032.lzma
2014-05-28T17:18:18.833Z,1401297498.833 [DataOverHttps](INFO): Moved sent file to Logs/20140528T154413/Courier0032.lzma.bak
2014-05-28T17:18:18.833Z,1401297498.833 [DataOverHttps](INFO): SBD MOMSN=980470
2014-05-28T17:18:26.236Z,1401297506.236 [DataOverHttps](INFO): Sending 193 bytes from file Logs/20140528T171454/Courier0000.lzma
2014-05-28T17:18:27.295Z,1401297507.295 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Courier0000.lzma.bak
2014-05-28T17:18:27.295Z,1401297507.295 [DataOverHttps](INFO): SBD MOMSN=980472
2014-05-28T17:18:35.396Z,1401297515.396 [DataOverHttps](INFO): Sending 291 bytes from file Logs/20140528T154413/Express0029.lzma
2014-05-28T17:18:36.429Z,1401297516.429 [DataOverHttps](INFO): Moved sent file to Logs/20140528T154413/Express0029.lzma.bak
2014-05-28T17:18:36.430Z,1401297516.430 [DataOverHttps](INFO): SBD MOMSN=980475
2014-05-28T17:18:39.727Z,1401297519.727 [Startup:StartupSatComms:B](INFO): Timed out from 2014-05-28T17:17:39.7Z
2014-05-28T17:18:39.727Z,1401297519.727 [Startup:StartupSatComms:B] Stopped
2014-05-28T17:18:39.727Z,1401297519.727 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2014-05-28T17:18:39.727Z,1401297519.727 [Startup:StartupSatComms] Stopped
2014-05-28T17:18:39.727Z,1401297519.727 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2014-05-28T17:18:39.733Z,1401297519.733 [Startup](INFO): Completed Startup
2014-05-28T17:18:39.733Z,1401297519.733 [Startup] Stopped
2014-05-28T17:18:39.733Z,1401297519.733 [Startup](INFO): Aggregate::uninitialize Startup
2014-05-28T17:18:39.733Z,1401297519.733 [Startup:A.GoToSurface] Stopped
2014-05-28T17:18:39.733Z,1401297519.733 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-28T17:18:40.250Z,1401297520.250 [MissionManager](IMPORTANT): Started mission Default
2014-05-28T17:18:40.250Z,1401297520.250 [Default] Running Loop=1
2014-05-28T17:18:40.250Z,1401297520.250 [Default](INFO): Aggregate::initialize Default
2014-05-28T17:18:40.251Z,1401297520.251 [Default:Iridium] Running Loop=1
2014-05-28T17:18:40.251Z,1401297520.251 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-28T17:18:40.251Z,1401297520.251 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-28T17:18:40.251Z,1401297520.251 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-28T17:18:40.251Z,1401297520.251 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-28T17:18:40.251Z,1401297520.251 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-28T17:18:40.252Z,1401297520.252 [Default:CallIridium] Running Loop=1
2014-05-28T17:18:40.252Z,1401297520.252 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-05-28T17:18:40.252Z,1401297520.252 [Default:CallIridium:A] Running Loop=1
2014-05-28T17:18:40.258Z,1401297520.258 [Default:CallIridium:A] Stopped
2014-05-28T17:18:40.258Z,1401297520.258 [Default:CallIridium:B] Running Loop=1
2014-05-28T17:18:40.259Z,1401297520.259 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-05-28T17:18:40.280Z,1401297520.280 [Default:Iridium:B.GoToSurface] Stopped
2014-05-28T17:18:40.281Z,1401297520.281 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-28T17:18:40.281Z,1401297520.281 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-28T17:18:40.281Z,1401297520.281 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-28T17:18:40.315Z,1401297520.315 [Default:GPS] Running Loop=1
2014-05-28T17:18:40.315Z,1401297520.315 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-05-28T17:18:40.315Z,1401297520.315 [Default:GPS:A.SetSpeed] Running Loop=1
2014-05-28T17:18:40.315Z,1401297520.315 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-05-28T17:18:40.316Z,1401297520.316 [Default:GPS:B.GoToSurface] Running Loop=1
2014-05-28T17:18:40.316Z,1401297520.316 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-28T17:18:40.342Z,1401297520.342 [Default:GPS:B.GoToSurface] Stopped
2014-05-28T17:18:40.342Z,1401297520.342 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-28T17:18:40.342Z,1401297520.342 [Default:GPS:Read_GPS] Running Loop=1
2014-05-28T17:18:40.342Z,1401297520.342 [Default:GPS:A.SetSpeed] Running Loop=1
2014-05-28T17:18:40.928Z,1401297520.928 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2014-05-28T17:18:40.939Z,1401297520.939 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2014-05-28T17:18:45.065Z,1401297525.065 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20140528T154413/Express0033.lzma
2014-05-28T17:18:46.054Z,1401297526.054 [DataOverHttps](INFO): Moved sent file to Logs/20140528T154413/Express0033.lzma.bak
2014-05-28T17:18:46.055Z,1401297526.055 [DataOverHttps](INFO): SBD MOMSN=980482
2014-05-28T17:18:48.921Z,1401297528.921 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T17:18:48.921Z,1401297528.921 [DVL_micro] Data Fault, FailCount= 1
2014-05-28T17:18:48.921Z,1401297528.921 [DVL_micro](ERROR): Data Fault
2014-05-28T17:18:49.038Z,1401297529.038 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T17:18:49.500Z,1401297529.500 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T17:18:49.972Z,1401297529.972 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T17:18:49.972Z,1401297529.972 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T17:18:49.972Z,1401297529.972 [DVL_micro](ERROR): Hardware Fault
2014-05-28T17:18:50.480Z,1401297530.480 [DVL_micro](INFO): Initializing
2014-05-28T17:18:50.629Z,1401297530.629 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T17:18:50.630Z,1401297530.630 [DVL_micro] No Fault, FailCount= 1
2014-05-28T17:18:53.611Z,1401297533.611 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20140528T171454/Courier0004.lzma
2014-05-28T17:18:54.616Z,1401297534.616 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Courier0004.lzma.bak
2014-05-28T17:18:54.616Z,1401297534.616 [DataOverHttps](INFO): SBD MOMSN=980484
2014-05-28T17:19:03.049Z,1401297543.049 [DataOverHttps](INFO): Sending 957 bytes from file Logs/20140528T171454/Express0001.lzma
2014-05-28T17:19:04.038Z,1401297544.037 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Express0001.lzma.bak
2014-05-28T17:19:04.038Z,1401297544.038 [DataOverHttps](INFO): SBD MOMSN=980486
2014-05-28T17:19:11.947Z,1401297551.947 [DataOverHttps](INFO): Sending 106 bytes from file Logs/20140528T171454/Express0005.lzma
2014-05-28T17:19:20.870Z,1401297560.870 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Express0005.lzma.bak
2014-05-28T17:19:20.870Z,1401297560.870 [DataOverHttps](INFO): SBD MOMSN=980500
2014-05-28T17:19:28.562Z,1401297568.562 [HFRadarModelCalc](IMPORTANT): Forecast time 20140528T140000: published 50 modes in rows, 61 hours in columns, 3050 elements.
2014-05-28T17:19:30.143Z,1401297570.143 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients.
2014-05-28T17:19:30.182Z,1401297570.182 [Default:Iridium:Read_Iridium] Stopped
2014-05-28T17:19:30.183Z,1401297570.183 [Default:Iridium](INFO): Completed Default:Iridium
2014-05-28T17:19:30.183Z,1401297570.183 [Default:Iridium] Stopped
2014-05-28T17:19:30.183Z,1401297570.183 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-28T17:19:30.183Z,1401297570.183 [Default:Iridium:A.SetSpeed] Stopped
2014-05-28T17:19:30.183Z,1401297570.183 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-28T17:19:30.183Z,1401297570.183 [Default:WaitAtTheSurface] Running Loop=1
2014-05-28T17:19:30.184Z,1401297570.184 [Default:WaitAtTheSurface](INFO): Aggregate::initialize Default:WaitAtTheSurface
2014-05-28T17:19:30.184Z,1401297570.184 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Running Loop=1
2014-05-28T17:19:30.184Z,1401297570.184 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Initialize.
2014-05-28T17:19:30.184Z,1401297570.184 [Default:WaitAtTheSurface:B.GoToSurface] Running Loop=1
2014-05-28T17:19:30.184Z,1401297570.184 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-28T17:19:31.198Z,1401297571.198 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 43 of 46
2014-05-28T17:19:31.198Z,1401297571.198 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 -900 -750 -723 -788 2 2 3 2 -236.2 50.7 -852.3 2 214.1 111.9 -852.3 2 -236 50 -852 2 214 111 -852 2 -0.40 0.13 219.7 -3.0 18.1 0.005 35.0 1489 103
2014-05-28T17:19:31.294Z,1401297571.294 [Default:WaitAtTheSurface:B.GoToSurface] Running Loop=1
2014-05-28T17:19:31.310Z,1401297571.310 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Running Loop=1
2014-05-28T17:19:31.319Z,1401297571.319 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-05-28T17:19:31.319Z,1401297571.319 [Default:CallIridium:B] Stopped
2014-05-28T17:19:31.320Z,1401297571.320 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-28T17:19:31.320Z,1401297571.320 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-05-28T17:19:31.320Z,1401297571.320 [Default:CallIridium] Stopped
2014-05-28T17:19:31.320Z,1401297571.320 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-28T17:20:58.335Z,1401297658.335 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2014-05-28T17:21:54.823Z,1401297714.823 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T17:21:54.823Z,1401297714.823 [DVL_micro] Data Fault, FailCount= 1
2014-05-28T17:21:54.823Z,1401297714.823 [DVL_micro](ERROR): Data Fault
2014-05-28T17:21:54.937Z,1401297714.937 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T17:21:55.364Z,1401297715.364 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T17:21:55.838Z,1401297715.838 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T17:21:55.838Z,1401297715.838 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T17:21:55.838Z,1401297715.838 [DVL_micro](ERROR): Hardware Fault
2014-05-28T17:21:56.352Z,1401297716.352 [DVL_micro](INFO): Initializing
2014-05-28T17:21:56.460Z,1401297716.460 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T17:21:56.461Z,1401297716.461 [DVL_micro] No Fault, FailCount= 1
2014-05-28T17:24:22.217Z,1401297862.217 [Default:CallIridium] Running Loop=1
2014-05-28T17:24:22.217Z,1401297862.217 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-05-28T17:24:22.217Z,1401297862.217 [Default:CallIridium:A] Running Loop=1
2014-05-28T17:24:22.217Z,1401297862.217 [Default:CallIridium:A] Stopped
2014-05-28T17:24:22.218Z,1401297862.218 [Default:CallIridium:B] Running Loop=1
2014-05-28T17:24:22.218Z,1401297862.218 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-05-28T17:24:22.705Z,1401297862.705 [Default:Iridium] Running Loop=1
2014-05-28T17:24:22.705Z,1401297862.705 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-28T17:24:22.705Z,1401297862.705 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-28T17:24:22.705Z,1401297862.705 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-28T17:24:22.706Z,1401297862.706 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-28T17:24:22.706Z,1401297862.706 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-28T17:24:22.706Z,1401297862.706 [Default:Iridium:B.GoToSurface] Stopped
2014-05-28T17:24:22.706Z,1401297862.706 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-28T17:24:22.707Z,1401297862.707 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-28T17:24:26.137Z,1401297866.137 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20140528T171454/Courier0008.lzma
2014-05-28T17:24:27.072Z,1401297867.072 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Courier0008.lzma.bak
2014-05-28T17:24:27.072Z,1401297867.072 [DataOverHttps](INFO): SBD MOMSN=980503
2014-05-28T17:24:34.842Z,1401297874.842 [DataOverHttps](INFO): Sending 472 bytes from file Logs/20140528T171454/Express0009.lzma
2014-05-28T17:24:35.865Z,1401297875.865 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Express0009.lzma.bak
2014-05-28T17:24:35.865Z,1401297875.865 [DataOverHttps](INFO): SBD MOMSN=980505
2014-05-28T17:24:43.454Z,1401297883.454 [HFRadarModelCalc](IMPORTANT): Forecast time 20140528T140000: published 50 modes in rows, 61 hours in columns, 3050 elements.
2014-05-28T17:24:45.048Z,1401297885.048 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients.
2014-05-28T17:24:45.092Z,1401297885.092 [Default:Iridium:Read_Iridium] Stopped
2014-05-28T17:24:45.092Z,1401297885.092 [Default:Iridium](INFO): Completed Default:Iridium
2014-05-28T17:24:45.093Z,1401297885.093 [Default:Iridium] Stopped
2014-05-28T17:24:45.093Z,1401297885.093 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-28T17:24:45.093Z,1401297885.093 [Default:Iridium:A.SetSpeed] Stopped
2014-05-28T17:24:45.093Z,1401297885.093 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-28T17:24:46.128Z,1401297886.128 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-05-28T17:24:46.128Z,1401297886.128 [Default:CallIridium:B] Stopped
2014-05-28T17:24:46.151Z,1401297886.151 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-28T17:24:46.152Z,1401297886.152 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-05-28T17:24:46.152Z,1401297886.152 [Default:CallIridium] Stopped
2014-05-28T17:24:46.152Z,1401297886.152 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-28T17:25:01.230Z,1401297901.230 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T17:25:01.230Z,1401297901.230 [DVL_micro] Data Fault, FailCount= 1
2014-05-28T17:25:01.230Z,1401297901.230 [DVL_micro](ERROR): Data Fault
2014-05-28T17:25:01.389Z,1401297901.389 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T17:25:01.885Z,1401297901.885 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T17:25:02.340Z,1401297902.340 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T17:25:02.341Z,1401297902.341 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T17:25:02.341Z,1401297902.341 [DVL_micro](ERROR): Hardware Fault
2014-05-28T17:25:02.822Z,1401297902.822 [DVL_micro](INFO): Initializing
2014-05-28T17:25:02.943Z,1401297902.943 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T17:25:02.944Z,1401297902.944 [DVL_micro] No Fault, FailCount= 1
2014-05-28T17:25:56.675Z,1401297956.675 [NAL9602](FAULT): GPS failed to acquire within timeout.
2014-05-28T17:25:56.675Z,1401297956.675 [NAL9602] Data Fault, FailCount= 1
2014-05-28T17:25:56.676Z,1401297956.676 [NAL9602](ERROR): Data Fault
2014-05-28T17:25:56.785Z,1401297956.785 [CBIT](ERROR): Data Fault in component: NAL9602
2014-05-28T17:25:57.154Z,1401297957.154 [NAL9602](INFO): Powering down
2014-05-28T17:25:58.214Z,1401297958.214 [CBIT](INFO): Clearing failed state for component NAL9602
2014-05-28T17:25:58.215Z,1401297958.215 [NAL9602] No Fault, FailCount= 1
2014-05-28T17:26:02.233Z,1401297962.233 [NAL9602](INFO): Powering up NAL9602
2014-05-28T17:26:13.116Z,1401297973.116 [NAL9602](INFO): NAL9602 initialized
2014-05-28T17:28:03.532Z,1401298083.532 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:99 Calculated:118
2014-05-28T17:28:03.532Z,1401298083.532 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -775 -913 -754 -778 2 2 3 2 -28.0 -180.2  -94.4 156.0 -868.2 2 -28 -180 -868 2 -94 156 -868 2 -0.48 0.11 220.0 -3.0 18.3 0.005 35.0 1489 99
2014-05-28T17:28:07.939Z,1401298087.939 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T17:28:07.939Z,1401298087.939 [DVL_micro] Data Fault, FailCount= 1
2014-05-28T17:28:07.939Z,1401298087.939 [DVL_micro](ERROR): Data Fault
2014-05-28T17:28:08.069Z,1401298088.069 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T17:28:08.499Z,1401298088.499 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T17:28:08.977Z,1401298088.977 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T17:28:08.977Z,1401298088.977 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T17:28:08.977Z,1401298088.977 [DVL_micro](ERROR): Hardware Fault
2014-05-28T17:28:09.529Z,1401298089.529 [DVL_micro](INFO): Initializing
2014-05-28T17:28:09.658Z,1401298089.658 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T17:28:09.658Z,1401298089.658 [DVL_micro] No Fault, FailCount= 1
2014-05-28T17:29:37.132Z,1401298177.132 [Default:CallIridium] Running Loop=1
2014-05-28T17:29:37.132Z,1401298177.132 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-05-28T17:29:37.132Z,1401298177.132 [Default:CallIridium:A] Running Loop=1
2014-05-28T17:29:37.133Z,1401298177.133 [Default:CallIridium:A] Stopped
2014-05-28T17:29:37.133Z,1401298177.133 [Default:CallIridium:B] Running Loop=1
2014-05-28T17:29:37.133Z,1401298177.133 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-05-28T17:29:37.699Z,1401298177.699 [Default:Iridium] Running Loop=1
2014-05-28T17:29:37.700Z,1401298177.700 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-28T17:29:37.700Z,1401298177.700 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-28T17:29:37.700Z,1401298177.700 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-28T17:29:37.700Z,1401298177.700 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-28T17:29:37.700Z,1401298177.700 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-28T17:29:37.713Z,1401298177.713 [Default:Iridium:B.GoToSurface] Stopped
2014-05-28T17:29:37.713Z,1401298177.713 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-28T17:29:37.713Z,1401298177.713 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-28T17:29:41.653Z,1401298181.653 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20140528T171454/Courier0012.lzma
2014-05-28T17:29:42.612Z,1401298182.612 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Courier0012.lzma.bak
2014-05-28T17:29:42.613Z,1401298182.613 [DataOverHttps](INFO): SBD MOMSN=980513
2014-05-28T17:29:50.458Z,1401298190.458 [DataOverHttps](INFO): Sending 284 bytes from file Logs/20140528T171454/Express0013.lzma
2014-05-28T17:29:51.438Z,1401298191.438 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Express0013.lzma.bak
2014-05-28T17:29:51.438Z,1401298191.438 [DataOverHttps](INFO): SBD MOMSN=980515
2014-05-28T17:29:59.085Z,1401298199.085 [HFRadarModelCalc](IMPORTANT): Forecast time 20140528T150000: published 50 modes in rows, 61 hours in columns, 3050 elements.
2014-05-28T17:30:00.675Z,1401298200.675 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients.
2014-05-28T17:30:00.688Z,1401298200.688 [Default:Iridium:Read_Iridium] Stopped
2014-05-28T17:30:00.692Z,1401298200.692 [Default:Iridium](INFO): Completed Default:Iridium
2014-05-28T17:30:00.693Z,1401298200.693 [Default:Iridium] Stopped
2014-05-28T17:30:00.693Z,1401298200.693 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-28T17:30:00.693Z,1401298200.693 [Default:Iridium:A.SetSpeed] Stopped
2014-05-28T17:30:00.693Z,1401298200.693 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-28T17:30:01.689Z,1401298201.689 [DVL_micro](ERROR): No DVL communication! Re-initializing
2014-05-28T17:30:01.689Z,1401298201.689 [DVL_micro] Communications Fault, FailCount= 1
2014-05-28T17:30:01.689Z,1401298201.689 [DVL_micro](ERROR): Communications Fault
2014-05-28T17:30:01.792Z,1401298201.792 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-05-28T17:30:01.792Z,1401298201.792 [Default:CallIridium:B] Stopped
2014-05-28T17:30:01.792Z,1401298201.792 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-28T17:30:01.793Z,1401298201.793 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-05-28T17:30:01.793Z,1401298201.793 [Default:CallIridium] Stopped
2014-05-28T17:30:01.793Z,1401298201.793 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-28T17:30:01.802Z,1401298201.802 [CBIT](ERROR): Communications Fault in component: DVL_micro
2014-05-28T17:30:03.269Z,1401298203.269 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T17:30:03.828Z,1401298203.828 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T17:30:03.828Z,1401298203.828 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T17:30:03.829Z,1401298203.829 [DVL_micro](ERROR): Hardware Fault
2014-05-28T17:30:04.331Z,1401298204.331 [DVL_micro](INFO): Initializing
2014-05-28T17:30:04.446Z,1401298204.446 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T17:30:04.447Z,1401298204.447 [DVL_micro] No Fault, FailCount= 1
2014-05-28T17:31:13.704Z,1401298273.704 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T17:31:13.704Z,1401298273.704 [DVL_micro] Data Fault, FailCount= 1
2014-05-28T17:31:13.704Z,1401298273.704 [DVL_micro](ERROR): Data Fault
2014-05-28T17:31:13.840Z,1401298273.840 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T17:31:14.383Z,1401298274.383 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T17:31:14.865Z,1401298274.865 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T17:31:14.865Z,1401298274.865 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T17:31:14.865Z,1401298274.865 [DVL_micro](ERROR): Hardware Fault
2014-05-28T17:31:15.360Z,1401298275.360 [DVL_micro](INFO): Initializing
2014-05-28T17:31:15.512Z,1401298275.512 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T17:31:15.512Z,1401298275.512 [DVL_micro] No Fault, FailCount= 1
2014-05-28T17:34:20.334Z,1401298460.334 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T17:34:20.339Z,1401298460.339 [DVL_micro] Data Fault, FailCount= 1
2014-05-28T17:34:20.339Z,1401298460.339 [DVL_micro](ERROR): Data Fault
2014-05-28T17:34:20.497Z,1401298460.497 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T17:34:20.912Z,1401298460.912 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T17:34:21.370Z,1401298461.370 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T17:34:21.370Z,1401298461.370 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T17:34:21.370Z,1401298461.370 [DVL_micro](ERROR): Hardware Fault
2014-05-28T17:34:21.870Z,1401298461.870 [DVL_micro](INFO): Initializing
2014-05-28T17:34:21.968Z,1401298461.968 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T17:34:21.968Z,1401298461.968 [DVL_micro] No Fault, FailCount= 1
2014-05-28T17:34:52.907Z,1401298492.907 [Default:CallIridium] Running Loop=1
2014-05-28T17:34:52.907Z,1401298492.907 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-05-28T17:34:52.907Z,1401298492.907 [Default:CallIridium:A] Running Loop=1
2014-05-28T17:34:52.908Z,1401298492.908 [Default:CallIridium:A] Stopped
2014-05-28T17:34:52.908Z,1401298492.908 [Default:CallIridium:B] Running Loop=1
2014-05-28T17:34:52.908Z,1401298492.908 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-05-28T17:34:53.394Z,1401298493.394 [Default:Iridium] Running Loop=1
2014-05-28T17:34:53.394Z,1401298493.394 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-28T17:34:53.394Z,1401298493.394 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-28T17:34:53.398Z,1401298493.398 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-28T17:34:53.398Z,1401298493.398 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-28T17:34:53.398Z,1401298493.398 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-28T17:34:53.399Z,1401298493.399 [Default:Iridium:B.GoToSurface] Stopped
2014-05-28T17:34:53.399Z,1401298493.399 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-28T17:34:53.399Z,1401298493.399 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-28T17:34:56.864Z,1401298496.864 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20140528T171454/Courier0016.lzma
2014-05-28T17:34:57.869Z,1401298497.869 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Courier0016.lzma.bak
2014-05-28T17:34:57.869Z,1401298497.869 [DataOverHttps](INFO): SBD MOMSN=980524
2014-05-28T17:35:05.806Z,1401298505.806 [DataOverHttps](INFO): Sending 260 bytes from file Logs/20140528T171454/Express0017.lzma
2014-05-28T17:35:06.823Z,1401298506.823 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Express0017.lzma.bak
2014-05-28T17:35:06.824Z,1401298506.824 [DataOverHttps](INFO): SBD MOMSN=980526
2014-05-28T17:35:15.611Z,1401298515.611 [HFRadarModelCalc](IMPORTANT): Forecast time 20140528T150000: published 50 modes in rows, 61 hours in columns, 3050 elements.
2014-05-28T17:35:17.239Z,1401298517.239 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients.
2014-05-28T17:35:17.280Z,1401298517.280 [Default:Iridium:Read_Iridium] Stopped
2014-05-28T17:35:17.280Z,1401298517.280 [Default:Iridium](INFO): Completed Default:Iridium
2014-05-28T17:35:17.280Z,1401298517.280 [Default:Iridium] Stopped
2014-05-28T17:35:17.280Z,1401298517.280 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-28T17:35:17.280Z,1401298517.280 [Default:Iridium:A.SetSpeed] Stopped
2014-05-28T17:35:17.280Z,1401298517.280 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-28T17:35:18.235Z,1401298518.235 [DVL_micro](ERROR): No DVL communication! Re-initializing
2014-05-28T17:35:18.235Z,1401298518.235 [DVL_micro] Communications Fault, FailCount= 1
2014-05-28T17:35:18.235Z,1401298518.235 [DVL_micro](ERROR): Communications Fault
2014-05-28T17:35:18.296Z,1401298518.296 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-05-28T17:35:18.296Z,1401298518.296 [Default:CallIridium:B] Stopped
2014-05-28T17:35:18.296Z,1401298518.296 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-28T17:35:18.305Z,1401298518.305 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-05-28T17:35:18.305Z,1401298518.305 [Default:CallIridium] Stopped
2014-05-28T17:35:18.305Z,1401298518.305 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-28T17:35:18.340Z,1401298518.340 [CBIT](ERROR): Communications Fault in component: DVL_micro
2014-05-28T17:35:19.839Z,1401298519.839 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T17:35:20.374Z,1401298520.374 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T17:35:20.374Z,1401298520.374 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T17:35:20.374Z,1401298520.374 [DVL_micro](ERROR): Hardware Fault
2014-05-28T17:35:20.949Z,1401298520.949 [DVL_micro](INFO): Initializing
2014-05-28T17:35:21.057Z,1401298521.057 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T17:35:21.057Z,1401298521.057 [DVL_micro] No Fault, FailCount= 1
2014-05-28T17:36:15.756Z,1401298575.756 [NAL9602](FAULT): GPS failed to acquire within timeout.
2014-05-28T17:36:15.756Z,1401298575.756 [NAL9602] Data Fault, FailCount= 2
2014-05-28T17:36:15.756Z,1401298575.756 [NAL9602](ERROR): Data Fault
2014-05-28T17:36:15.855Z,1401298575.855 [CBIT](ERROR): Data Fault in component: NAL9602
2014-05-28T17:36:15.855Z,1401298575.855 [CBIT](CRITICAL): Data Fault in component: NAL9602
2014-05-28T17:36:16.225Z,1401298576.225 [NAL9602](INFO): Powering down
2014-05-28T17:36:16.344Z,1401298576.344 [CommandLine](FAULT): Scheduling is paused
2014-05-28T17:37:25.937Z,1401298645.937 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T17:37:25.937Z,1401298645.937 [DVL_micro] Data Fault, FailCount= 1
2014-05-28T17:37:25.937Z,1401298645.937 [DVL_micro](ERROR): Data Fault
2014-05-28T17:37:26.056Z,1401298646.056 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T17:37:26.480Z,1401298646.480 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T17:37:26.950Z,1401298646.950 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T17:37:26.950Z,1401298646.950 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T17:37:26.950Z,1401298646.950 [DVL_micro](ERROR): Hardware Fault
2014-05-28T17:37:27.482Z,1401298647.482 [DVL_micro](INFO): Initializing
2014-05-28T17:37:27.602Z,1401298647.602 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T17:37:27.603Z,1401298647.603 [DVL_micro] No Fault, FailCount= 1
2014-05-28T17:38:16.001Z,1401298696.001 [CBIT](INFO): Clearing failed count for component NAL9602
2014-05-28T17:38:16.001Z,1401298696.001 [NAL9602] No Fault, FailCount= 2
2014-05-28T17:38:16.352Z,1401298696.352 [NAL9602](INFO): Powering up NAL9602
2014-05-28T17:38:27.234Z,1401298707.234 [NAL9602](INFO): NAL9602 initialized
2014-05-28T17:40:08.083Z,1401298808.083 [Default:CallIridium] Running Loop=1
2014-05-28T17:40:08.083Z,1401298808.083 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-05-28T17:40:08.083Z,1401298808.083 [Default:CallIridium:A] Running Loop=1
2014-05-28T17:40:08.083Z,1401298808.083 [Default:CallIridium:A] Stopped
2014-05-28T17:40:08.084Z,1401298808.084 [Default:CallIridium:B] Running Loop=1
2014-05-28T17:40:08.084Z,1401298808.084 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-05-28T17:40:08.561Z,1401298808.561 [Default:Iridium] Running Loop=1
2014-05-28T17:40:08.561Z,1401298808.561 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-28T17:40:08.561Z,1401298808.561 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-28T17:40:08.561Z,1401298808.561 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-28T17:40:08.561Z,1401298808.561 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-28T17:40:08.561Z,1401298808.561 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-28T17:40:08.562Z,1401298808.562 [Default:Iridium:B.GoToSurface] Stopped
2014-05-28T17:40:08.562Z,1401298808.562 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-28T17:40:08.562Z,1401298808.562 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-28T17:40:12.085Z,1401298812.085 [DataOverHttps](INFO): Sending 111 bytes from file Logs/20140528T171454/Courier0020.lzma
2014-05-28T17:40:13.022Z,1401298813.022 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Courier0020.lzma.bak
2014-05-28T17:40:13.022Z,1401298813.022 [DataOverHttps](INFO): SBD MOMSN=980534
2014-05-28T17:40:21.533Z,1401298821.533 [DataOverHttps](INFO): Sending 332 bytes from file Logs/20140528T171454/Express0021.lzma
2014-05-28T17:40:22.589Z,1401298822.589 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Express0021.lzma.bak
2014-05-28T17:40:22.590Z,1401298822.590 [DataOverHttps](INFO): SBD MOMSN=980537
2014-05-28T17:40:30.243Z,1401298830.243 [HFRadarModelCalc](IMPORTANT): Forecast time 20140528T150000: published 50 modes in rows, 61 hours in columns, 3050 elements.
2014-05-28T17:40:31.808Z,1401298831.808 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients.
2014-05-28T17:40:31.846Z,1401298831.846 [Default:Iridium:Read_Iridium] Stopped
2014-05-28T17:40:31.847Z,1401298831.847 [Default:Iridium](INFO): Completed Default:Iridium
2014-05-28T17:40:31.847Z,1401298831.847 [Default:Iridium] Stopped
2014-05-28T17:40:31.847Z,1401298831.847 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-28T17:40:31.847Z,1401298831.847 [Default:Iridium:A.SetSpeed] Stopped
2014-05-28T17:40:31.847Z,1401298831.847 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-28T17:40:32.794Z,1401298832.794 [DVL_micro](ERROR): No DVL communication! Re-initializing
2014-05-28T17:40:32.795Z,1401298832.795 [DVL_micro] Communications Fault, FailCount= 1
2014-05-28T17:40:32.795Z,1401298832.795 [DVL_micro](ERROR): Communications Fault
2014-05-28T17:40:32.886Z,1401298832.886 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-05-28T17:40:32.886Z,1401298832.886 [Default:CallIridium:B] Stopped
2014-05-28T17:40:32.887Z,1401298832.887 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-28T17:40:32.887Z,1401298832.887 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-05-28T17:40:32.887Z,1401298832.887 [Default:CallIridium] Stopped
2014-05-28T17:40:32.887Z,1401298832.887 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-28T17:40:32.896Z,1401298832.896 [CBIT](ERROR): Communications Fault in component: DVL_micro
2014-05-28T17:40:34.431Z,1401298834.431 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T17:40:35.004Z,1401298835.004 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T17:40:35.004Z,1401298835.004 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T17:40:35.004Z,1401298835.004 [DVL_micro](ERROR): Hardware Fault
2014-05-28T17:40:35.593Z,1401298835.593 [DVL_micro](INFO): Initializing
2014-05-28T17:40:35.701Z,1401298835.701 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T17:40:35.701Z,1401298835.701 [DVL_micro] No Fault, FailCount= 1
2014-05-28T17:40:39.895Z,1401298839.895 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T17:40:39.896Z,1401298839.896 [DVL_micro] Data Fault, FailCount= 2
2014-05-28T17:40:39.896Z,1401298839.896 [DVL_micro](ERROR): Data Fault
2014-05-28T17:40:40.012Z,1401298840.012 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T17:40:40.456Z,1401298840.456 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T17:40:40.975Z,1401298840.975 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T17:40:40.975Z,1401298840.975 [DVL_micro] Hardware Fault, FailCount= 2
2014-05-28T17:40:40.975Z,1401298840.975 [DVL_micro](ERROR): Hardware Fault
2014-05-28T17:40:41.474Z,1401298841.474 [DVL_micro](INFO): Initializing
2014-05-28T17:40:41.620Z,1401298841.620 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T17:40:41.620Z,1401298841.620 [DVL_micro] No Fault, FailCount= 2
2014-05-28T17:40:51.906Z,1401298851.906 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46
2014-05-28T17:40:51.906Z,1401298851.906 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -674 -505 -615 -879 2 2 3 2 -78.7 499.2 -720.7 2 380.6 -332.5 -720.7 2 -78 499 -7 -332 -720 2 -0.41 0.13 219.9 -3.0 18.5 0.005 35.0 1489 108
2014-05-28T17:43:46.355Z,1401299026.355 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T17:43:46.355Z,1401299026.355 [DVL_micro] Data Fault, FailCount= 1
2014-05-28T17:43:46.355Z,1401299026.355 [DVL_micro](ERROR): Data Fault
2014-05-28T17:43:46.514Z,1401299026.514 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T17:43:46.938Z,1401299026.938 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T17:43:47.492Z,1401299027.492 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T17:43:47.492Z,1401299027.492 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T17:43:47.492Z,1401299027.492 [DVL_micro](ERROR): Hardware Fault
2014-05-28T17:43:48.011Z,1401299028.011 [DVL_micro](INFO): Initializing
2014-05-28T17:43:48.188Z,1401299028.188 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T17:43:48.189Z,1401299028.189 [DVL_micro] No Fault, FailCount= 1
2014-05-28T17:44:29.805Z,1401299069.805 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 43 of 46
2014-05-28T17:44:29.806Z,1401299069.806 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -731 -758 -802 -3 2 94.8 201.5 -862.9 2 56.9 -215.3 -862.9 2 94 201 -862 2 56 -215 -862 0.12 220.0 -3.0 18.6 0.005 35.0 1489 109
2014-05-28T17:45:23.686Z,1401299123.686 [Default:CallIridium] Running Loop=1
2014-05-28T17:45:23.686Z,1401299123.686 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-05-28T17:45:23.686Z,1401299123.686 [Default:CallIridium:A] Running Loop=1
2014-05-28T17:45:23.687Z,1401299123.687 [Default:CallIridium:A] Stopped
2014-05-28T17:45:23.687Z,1401299123.687 [Default:CallIridium:B] Running Loop=1
2014-05-28T17:45:23.687Z,1401299123.687 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-05-28T17:45:24.191Z,1401299124.191 [Default:Iridium] Running Loop=1
2014-05-28T17:45:24.191Z,1401299124.191 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-28T17:45:24.191Z,1401299124.191 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-28T17:45:24.191Z,1401299124.191 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-28T17:45:24.191Z,1401299124.191 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-28T17:45:24.191Z,1401299124.191 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-28T17:45:24.196Z,1401299124.196 [Default:Iridium:B.GoToSurface] Stopped
2014-05-28T17:45:24.196Z,1401299124.196 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-28T17:45:24.196Z,1401299124.196 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-28T17:45:28.571Z,1401299128.571 [DataOverHttps](INFO): Sending 46 bytes from file Logs/20140528T171454/Courier0024.lzma
2014-05-28T17:45:29.516Z,1401299129.516 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Courier0024.lzma.bak
2014-05-28T17:45:29.517Z,1401299129.517 [DataOverHttps](INFO): SBD MOMSN=980545
2014-05-28T17:45:37.406Z,1401299137.406 [DataOverHttps](INFO): Sending 271 bytes from file Logs/20140528T171454/Express0025.lzma
2014-05-28T17:45:38.463Z,1401299138.463 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Express0025.lzma.bak
2014-05-28T17:45:38.463Z,1401299138.463 [DataOverHttps](INFO): SBD MOMSN=980547
2014-05-28T17:45:46.147Z,1401299146.147 [HFRadarModelCalc](IMPORTANT): Forecast time 20140528T150000: published 50 modes in rows, 61 hours in columns, 3050 elements.
2014-05-28T17:45:47.703Z,1401299147.703 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients.
2014-05-28T17:45:47.727Z,1401299147.727 [Default:Iridium:Read_Iridium] Stopped
2014-05-28T17:45:47.727Z,1401299147.727 [Default:Iridium](INFO): Completed Default:Iridium
2014-05-28T17:45:47.727Z,1401299147.727 [Default:Iridium] Stopped
2014-05-28T17:45:47.727Z,1401299147.727 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-28T17:45:47.727Z,1401299147.727 [Default:Iridium:A.SetSpeed] Stopped
2014-05-28T17:45:47.727Z,1401299147.727 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-28T17:45:48.703Z,1401299148.703 [DVL_micro](ERROR): No DVL communication! Re-initializing
2014-05-28T17:45:48.703Z,1401299148.703 [DVL_micro] Communications Fault, FailCount= 1
2014-05-28T17:45:48.703Z,1401299148.703 [DVL_micro](ERROR): Communications Fault
2014-05-28T17:45:48.878Z,1401299148.878 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-05-28T17:45:48.878Z,1401299148.878 [Default:CallIridium:B] Stopped
2014-05-28T17:45:48.879Z,1401299148.879 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-28T17:45:48.879Z,1401299148.879 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-05-28T17:45:48.879Z,1401299148.879 [Default:CallIridium] Stopped
2014-05-28T17:45:48.879Z,1401299148.879 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-28T17:45:48.930Z,1401299148.930 [CBIT](ERROR): Communications Fault in component: DVL_micro
2014-05-28T17:45:50.409Z,1401299150.409 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T17:45:50.923Z,1401299150.923 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T17:45:50.923Z,1401299150.923 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T17:45:50.923Z,1401299150.923 [DVL_micro](ERROR): Hardware Fault
2014-05-28T17:45:51.457Z,1401299151.457 [DVL_micro](INFO): Initializing
2014-05-28T17:45:51.566Z,1401299151.566 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T17:45:51.566Z,1401299151.566 [DVL_micro] No Fault, FailCount= 1
2014-05-28T17:46:52.791Z,1401299212.791 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T17:46:52.791Z,1401299212.791 [DVL_micro] Data Fault, FailCount= 1
2014-05-28T17:46:52.792Z,1401299212.792 [DVL_micro](ERROR): Data Fault
2014-05-28T17:46:52.945Z,1401299212.945 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T17:46:53.383Z,1401299213.383 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T17:46:53.857Z,1401299213.857 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T17:46:53.857Z,1401299213.857 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T17:46:53.857Z,1401299213.857 [DVL_micro](ERROR): Hardware Fault
2014-05-28T17:46:54.321Z,1401299214.321 [DVL_micro](INFO): Initializing
2014-05-28T17:46:54.458Z,1401299214.458 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T17:46:54.458Z,1401299214.458 [DVL_micro] No Fault, FailCount= 1
2014-05-28T17:48:28.649Z,1401299308.649 [NAL9602](FAULT): GPS failed to acquire within timeout.
2014-05-28T17:48:28.649Z,1401299308.649 [NAL9602] Data Fault, FailCount= 1
2014-05-28T17:48:28.649Z,1401299308.649 [NAL9602](ERROR): Data Fault
2014-05-28T17:48:28.748Z,1401299308.748 [CBIT](ERROR): Data Fault in component: NAL9602
2014-05-28T17:48:29.114Z,1401299309.114 [NAL9602](INFO): Powering down
2014-05-28T17:48:30.284Z,1401299310.284 [CBIT](INFO): Clearing failed state for component NAL9602
2014-05-28T17:48:30.284Z,1401299310.284 [NAL9602] No Fault, FailCount= 1
2014-05-28T17:48:34.172Z,1401299314.172 [NAL9602](INFO): Powering up NAL9602
2014-05-28T17:48:44.784Z,1401299324.784 [NAL9602](INFO): NAL9602 initialized
2014-05-28T17:49:58.844Z,1401299398.844 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T17:49:58.844Z,1401299398.844 [DVL_micro] Data Fault, FailCount= 1
2014-05-28T17:49:58.844Z,1401299398.844 [DVL_micro](ERROR): Data Fault
2014-05-28T17:49:59.020Z,1401299399.020 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T17:49:59.551Z,1401299399.551 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T17:50:00.078Z,1401299400.078 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T17:50:00.078Z,1401299400.078 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T17:50:00.078Z,1401299400.078 [DVL_micro](ERROR): Hardware Fault
2014-05-28T17:50:00.748Z,1401299400.748 [DVL_micro](INFO): Initializing
2014-05-28T17:50:00.861Z,1401299400.861 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T17:50:00.861Z,1401299400.861 [DVL_micro] No Fault, FailCount= 1
2014-05-28T17:50:39.913Z,1401299439.913 [Default:CallIridium] Running Loop=1
2014-05-28T17:50:39.926Z,1401299439.926 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-05-28T17:50:39.926Z,1401299439.926 [Default:CallIridium:A] Running Loop=1
2014-05-28T17:50:39.927Z,1401299439.927 [Default:CallIridium:A] Stopped
2014-05-28T17:50:39.927Z,1401299439.927 [Default:CallIridium:B] Running Loop=1
2014-05-28T17:50:39.927Z,1401299439.927 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-05-28T17:50:40.512Z,1401299440.512 [Default:Iridium] Running Loop=1
2014-05-28T17:50:40.512Z,1401299440.512 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-28T17:50:40.512Z,1401299440.512 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-28T17:50:40.512Z,1401299440.512 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-28T17:50:40.512Z,1401299440.512 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-28T17:50:40.512Z,1401299440.512 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-28T17:50:40.513Z,1401299440.513 [Default:Iridium:B.GoToSurface] Stopped
2014-05-28T17:50:40.513Z,1401299440.513 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-28T17:50:40.513Z,1401299440.513 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-28T17:50:46.544Z,1401299446.544 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20140528T171454/Courier0028.lzma
2014-05-28T17:50:47.862Z,1401299447.862 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Courier0028.lzma.bak
2014-05-28T17:50:47.862Z,1401299447.862 [DataOverHttps](INFO): SBD MOMSN=980555
2014-05-28T17:50:58.435Z,1401299458.435 [DataOverHttps](INFO): Sending 288 bytes from file Logs/20140528T171454/Express0029.lzma
2014-05-28T17:50:59.859Z,1401299459.859 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Express0029.lzma.bak
2014-05-28T17:50:59.859Z,1401299459.859 [DataOverHttps](INFO): SBD MOMSN=980557
2014-05-28T17:51:11.793Z,1401299471.793 [HFRadarModelCalc](IMPORTANT): Forecast time 20140528T150000: published 50 modes in rows, 61 hours in columns, 3050 elements.
2014-05-28T17:51:14.248Z,1401299474.248 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients.
2014-05-28T17:51:14.283Z,1401299474.283 [Default:Iridium:Read_Iridium] Stopped
2014-05-28T17:51:14.284Z,1401299474.284 [Default:Iridium](INFO): Completed Default:Iridium
2014-05-28T17:51:14.284Z,1401299474.284 [Default:Iridium] Stopped
2014-05-28T17:51:14.284Z,1401299474.284 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-28T17:51:14.284Z,1401299474.284 [Default:Iridium:A.SetSpeed] Stopped
2014-05-28T17:51:14.284Z,1401299474.284 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-28T17:51:15.763Z,1401299475.763 [DVL_micro](ERROR): No DVL communication! Re-initializing
2014-05-28T17:51:15.763Z,1401299475.763 [DVL_micro] Communications Fault, FailCount= 1
2014-05-28T17:51:15.764Z,1401299475.764 [DVL_micro](ERROR): Communications Fault
2014-05-28T17:51:15.903Z,1401299475.903 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-05-28T17:51:15.903Z,1401299475.903 [Default:CallIridium:B] Stopped
2014-05-28T17:51:15.903Z,1401299475.903 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-28T17:51:15.903Z,1401299475.903 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-05-28T17:51:15.903Z,1401299475.903 [Default:CallIridium] Stopped
2014-05-28T17:51:15.903Z,1401299475.903 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-28T17:51:15.994Z,1401299475.994 [CBIT](ERROR): Communications Fault in component: DVL_micro
2014-05-28T17:51:18.217Z,1401299478.217 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T17:51:18.904Z,1401299478.904 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T17:51:18.905Z,1401299478.905 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T17:51:18.905Z,1401299478.905 [DVL_micro](ERROR): Hardware Fault
2014-05-28T17:51:19.548Z,1401299479.548 [DVL_micro](INFO): Initializing
2014-05-28T17:51:19.665Z,1401299479.665 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T17:51:19.665Z,1401299479.665 [DVL_micro] No Fault, FailCount= 1
2014-05-28T17:51:58.141Z,1401299518.141 [DVL_micro](ERROR): No DVL communication! Re-initializing
2014-05-28T17:51:58.141Z,1401299518.141 [DVL_micro] Communications Fault, FailCount= 1
2014-05-28T17:51:58.141Z,1401299518.141 [DVL_micro](ERROR): Communications Fault
2014-05-28T17:51:58.330Z,1401299518.330 [CBIT](ERROR): Communications Fault in component: DVL_micro
2014-05-28T17:51:58.768Z,1401299518.768 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T17:51:59.310Z,1401299519.310 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T17:51:59.310Z,1401299519.310 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T17:51:59.310Z,1401299519.310 [DVL_micro](ERROR): Hardware Fault
2014-05-28T17:51:59.940Z,1401299519.940 [DVL_micro](INFO): Initializing
2014-05-28T17:52:00.079Z,1401299520.079 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T17:52:00.079Z,1401299520.079 [DVL_micro] No Fault, FailCount= 1
2014-05-28T17:52:52.658Z,1401299572.658 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:97 Calculated:125
2014-05-28T17:52:52.658Z,1401299572.658 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -790 -550 -681 -704 2 2 3 2 -145.5 205.5 -734.8 -61.4 -734.8 2 -145 205 -734 2 244 -61 -734 2 -0.39 0.04 220.6 -3.0 18.7 0.005 35.0 1489 97
2014-05-28T17:53:06.127Z,1401299586.127 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T17:53:06.127Z,1401299586.127 [DVL_micro] Data Fault, FailCount= 1
2014-05-28T17:53:06.127Z,1401299586.127 [DVL_micro](ERROR): Data Fault
2014-05-28T17:53:06.289Z,1401299586.289 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T17:53:06.830Z,1401299586.830 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T17:53:07.400Z,1401299587.400 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T17:53:07.400Z,1401299587.400 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T17:53:07.400Z,1401299587.400 [DVL_micro](ERROR): Hardware Fault
2014-05-28T17:53:07.993Z,1401299587.993 [DVL_micro](INFO): Initializing
2014-05-28T17:53:08.136Z,1401299588.136 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T17:53:08.136Z,1401299588.136 [DVL_micro] No Fault, FailCount= 1
2014-05-28T17:54:19.314Z,1401299659.314 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46
2014-05-28T17:54:19.314Z,1401299659.314 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -683 -630 -700 -536 2 2 3 2 22.7 -125.5 -687.3 2 -97.6 82.1 -687.3 2 2687 2 -97 82 -687 2 -0.41 0.02 219.7 -3.0 18.8 0.005 35.0 1489 98
2014-05-28T17:55:08.522Z,1401299708.522 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46
2014-05-28T17:55:08.523Z,1401299708.523 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -690 -693 -664 -745 2 2 3 2 -34.7 69.4 -752.9 2 71.1 -31.1 -752.9 2 -34 69 -752 2 71 -31 -752 2 -0 219.8 -3.0 18.8 0.005 35.0 1489 97
2014-05-28T17:56:01.748Z,1401299761.748 [Default:CallIridium] Running Loop=1
2014-05-28T17:56:01.748Z,1401299761.748 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-05-28T17:56:01.748Z,1401299761.748 [Default:CallIridium:A] Running Loop=1
2014-05-28T17:56:01.749Z,1401299761.749 [Default:CallIridium:A] Stopped
2014-05-28T17:56:01.749Z,1401299761.749 [Default:CallIridium:B] Running Loop=1
2014-05-28T17:56:01.749Z,1401299761.749 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-05-28T17:56:02.305Z,1401299762.305 [Default:Iridium] Running Loop=1
2014-05-28T17:56:02.305Z,1401299762.305 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-28T17:56:02.305Z,1401299762.305 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-28T17:56:02.305Z,1401299762.305 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-28T17:56:02.314Z,1401299762.314 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-28T17:56:02.314Z,1401299762.314 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-28T17:56:02.314Z,1401299762.314 [Default:Iridium:B.GoToSurface] Stopped
2014-05-28T17:56:02.315Z,1401299762.315 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-28T17:56:02.315Z,1401299762.315 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-28T17:56:07.230Z,1401299767.230 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20140528T171454/Courier0032.lzma
2014-05-28T17:56:08.685Z,1401299768.685 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Courier0032.lzma.bak
2014-05-28T17:56:08.686Z,1401299768.686 [DataOverHttps](INFO): SBD MOMSN=980566
2014-05-28T17:56:12.952Z,1401299772.952 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T17:56:12.952Z,1401299772.952 [DVL_micro] Data Fault, FailCount= 1
2014-05-28T17:56:12.952Z,1401299772.952 [DVL_micro](ERROR): Data Fault
2014-05-28T17:56:13.183Z,1401299773.183 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T17:56:13.944Z,1401299773.944 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T17:56:14.487Z,1401299774.487 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T17:56:14.487Z,1401299774.487 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T17:56:14.487Z,1401299774.487 [DVL_micro](ERROR): Hardware Fault
2014-05-28T17:56:15.046Z,1401299775.046 [DVL_micro](INFO): Initializing
2014-05-28T17:56:15.201Z,1401299775.201 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T17:56:15.201Z,1401299775.201 [DVL_micro] No Fault, FailCount= 1
2014-05-28T17:56:19.133Z,1401299779.133 [DataOverHttps](INFO): Sending 255 bytes from file Logs/20140528T171454/Express0033.lzma
2014-05-28T17:56:20.322Z,1401299780.322 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Express0033.lzma.bak
2014-05-28T17:56:20.322Z,1401299780.322 [DataOverHttps](INFO): SBD MOMSN=980568
2014-05-28T17:56:32.154Z,1401299792.154 [HFRadarModelCalc](IMPORTANT): Forecast time 20140528T150000: published 50 modes in rows, 61 hours in columns, 3050 elements.
2014-05-28T17:56:34.660Z,1401299794.660 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients.
2014-05-28T17:56:34.697Z,1401299794.697 [Default:Iridium:Read_Iridium] Stopped
2014-05-28T17:56:34.697Z,1401299794.697 [Default:Iridium](INFO): Completed Default:Iridium
2014-05-28T17:56:34.697Z,1401299794.697 [Default:Iridium] Stopped
2014-05-28T17:56:34.697Z,1401299794.697 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-28T17:56:34.698Z,1401299794.698 [Default:Iridium:A.SetSpeed] Stopped
2014-05-28T17:56:34.698Z,1401299794.698 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-28T17:56:36.435Z,1401299796.435 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-05-28T17:56:36.435Z,1401299796.435 [Default:CallIridium:B] Stopped
2014-05-28T17:56:36.435Z,1401299796.435 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-28T17:56:36.435Z,1401299796.435 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-05-28T17:56:36.435Z,1401299796.435 [Default:CallIridium] Stopped
2014-05-28T17:56:36.436Z,1401299796.436 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-28T17:58:30.750Z,1401299910.750 [DVL_micro](ERROR): No DVL communication! Re-initializing
2014-05-28T17:58:30.750Z,1401299910.750 [DVL_micro] Communications Fault, FailCount= 1
2014-05-28T17:58:30.750Z,1401299910.750 [DVL_micro](ERROR): Communications Fault
2014-05-28T17:58:30.929Z,1401299910.929 [CBIT](ERROR): Communications Fault in component: DVL_micro
2014-05-28T17:58:31.393Z,1401299911.393 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T17:58:31.952Z,1401299911.952 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T17:58:31.953Z,1401299911.953 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T17:58:31.953Z,1401299911.953 [DVL_micro](ERROR): Hardware Fault
2014-05-28T17:58:32.508Z,1401299912.508 [DVL_micro](INFO): Initializing
2014-05-28T17:58:32.683Z,1401299912.683 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T17:58:32.683Z,1401299912.683 [DVL_micro] No Fault, FailCount= 1
2014-05-28T17:58:39.476Z,1401299919.476 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 43 of 46
2014-05-28T17:58:39.477Z,1401299919.477 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 -828 -543 -679 -511 2 2 3 2 -198.9 -42.7 -690.6 2 125.5 160.1 -690.6 2 -198 -42 -690 2 125 160 -690 2 -0.37 0.11 219.8 -3.0 18.8 0.005 35.0 1489 99
2014-05-28T17:58:46.238Z,1401299926.238 [NAL9602](FAULT): GPS failed to acquire within timeout.
2014-05-28T17:58:46.238Z,1401299926.238 [NAL9602] Data Fault, FailCount= 2
2014-05-28T17:58:46.238Z,1401299926.238 [NAL9602](ERROR): Data Fault
2014-05-28T17:58:46.382Z,1401299926.382 [CBIT](ERROR): Data Fault in component: NAL9602
2014-05-28T17:58:46.382Z,1401299926.382 [CBIT](CRITICAL): Data Fault in component: NAL9602
2014-05-28T17:58:46.771Z,1401299926.771 [NAL9602](INFO): Powering down
2014-05-28T17:59:19.851Z,1401299959.851 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T17:59:19.851Z,1401299959.851 [DVL_micro] Data Fault, FailCount= 1
2014-05-28T17:59:19.851Z,1401299959.851 [DVL_micro](ERROR): Data Fault
2014-05-28T17:59:19.977Z,1401299959.977 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T17:59:20.421Z,1401299960.421 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T17:59:20.917Z,1401299960.917 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T17:59:20.917Z,1401299960.917 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T17:59:20.917Z,1401299960.917 [DVL_micro](ERROR): Hardware Fault
2014-05-28T17:59:21.521Z,1401299961.521 [DVL_micro](INFO): Initializing
2014-05-28T17:59:21.654Z,1401299961.654 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T17:59:21.678Z,1401299961.678 [DVL_micro] No Fault, FailCount= 1
2014-05-28T18:00:46.492Z,1401300046.492 [CBIT](INFO): Clearing failed count for component NAL9602
2014-05-28T18:00:46.492Z,1401300046.492 [NAL9602] No Fault, FailCount= 2
2014-05-28T18:00:47.022Z,1401300047.022 [NAL9602](INFO): Powering up NAL9602
2014-05-28T18:00:57.892Z,1401300057.892 [NAL9602](INFO): NAL9602 initialized
2014-05-28T18:00:59.284Z,1401300059.284 [NAL9602](ERROR): getFix uart error: serial timeout
2014-05-28T18:01:22.140Z,1401300082.140 [Default:CallIridium] Running Loop=1
2014-05-28T18:01:22.140Z,1401300082.140 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-05-28T18:01:22.140Z,1401300082.140 [Default:CallIridium:A] Running Loop=1
2014-05-28T18:01:22.141Z,1401300082.141 [Default:CallIridium:A] Stopped
2014-05-28T18:01:22.141Z,1401300082.141 [Default:CallIridium:B] Running Loop=1
2014-05-28T18:01:22.173Z,1401300082.173 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-05-28T18:01:22.700Z,1401300082.700 [Default:Iridium] Running Loop=1
2014-05-28T18:01:22.700Z,1401300082.700 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-28T18:01:22.700Z,1401300082.700 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-28T18:01:22.700Z,1401300082.700 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-28T18:01:22.700Z,1401300082.700 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-28T18:01:22.700Z,1401300082.700 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-28T18:01:22.701Z,1401300082.701 [Default:Iridium:B.GoToSurface] Stopped
2014-05-28T18:01:22.701Z,1401300082.701 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-28T18:01:22.701Z,1401300082.701 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-28T18:01:28.224Z,1401300088.224 [DataOverHttps](INFO): Sending 88 bytes from file Logs/20140528T171454/Courier0036.lzma
2014-05-28T18:01:29.511Z,1401300089.511 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Courier0036.lzma.bak
2014-05-28T18:01:29.511Z,1401300089.511 [DataOverHttps](INFO): SBD MOMSN=980575
2014-05-28T18:01:40.122Z,1401300100.122 [DataOverHttps](INFO): Sending 292 bytes from file Logs/20140528T171454/Express0037.lzma
2014-05-28T18:01:41.207Z,1401300101.207 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Express0037.lzma.bak
2014-05-28T18:01:41.207Z,1401300101.207 [DataOverHttps](INFO): SBD MOMSN=980578
2014-05-28T18:01:53.269Z,1401300113.269 [HFRadarModelCalc](IMPORTANT): Forecast time 20140528T150000: published 50 modes in rows, 61 hours in columns, 3050 elements.
2014-05-28T18:01:55.766Z,1401300115.766 [HFRadarCompactModelForecaster](DEBUG): Found new ECs!
2014-05-28T18:02:06.254Z,1401300126.254 [HFRadarCompactModelForecaster](IMPORTANT): Forecast time 201405281500: published 50 modes in rows, 61 hours in columns, 3050 elements.
2014-05-28T18:02:06.314Z,1401300126.314 [Default:Iridium:Read_Iridium] Stopped
2014-05-28T18:02:06.315Z,1401300126.315 [Default:Iridium](INFO): Completed Default:Iridium
2014-05-28T18:02:06.315Z,1401300126.315 [Default:Iridium] Stopped
2014-05-28T18:02:06.315Z,1401300126.315 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-28T18:02:06.315Z,1401300126.315 [Default:Iridium:A.SetSpeed] Stopped
2014-05-28T18:02:06.315Z,1401300126.315 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-28T18:02:08.554Z,1401300128.554 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-05-28T18:02:08.554Z,1401300128.554 [Default:CallIridium:B] Stopped
2014-05-28T18:02:08.554Z,1401300128.554 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-28T18:02:08.554Z,1401300128.554 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-05-28T18:02:08.554Z,1401300128.554 [Default:CallIridium] Stopped
2014-05-28T18:02:08.554Z,1401300128.554 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-28T18:02:26.960Z,1401300146.960 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T18:02:26.960Z,1401300146.960 [DVL_micro] Data Fault, FailCount= 1
2014-05-28T18:02:26.960Z,1401300146.960 [DVL_micro](ERROR): Data Fault
2014-05-28T18:02:27.099Z,1401300147.099 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T18:02:27.723Z,1401300147.723 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T18:02:28.270Z,1401300148.270 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T18:02:28.270Z,1401300148.270 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T18:02:28.270Z,1401300148.270 [DVL_micro](ERROR): Hardware Fault
2014-05-28T18:02:28.845Z,1401300148.845 [DVL_micro](INFO): Initializing
2014-05-28T18:02:29.028Z,1401300149.028 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T18:02:29.028Z,1401300149.028 [DVL_micro] No Fault, FailCount= 1
2014-05-28T18:03:06.904Z,1401300186.904 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 44 of 46
2014-05-28T18:03:06.904Z,1401300186.904 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -651 -640 -629 -559 2 2 3 2 -29.4 -108.1 -668.5 2 -46.8 101.8 -668.5 2 -29 -108 -668 2 -46 101 -668 2 -0.45 0.05 219.9 -3.0 18.8 0.005 35.0 
2014-05-28T18:03:56.056Z,1401300236.056 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 14 of 46
2014-05-28T18:03:56.060Z,1401300236.060 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -613 - -657 2 2 3 2 12.0 -140.1 -715.6 2 -99.1 99.8 -715.6 2 12 -140 -715 2 -99 99 -715 2 -0.38 0.12 219.9 -3.0 18.9 0.005 35.0 1489 101
2014-05-28T18:04:59.768Z,1401300299.768 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:05:02.140Z,1401300302.140 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:05:04.448Z,1401300304.448 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:05:06.884Z,1401300306.884 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:05:09.300Z,1401300309.300 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:05:11.718Z,1401300311.718 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:05:14.537Z,1401300314.537 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:05:17.084Z,1401300317.084 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:05:19.463Z,1401300319.463 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:05:21.858Z,1401300321.858 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:05:24.136Z,1401300324.136 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:05:25.963Z,1401300325.963 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#7 STATUS: 65535
2014-05-28T18:05:26.618Z,1401300326.618 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:05:29.367Z,1401300329.367 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:05:30.088Z,1401300330.088 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#7 STATUS: 65535
2014-05-28T18:05:31.281Z,1401300331.281 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:05:33.485Z,1401300333.485 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T18:05:33.485Z,1401300333.485 [DVL_micro] Data Fault, FailCount= 1
2014-05-28T18:05:33.485Z,1401300333.485 [DVL_micro](ERROR): Data Fault
2014-05-28T18:05:33.648Z,1401300333.648 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T18:05:34.142Z,1401300334.142 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#7 STATUS: 65535
2014-05-28T18:05:34.253Z,1401300334.253 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:05:34.353Z,1401300334.353 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T18:05:34.895Z,1401300334.895 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T18:05:34.895Z,1401300334.895 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T18:05:34.895Z,1401300334.895 [DVL_micro](ERROR): Hardware Fault
2014-05-28T18:05:35.482Z,1401300335.482 [DVL_micro](INFO): Initializing
2014-05-28T18:05:35.649Z,1401300335.649 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T18:05:35.649Z,1401300335.649 [DVL_micro] No Fault, FailCount= 1
2014-05-28T18:05:36.637Z,1401300336.637 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:05:39.030Z,1401300339.030 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#7 STATUS: 65535
2014-05-28T18:05:39.139Z,1401300339.139 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:05:41.146Z,1401300341.146 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:05:43.700Z,1401300343.700 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:05:47.282Z,1401300347.282 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:05:49.871Z,1401300349.871 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:05:52.073Z,1401300352.073 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:05:53.789Z,1401300353.789 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:05:56.396Z,1401300356.396 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:05:58.732Z,1401300358.732 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:06:01.168Z,1401300361.168 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:06:03.664Z,1401300363.664 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:06:06.167Z,1401300366.167 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:06:08.246Z,1401300368.246 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:06:10.729Z,1401300370.729 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:06:13.149Z,1401300373.149 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:06:15.680Z,1401300375.680 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:06:18.452Z,1401300378.452 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:06:21.055Z,1401300381.055 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:06:23.367Z,1401300383.367 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:06:25.569Z,1401300385.569 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:06:28.010Z,1401300388.010 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:06:43.254Z,1401300403.254 [Default:CallIridium] Running Loop=1
2014-05-28T18:06:43.254Z,1401300403.254 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-05-28T18:06:43.254Z,1401300403.254 [Default:CallIridium:A] Running Loop=1
2014-05-28T18:06:43.255Z,1401300403.255 [Default:CallIridium:A] Stopped
2014-05-28T18:06:43.267Z,1401300403.267 [Default:CallIridium:B] Running Loop=1
2014-05-28T18:06:43.267Z,1401300403.267 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-05-28T18:06:43.761Z,1401300403.761 [Default:Iridium] Running Loop=1
2014-05-28T18:06:43.761Z,1401300403.761 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-28T18:06:43.761Z,1401300403.761 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-28T18:06:43.761Z,1401300403.761 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-28T18:06:43.762Z,1401300403.762 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-28T18:06:43.762Z,1401300403.762 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-28T18:06:43.762Z,1401300403.762 [Default:Iridium:B.GoToSurface] Stopped
2014-05-28T18:06:43.762Z,1401300403.762 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-28T18:06:43.763Z,1401300403.763 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-28T18:06:49.087Z,1401300409.087 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20140528T171454/Courier0040.lzma
2014-05-28T18:06:50.138Z,1401300410.138 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Courier0040.lzma.bak
2014-05-28T18:06:50.139Z,1401300410.139 [DataOverHttps](INFO): SBD MOMSN=980587
2014-05-28T18:07:00.982Z,1401300420.982 [DataOverHttps](INFO): Sending 281 bytes from file Logs/20140528T171454/Express0041.lzma
2014-05-28T18:07:02.217Z,1401300422.217 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Express0041.lzma.bak
2014-05-28T18:07:02.218Z,1401300422.218 [DataOverHttps](INFO): SBD MOMSN=980589
2014-05-28T18:07:14.280Z,1401300434.280 [HFRadarModelCalc](IMPORTANT): Forecast time 20140528T150000: published 50 modes in rows, 61 hours in columns, 3050 elements.
2014-05-28T18:07:16.679Z,1401300436.679 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients.
2014-05-28T18:07:16.714Z,1401300436.714 [Default:Iridium:Read_Iridium] Stopped
2014-05-28T18:07:16.714Z,1401300436.714 [Default:Iridium](INFO): Completed Default:Iridium
2014-05-28T18:07:16.714Z,1401300436.714 [Default:Iridium] Stopped
2014-05-28T18:07:16.715Z,1401300436.715 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-28T18:07:16.715Z,1401300436.715 [Default:Iridium:A.SetSpeed] Stopped
2014-05-28T18:07:16.715Z,1401300436.715 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-28T18:07:18.231Z,1401300438.231 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-05-28T18:07:18.231Z,1401300438.231 [Default:CallIridium:B] Stopped
2014-05-28T18:07:18.232Z,1401300438.232 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-28T18:07:18.232Z,1401300438.232 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-05-28T18:07:18.232Z,1401300438.232 [Default:CallIridium] Stopped
2014-05-28T18:07:18.232Z,1401300438.232 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-28T18:08:40.996Z,1401300520.996 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T18:08:40.996Z,1401300520.996 [DVL_micro] Data Fault, FailCount= 1
2014-05-28T18:08:40.996Z,1401300520.996 [DVL_micro](ERROR): Data Fault
2014-05-28T18:08:41.133Z,1401300521.133 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T18:08:41.691Z,1401300521.691 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T18:08:42.378Z,1401300522.378 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T18:08:42.378Z,1401300522.378 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T18:08:42.378Z,1401300522.378 [DVL_micro](ERROR): Hardware Fault
2014-05-28T18:08:42.941Z,1401300522.941 [DVL_micro](INFO): Initializing
2014-05-28T18:08:43.065Z,1401300523.065 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T18:08:43.066Z,1401300523.066 [DVL_micro] No Fault, FailCount= 1
2014-05-28T18:09:02.808Z,1401300542.808 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46
2014-05-28T18:09:02.808Z,1401300542.808 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -703 -674 -592 -642 2 2 3 2 -148.1 -42.7 -704.1 2 86.0 127.9 -704.1 2 -148 -42 -704 2 86 127-0.45 0.06 220.0 -3.0 19.0 0.005 35.0 1489 108
2014-05-28T18:10:28.567Z,1401300628.567 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 43 of 46
2014-05-28T18:10:28.568Z,1401300628.568 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 -591 -588 -703 -600 2 3 3 2 149.5 16.0 -669.2 2 -104.6 -108.0 -669.2 2 149 16 -669 2 -104 -108 -669 2 -0.41 0.06 219.8 -3.0 19.0 0.005 35.0 1489 98
2014-05-28T18:10:59.626Z,1401300659.626 [NAL9602](FAULT): GPS failed to acquire within timeout.
2014-05-28T18:10:59.626Z,1401300659.626 [NAL9602] Data Fault, FailCount= 1
2014-05-28T18:10:59.626Z,1401300659.626 [NAL9602](ERROR): Data Fault
2014-05-28T18:10:59.779Z,1401300659.779 [CBIT](ERROR): Data Fault in component: NAL9602
2014-05-28T18:11:00.164Z,1401300660.164 [NAL9602](INFO): Powering down
2014-05-28T18:11:01.366Z,1401300661.366 [CBIT](INFO): Clearing failed state for component NAL9602
2014-05-28T18:11:01.366Z,1401300661.366 [NAL9602] No Fault, FailCount= 1
2014-05-28T18:11:05.379Z,1401300665.379 [NAL9602](INFO): Powering up NAL9602
2014-05-28T18:11:16.337Z,1401300676.337 [NAL9602](INFO): NAL9602 initialized
2014-05-28T18:11:22.076Z,1401300682.076 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 43 of 46
2014-05-28T18:11:22.076Z,1401300682.076 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 -662 -706 -628 -637 2 3 3 2 -45.4 -92.1 -710.0 2 -24.4 99.7 -710.0 2 -45 -92 -710 2 -24 99 -710 2 -0.41 0.09 220.0 -3.0 19.0 0.005 35.0 1489 109
2014-05-28T18:11:47.765Z,1401300707.765 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T18:11:47.765Z,1401300707.765 [DVL_micro] Data Fault, FailCount= 1
2014-05-28T18:11:47.765Z,1401300707.765 [DVL_micro](ERROR): Data Fault
2014-05-28T18:11:47.948Z,1401300707.948 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T18:11:48.473Z,1401300708.473 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T18:11:49.040Z,1401300709.040 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T18:11:49.040Z,1401300709.040 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T18:11:49.040Z,1401300709.040 [DVL_micro](ERROR): Hardware Fault
2014-05-28T18:11:49.587Z,1401300709.587 [DVL_micro](INFO): Initializing
2014-05-28T18:11:49.733Z,1401300709.733 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T18:11:49.734Z,1401300709.734 [DVL_micro] No Fault, FailCount= 1
2014-05-28T18:12:04.096Z,1401300724.096 [Default:CallIridium] Running Loop=1
2014-05-28T18:12:04.130Z,1401300724.130 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-05-28T18:12:04.130Z,1401300724.130 [Default:CallIridium:A] Running Loop=1
2014-05-28T18:12:04.130Z,1401300724.130 [Default:CallIridium:A] Stopped
2014-05-28T18:12:04.131Z,1401300724.131 [Default:CallIridium:B] Running Loop=1
2014-05-28T18:12:04.131Z,1401300724.131 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-05-28T18:12:04.668Z,1401300724.668 [Default:Iridium] Running Loop=1
2014-05-28T18:12:04.668Z,1401300724.668 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-28T18:12:04.669Z,1401300724.669 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-28T18:12:04.669Z,1401300724.669 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-28T18:12:04.669Z,1401300724.669 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-28T18:12:04.669Z,1401300724.669 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-28T18:12:04.678Z,1401300724.678 [Default:Iridium:B.GoToSurface] Stopped
2014-05-28T18:12:04.678Z,1401300724.678 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-28T18:12:04.678Z,1401300724.678 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-28T18:12:10.118Z,1401300730.118 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20140528T171454/Courier0044.lzma
2014-05-28T18:12:11.176Z,1401300731.176 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Courier0044.lzma.bak
2014-05-28T18:12:11.177Z,1401300731.177 [DataOverHttps](INFO): SBD MOMSN=980597
2014-05-28T18:12:22.102Z,1401300742.102 [DataOverHttps](INFO): Sending 272 bytes from file Logs/20140528T171454/Express0045.lzma
2014-05-28T18:12:23.367Z,1401300743.367 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Express0045.lzma.bak
2014-05-28T18:12:23.367Z,1401300743.367 [DataOverHttps](INFO): SBD MOMSN=980599
2014-05-28T18:12:36.160Z,1401300756.160 [HFRadarModelCalc](IMPORTANT): Forecast time 20140528T150000: published 50 modes in rows, 61 hours in columns, 3050 elements.
2014-05-28T18:12:38.771Z,1401300758.771 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients.
2014-05-28T18:12:38.807Z,1401300758.807 [Default:Iridium:Read_Iridium] Stopped
2014-05-28T18:12:38.807Z,1401300758.807 [Default:Iridium](INFO): Completed Default:Iridium
2014-05-28T18:12:38.807Z,1401300758.807 [Default:Iridium] Stopped
2014-05-28T18:12:38.807Z,1401300758.807 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-28T18:12:38.807Z,1401300758.807 [Default:Iridium:A.SetSpeed] Stopped
2014-05-28T18:12:38.807Z,1401300758.807 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-28T18:12:40.632Z,1401300760.632 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-05-28T18:12:40.632Z,1401300760.632 [Default:CallIridium:B] Stopped
2014-05-28T18:12:40.632Z,1401300760.632 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-28T18:12:40.632Z,1401300760.632 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-05-28T18:12:40.632Z,1401300760.632 [Default:CallIridium] Stopped
2014-05-28T18:12:40.633Z,1401300760.633 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-28T18:13:25.163Z,1401300805.163 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 27 of 46
2014-05-28T18:13:25.163Z,1401300805.163 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -747 -600 -728 -654 2 3 3 2 -25.4 72.1 -735.8 2 65.7 -39.1 --25 72 -735 2 65 -39 -735 2 -0.41 0.05 219.8 -3.0 19.1 0.005 35.0 1489 98
2014-05-28T18:14:54.535Z,1401300894.535 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T18:14:54.535Z,1401300894.535 [DVL_micro] Data Fault, FailCount= 1
2014-05-28T18:14:54.535Z,1401300894.535 [DVL_micro](ERROR): Data Fault
2014-05-28T18:14:54.664Z,1401300894.664 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T18:14:55.214Z,1401300895.214 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T18:14:55.918Z,1401300895.918 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T18:14:55.918Z,1401300895.918 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T18:14:55.918Z,1401300895.918 [DVL_micro](ERROR): Hardware Fault
2014-05-28T18:14:56.481Z,1401300896.481 [DVL_micro](INFO): Initializing
2014-05-28T18:14:56.646Z,1401300896.646 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T18:14:56.646Z,1401300896.646 [DVL_micro] No Fault, FailCount= 1
2014-05-28T18:17:25.313Z,1401301045.313 [Default:CallIridium] Running Loop=1
2014-05-28T18:17:25.313Z,1401301045.313 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-05-28T18:17:25.314Z,1401301045.314 [Default:CallIridium:A] Running Loop=1
2014-05-28T18:17:25.314Z,1401301045.314 [Default:CallIridium:A] Stopped
2014-05-28T18:17:25.314Z,1401301045.314 [Default:CallIridium:B] Running Loop=1
2014-05-28T18:17:25.314Z,1401301045.314 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-05-28T18:17:25.889Z,1401301045.889 [Default:Iridium] Running Loop=1
2014-05-28T18:17:25.890Z,1401301045.890 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-28T18:17:25.890Z,1401301045.890 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-28T18:17:25.890Z,1401301045.890 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-28T18:17:25.890Z,1401301045.890 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-28T18:17:25.890Z,1401301045.890 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-28T18:17:25.891Z,1401301045.891 [Default:Iridium:B.GoToSurface] Stopped
2014-05-28T18:17:25.891Z,1401301045.891 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-28T18:17:25.891Z,1401301045.891 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-28T18:17:31.390Z,1401301051.390 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20140528T171454/Courier0048.lzma
2014-05-28T18:17:32.540Z,1401301052.540 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Courier0048.lzma.bak
2014-05-28T18:17:32.540Z,1401301052.540 [DataOverHttps](INFO): SBD MOMSN=980607
2014-05-28T18:17:43.517Z,1401301063.517 [DataOverHttps](INFO): Sending 258 bytes from file Logs/20140528T171454/Express0049.lzma
2014-05-28T18:17:44.845Z,1401301064.845 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Express0049.lzma.bak
2014-05-28T18:17:44.845Z,1401301064.845 [DataOverHttps](INFO): SBD MOMSN=980609
2014-05-28T18:17:56.880Z,1401301076.880 [HFRadarModelCalc](IMPORTANT): Forecast time 20140528T150000: published 50 modes in rows, 61 hours in columns, 3050 elements.
2014-05-28T18:17:59.297Z,1401301079.297 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients.
2014-05-28T18:17:59.336Z,1401301079.336 [Default:Iridium:Read_Iridium] Stopped
2014-05-28T18:17:59.336Z,1401301079.336 [Default:Iridium](INFO): Completed Default:Iridium
2014-05-28T18:17:59.336Z,1401301079.336 [Default:Iridium] Stopped
2014-05-28T18:17:59.337Z,1401301079.337 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-28T18:17:59.337Z,1401301079.337 [Default:Iridium:A.SetSpeed] Stopped
2014-05-28T18:17:59.337Z,1401301079.337 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-28T18:18:00.978Z,1401301080.978 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-05-28T18:18:00.978Z,1401301080.978 [Default:CallIridium:B] Stopped
2014-05-28T18:18:00.978Z,1401301080.978 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-28T18:18:00.978Z,1401301080.978 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-05-28T18:18:00.978Z,1401301080.978 [Default:CallIridium] Stopped
2014-05-28T18:18:00.978Z,1401301080.978 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-28T18:18:03.138Z,1401301083.138 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T18:18:03.138Z,1401301083.138 [DVL_micro] Data Fault, FailCount= 1
2014-05-28T18:18:03.139Z,1401301083.139 [DVL_micro](ERROR): Data Fault
2014-05-28T18:18:03.268Z,1401301083.268 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T18:18:03.835Z,1401301083.835 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T18:18:04.337Z,1401301084.337 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T18:18:04.337Z,1401301084.337 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T18:18:04.337Z,1401301084.337 [DVL_micro](ERROR): Hardware Fault
2014-05-28T18:18:05.154Z,1401301085.154 [DVL_micro](INFO): Initializing
2014-05-28T18:18:05.330Z,1401301085.330 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T18:18:05.331Z,1401301085.331 [DVL_micro] No Fault, FailCount= 1
2014-05-28T18:21:09.725Z,1401301269.725 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T18:21:09.725Z,1401301269.725 [DVL_micro] Data Fault, FailCount= 1
2014-05-28T18:21:09.725Z,1401301269.725 [DVL_micro](ERROR): Data Fault
2014-05-28T18:21:09.872Z,1401301269.872 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T18:21:10.344Z,1401301270.344 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T18:21:10.858Z,1401301270.858 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T18:21:10.858Z,1401301270.858 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T18:21:10.858Z,1401301270.858 [DVL_micro](ERROR): Hardware Fault
2014-05-28T18:21:11.478Z,1401301271.478 [DVL_micro](INFO): Initializing
2014-05-28T18:21:11.639Z,1401301271.639 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T18:21:11.639Z,1401301271.639 [DVL_micro] No Fault, FailCount= 1
2014-05-28T18:21:18.783Z,1401301278.783 [NAL9602](FAULT): GPS failed to acquire within timeout.
2014-05-28T18:21:18.784Z,1401301278.784 [NAL9602] Data Fault, FailCount= 2
2014-05-28T18:21:18.784Z,1401301278.784 [NAL9602](ERROR): Data Fault
2014-05-28T18:21:18.990Z,1401301278.990 [CBIT](ERROR): Data Fault in component: NAL9602
2014-05-28T18:21:18.990Z,1401301278.990 [CBIT](CRITICAL): Data Fault in component: NAL9602
2014-05-28T18:21:19.380Z,1401301279.380 [NAL9602](INFO): Powering down
2014-05-28T18:22:03.867Z,1401301323.867 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 43 of 46
2014-05-28T18:22:03.867Z,1401301323.867 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 -568 -627 -502 -591 2 3 3 2 -88.1 -48.0 -616.9 2 36.8 93.3 -616.9 2 -88 -48 -616 2 36 93 -616 2 -0.44 0.04 219.9 -3.0 19.2 0.005 35.0 1489 103
2014-05-28T18:22:46.253Z,1401301366.253 [Default:CallIridium] Running Loop=1
2014-05-28T18:22:46.253Z,1401301366.253 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-05-28T18:22:46.253Z,1401301366.253 [Default:CallIridium:A] Running Loop=1
2014-05-28T18:22:46.253Z,1401301366.253 [Default:CallIridium:A] Stopped
2014-05-28T18:22:46.253Z,1401301366.253 [Default:CallIridium:B] Running Loop=1
2014-05-28T18:22:46.253Z,1401301366.253 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-05-28T18:22:46.809Z,1401301366.809 [Default:Iridium] Running Loop=1
2014-05-28T18:22:46.809Z,1401301366.809 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-28T18:22:46.809Z,1401301366.809 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-28T18:22:46.809Z,1401301366.809 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-28T18:22:46.810Z,1401301366.810 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-28T18:22:46.810Z,1401301366.810 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-28T18:22:46.811Z,1401301366.811 [Default:Iridium:B.GoToSurface] Stopped
2014-05-28T18:22:46.811Z,1401301366.811 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-28T18:22:46.811Z,1401301366.811 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-28T18:22:52.435Z,1401301372.435 [DataOverHttps](INFO): Sending 88 bytes from file Logs/20140528T171454/Courier0052.lzma
2014-05-28T18:22:53.665Z,1401301373.665 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Courier0052.lzma.bak
2014-05-28T18:22:53.665Z,1401301373.665 [DataOverHttps](INFO): SBD MOMSN=980614
2014-05-28T18:22:59.145Z,1401301379.145 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:72 Calculated:84
2014-05-28T18:22:59.145Z,1401301379.145 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -507 -540 -690 -615 2 3 3 100.1 -634.2 2 -106.1 -241.6 -634.2 2 244 100 -634 2 -106 -241 -634 2 -0.44 0 224.0 -3.0 19.2 0.005 35.0 1489 72
2014-05-28T18:23:04.667Z,1401301384.667 [DataOverHttps](INFO): Sending 284 bytes from file Logs/20140528T171454/Express0053.lzma
2014-05-28T18:23:05.960Z,1401301385.960 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Express0053.lzma.bak
2014-05-28T18:23:05.960Z,1401301385.960 [DataOverHttps](INFO): SBD MOMSN=980617
2014-05-28T18:23:17.947Z,1401301397.947 [HFRadarModelCalc](IMPORTANT): Forecast time 20140528T150000: published 50 modes in rows, 61 hours in columns, 3050 elements.
2014-05-28T18:23:20.440Z,1401301400.440 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients.
2014-05-28T18:23:20.523Z,1401301400.523 [Default:Iridium:Read_Iridium] Stopped
2014-05-28T18:23:20.523Z,1401301400.523 [Default:Iridium](INFO): Completed Default:Iridium
2014-05-28T18:23:20.523Z,1401301400.523 [Default:Iridium] Stopped
2014-05-28T18:23:20.523Z,1401301400.523 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-28T18:23:20.523Z,1401301400.523 [Default:Iridium:A.SetSpeed] Stopped
2014-05-28T18:23:20.523Z,1401301400.523 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-28T18:23:20.572Z,1401301400.572 [CBIT](INFO): Clearing failed count for component NAL9602
2014-05-28T18:23:20.572Z,1401301400.572 [NAL9602] No Fault, FailCount= 2
2014-05-28T18:23:21.822Z,1401301401.822 [NAL9602](INFO): Powering up NAL9602
2014-05-28T18:23:21.930Z,1401301401.930 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-05-28T18:23:21.930Z,1401301401.930 [Default:CallIridium:B] Stopped
2014-05-28T18:23:21.930Z,1401301401.930 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-28T18:23:21.930Z,1401301401.930 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-05-28T18:23:21.930Z,1401301401.930 [Default:CallIridium] Stopped
2014-05-28T18:23:21.930Z,1401301401.930 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-28T18:23:32.721Z,1401301412.721 [NAL9602](INFO): NAL9602 initialized
2014-05-28T18:24:16.410Z,1401301456.410 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T18:24:16.410Z,1401301456.410 [DVL_micro] Data Fault, FailCount= 1
2014-05-28T18:24:16.410Z,1401301456.410 [DVL_micro](ERROR): Data Fault
2014-05-28T18:24:16.662Z,1401301456.662 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T18:24:17.105Z,1401301457.105 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T18:24:17.788Z,1401301457.788 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T18:24:17.788Z,1401301457.788 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T18:24:17.788Z,1401301457.788 [DVL_micro](ERROR): Hardware Fault
2014-05-28T18:24:18.601Z,1401301458.601 [DVL_micro](INFO): Initializing
2014-05-28T18:24:18.762Z,1401301458.762 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T18:24:18.762Z,1401301458.762 [DVL_micro] No Fault, FailCount= 1
2014-05-28T18:25:25.599Z,1401301525.599 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 43 of 46
2014-05-28T18:25:25.607Z,1401301525.607 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0569 -594 -569 -583 2 2 3 2 0 -14.7 -624.2 2 -10.2 10.6 -624.2 2 0 -14 -624 2 -10 10 -624 2 -0.44 0.03 223.8 -3.0 19.2 0.005 35.0 1489 122
2014-05-28T18:26:03.627Z,1401301563.627 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#4 STATUS: 65535
2014-05-28T18:26:07.947Z,1401301567.947 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#4 STATUS: 65535
2014-05-28T18:26:12.163Z,1401301572.163 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#4 STATUS: 65535
2014-05-28T18:26:16.871Z,1401301576.871 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#4 STATUS: 65535
2014-05-28T18:26:21.018Z,1401301581.018 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#4 STATUS: 65535
2014-05-28T18:26:25.036Z,1401301585.036 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#4 STATUS: 65535
2014-05-28T18:26:29.451Z,1401301589.451 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#4 STATUS: 65535
2014-05-28T18:26:34.180Z,1401301594.180 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#4 STATUS: 65535
2014-05-28T18:26:38.460Z,1401301598.460 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#4 STATUS: 65535
2014-05-28T18:26:42.633Z,1401301602.633 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#4 STATUS: 65535
2014-05-28T18:26:46.806Z,1401301606.806 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#4 STATUS: 65535
2014-05-28T18:26:51.528Z,1401301611.528 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#4 STATUS: 65535
2014-05-28T18:26:55.742Z,1401301615.742 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#4 STATUS: 65535
2014-05-28T18:26:59.780Z,1401301619.780 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#4 STATUS: 65535
2014-05-28T18:27:04.640Z,1401301624.640 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#4 STATUS: 65535
2014-05-28T18:27:08.896Z,1401301628.896 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#4 STATUS: 65535
2014-05-28T18:27:13.096Z,1401301633.096 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#4 STATUS: 65535
2014-05-28T18:27:17.117Z,1401301637.117 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#4 STATUS: 65535
2014-05-28T18:27:21.723Z,1401301641.723 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#4 STATUS: 65535
2014-05-28T18:27:23.015Z,1401301643.015 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T18:27:23.015Z,1401301643.015 [DVL_micro] Data Fault, FailCount= 1
2014-05-28T18:27:23.016Z,1401301643.016 [DVL_micro](ERROR): Data Fault
2014-05-28T18:27:23.194Z,1401301643.194 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T18:27:23.655Z,1401301643.655 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T18:27:24.193Z,1401301644.193 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T18:27:24.193Z,1401301644.193 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T18:27:24.193Z,1401301644.193 [DVL_micro](ERROR): Hardware Fault
2014-05-28T18:27:24.697Z,1401301644.697 [DVL_micro](INFO): Initializing
2014-05-28T18:27:24.853Z,1401301644.853 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T18:27:24.853Z,1401301644.853 [DVL_micro] No Fault, FailCount= 1
2014-05-28T18:27:26.002Z,1401301646.002 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#4 STATUS: 65535
2014-05-28T18:27:30.446Z,1401301650.446 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#4 STATUS: 65535
2014-05-28T18:27:34.546Z,1401301654.546 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#4 STATUS: 65535
2014-05-28T18:27:38.591Z,1401301658.591 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#4 STATUS: 65535
2014-05-28T18:27:43.280Z,1401301663.280 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#4 STATUS: 65535
2014-05-28T18:27:47.230Z,1401301667.230 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#4 STATUS: 65535
2014-05-28T18:27:51.836Z,1401301671.836 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#4 STATUS: 65535
2014-05-28T18:28:07.607Z,1401301687.607 [Default:CallIridium] Running Loop=1
2014-05-28T18:28:07.607Z,1401301687.607 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-05-28T18:28:07.607Z,1401301687.607 [Default:CallIridium:A] Running Loop=1
2014-05-28T18:28:07.607Z,1401301687.607 [Default:CallIridium:A] Stopped
2014-05-28T18:28:07.608Z,1401301687.608 [Default:CallIridium:B] Running Loop=1
2014-05-28T18:28:07.608Z,1401301687.608 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-05-28T18:28:08.291Z,1401301688.291 [Default:Iridium] Running Loop=1
2014-05-28T18:28:08.304Z,1401301688.304 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-28T18:28:08.304Z,1401301688.304 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-28T18:28:08.304Z,1401301688.304 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-28T18:28:08.304Z,1401301688.304 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-28T18:28:08.304Z,1401301688.304 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-28T18:28:08.305Z,1401301688.305 [Default:Iridium:B.GoToSurface] Stopped
2014-05-28T18:28:08.305Z,1401301688.305 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-28T18:28:08.305Z,1401301688.305 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-28T18:28:13.777Z,1401301693.777 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20140528T171454/Courier0056.lzma
2014-05-28T18:28:14.782Z,1401301694.782 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Courier0056.lzma.bak
2014-05-28T18:28:14.782Z,1401301694.782 [DataOverHttps](INFO): SBD MOMSN=980625
2014-05-28T18:28:19.950Z,1401301699.950 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 44 of 46
2014-05-28T18:28:19.950Z,1401301699.950 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -626 -576 -594 -539 2 2 3 2 -42.7 -49.4 -629.6 2 -3.3 65.2 -629.6 2 -42 -49 -629 2 -3 65 -629 2 -0.40 0.03 223.7 -3.0 19.3 0.005 35.04
2014-05-28T18:28:25.447Z,1401301705.447 [DataOverHttps](INFO): Sending 256 bytes from file Logs/20140528T171454/Express0057.lzma
2014-05-28T18:28:26.581Z,1401301706.581 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Express0057.lzma.bak
2014-05-28T18:28:26.581Z,1401301706.581 [DataOverHttps](INFO): SBD MOMSN=980627
2014-05-28T18:28:38.504Z,1401301718.504 [HFRadarModelCalc](IMPORTANT): Forecast time 20140528T160000: published 50 modes in rows, 61 hours in columns, 3050 elements.
2014-05-28T18:28:41.037Z,1401301721.037 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients.
2014-05-28T18:28:41.066Z,1401301721.066 [Default:Iridium:Read_Iridium] Stopped
2014-05-28T18:28:41.090Z,1401301721.090 [Default:Iridium](INFO): Completed Default:Iridium
2014-05-28T18:28:41.090Z,1401301721.090 [Default:Iridium] Stopped
2014-05-28T18:28:41.090Z,1401301721.090 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-28T18:28:41.090Z,1401301721.090 [Default:Iridium:A.SetSpeed] Stopped
2014-05-28T18:28:41.091Z,1401301721.091 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-28T18:28:42.673Z,1401301722.673 [DVL_micro](ERROR): No DVL communication! Re-initializing
2014-05-28T18:28:42.673Z,1401301722.673 [DVL_micro] Communications Fault, FailCount= 1
2014-05-28T18:28:42.673Z,1401301722.673 [DVL_micro](ERROR): Communications Fault
2014-05-28T18:28:42.799Z,1401301722.799 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-05-28T18:28:42.799Z,1401301722.799 [Default:CallIridium:B] Stopped
2014-05-28T18:28:42.799Z,1401301722.799 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-28T18:28:42.799Z,1401301722.799 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-05-28T18:28:42.800Z,1401301722.800 [Default:CallIridium] Stopped
2014-05-28T18:28:42.800Z,1401301722.800 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-28T18:28:42.867Z,1401301722.867 [CBIT](ERROR): Communications Fault in component: DVL_micro
2014-05-28T18:28:44.977Z,1401301724.977 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T18:28:45.852Z,1401301725.852 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T18:28:45.852Z,1401301725.852 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T18:28:45.852Z,1401301725.852 [DVL_micro](ERROR): Hardware Fault
2014-05-28T18:28:46.455Z,1401301726.455 [DVL_micro](INFO): Initializing
2014-05-28T18:28:46.651Z,1401301726.651 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T18:28:46.652Z,1401301726.652 [DVL_micro] No Fault, FailCount= 1
2014-05-28T18:29:38.316Z,1401301778.316 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:108 Calculated:102
2014-05-28T18:29:38.317Z,1401301778.317 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -688 -544 -531 -581 2 2 35 49.4 -632.1 2 185.2 109.7 -632.1 2 -209 49 -632 2 185 109 -632 2 -0.45 0.03 223.9 -3.0 19.3 0.005 35.0 1489 108
2014-05-28T18:30:31.391Z,1401301831.391 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T18:30:31.391Z,1401301831.391 [DVL_micro] Data Fault, FailCount= 1
2014-05-28T18:30:31.392Z,1401301831.392 [DVL_micro](ERROR): Data Fault
2014-05-28T18:30:31.532Z,1401301831.532 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T18:30:32.183Z,1401301832.183 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T18:30:32.730Z,1401301832.730 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T18:30:32.730Z,1401301832.730 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T18:30:32.730Z,1401301832.730 [DVL_micro](ERROR): Hardware Fault
2014-05-28T18:30:33.313Z,1401301833.313 [DVL_micro](INFO): Initializing
2014-05-28T18:30:33.431Z,1401301833.431 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T18:30:33.432Z,1401301833.432 [DVL_micro] No Fault, FailCount= 1
2014-05-28T18:30:43.479Z,1401301843.479 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 43 of 46
2014-05-28T18:30:43.479Z,1401301843.479 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 -499 -734 -522 -531 2 2 3 2 30.7 -270.9 -616.4 2 -210.0 173.9 -616.4 2 30 -270 -616 2 -210 173 -616 2 -0.45 0.04 223.9 -3.0 19.3 0.005 35.0 1489 102
2014-05-28T18:32:25.010Z,1401301945.010 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:102 Calculated:113
2014-05-28T18:32:25.010Z,1401301945.010 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -457 -531 -546 -548 2 2 3 2 118.8 1.4 2 -69.9 -98.7 -561.4 2 118 22 -561 2 -69 -98 -561 2 -0.41 0.08 223.9 -3.0 19.4 0.005 35.0 1489 102
2014-05-28T18:33:21.776Z,1401302001.776 [DVL_micro](ERROR): No DVL communication! Re-initializing
2014-05-28T18:33:21.777Z,1401302001.777 [DVL_micro] Communications Fault, FailCount= 1
2014-05-28T18:33:21.777Z,1401302001.777 [DVL_micro](ERROR): Communications Fault
2014-05-28T18:33:21.931Z,1401302001.931 [CBIT](ERROR): Communications Fault in component: DVL_micro
2014-05-28T18:33:22.474Z,1401302002.474 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T18:33:23.143Z,1401302003.143 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T18:33:23.143Z,1401302003.143 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T18:33:23.143Z,1401302003.143 [DVL_micro](ERROR): Hardware Fault
2014-05-28T18:33:23.735Z,1401302003.735 [DVL_micro](INFO): Initializing
2014-05-28T18:33:23.927Z,1401302003.927 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T18:33:23.927Z,1401302003.927 [DVL_micro] No Fault, FailCount= 1
2014-05-28T18:33:28.021Z,1401302008.021 [Default:CallIridium] Running Loop=1
2014-05-28T18:33:28.021Z,1401302008.021 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-05-28T18:33:28.022Z,1401302008.022 [Default:CallIridium:A] Running Loop=1
2014-05-28T18:33:28.022Z,1401302008.022 [Default:CallIridium:A] Stopped
2014-05-28T18:33:28.022Z,1401302008.022 [Default:CallIridium:B] Running Loop=1
2014-05-28T18:33:28.022Z,1401302008.022 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-05-28T18:33:28.727Z,1401302008.727 [Default:Iridium] Running Loop=1
2014-05-28T18:33:28.727Z,1401302008.727 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-28T18:33:28.727Z,1401302008.727 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-28T18:33:28.727Z,1401302008.727 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-28T18:33:28.727Z,1401302008.727 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-28T18:33:28.728Z,1401302008.728 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-28T18:33:28.737Z,1401302008.737 [Default:Iridium:B.GoToSurface] Stopped
2014-05-28T18:33:28.737Z,1401302008.737 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-28T18:33:28.737Z,1401302008.737 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-28T18:33:34.254Z,1401302014.254 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20140528T171454/Courier0060.lzma
2014-05-28T18:33:34.825Z,1401302014.825 [NAL9602](FAULT): GPS failed to acquire within timeout.
2014-05-28T18:33:34.825Z,1401302014.825 [NAL9602] Data Fault, FailCount= 1
2014-05-28T18:33:34.825Z,1401302014.825 [NAL9602](ERROR): Data Fault
2014-05-28T18:33:34.961Z,1401302014.961 [CBIT](ERROR): Data Fault in component: NAL9602
2014-05-28T18:33:35.343Z,1401302015.343 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Courier0060.lzma.bak
2014-05-28T18:33:35.343Z,1401302015.343 [DataOverHttps](INFO): SBD MOMSN=980634
2014-05-28T18:33:35.349Z,1401302015.349 [NAL9602](INFO): Powering down
2014-05-28T18:33:37.607Z,1401302017.607 [CBIT](INFO): Clearing failed state for component NAL9602
2014-05-28T18:33:37.607Z,1401302017.607 [NAL9602] No Fault, FailCount= 1
2014-05-28T18:33:39.669Z,1401302019.669 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T18:33:39.669Z,1401302019.669 [DVL_micro] Data Fault, FailCount= 1
2014-05-28T18:33:39.669Z,1401302019.669 [DVL_micro](ERROR): Data Fault
2014-05-28T18:33:39.837Z,1401302019.837 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T18:33:40.648Z,1401302020.648 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T18:33:40.649Z,1401302020.649 [NAL9602](INFO): Powering up NAL9602
2014-05-28T18:33:41.226Z,1401302021.226 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T18:33:41.226Z,1401302021.226 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T18:33:41.226Z,1401302021.226 [DVL_micro](ERROR): Hardware Fault
2014-05-28T18:33:41.785Z,1401302021.785 [DVL_micro](INFO): Initializing
2014-05-28T18:33:41.999Z,1401302021.999 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T18:33:41.999Z,1401302021.999 [DVL_micro] No Fault, FailCount= 1
2014-05-28T18:33:46.030Z,1401302026.030 [DataOverHttps](INFO): Sending 269 bytes from file Logs/20140528T171454/Express0061.lzma
2014-05-28T18:33:47.141Z,1401302027.141 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Express0061.lzma.bak
2014-05-28T18:33:47.142Z,1401302027.142 [DataOverHttps](INFO): SBD MOMSN=980636
2014-05-28T18:33:58.927Z,1401302038.927 [HFRadarModelCalc](IMPORTANT): Forecast time 20140528T160000: published 50 modes in rows, 61 hours in columns, 3050 elements.
2014-05-28T18:34:01.398Z,1401302041.398 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients.
2014-05-28T18:34:01.435Z,1401302041.435 [Default:Iridium:Read_Iridium] Stopped
2014-05-28T18:34:01.436Z,1401302041.436 [Default:Iridium](INFO): Completed Default:Iridium
2014-05-28T18:34:01.436Z,1401302041.436 [Default:Iridium] Stopped
2014-05-28T18:34:01.436Z,1401302041.436 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-28T18:34:01.436Z,1401302041.436 [Default:Iridium:A.SetSpeed] Stopped
2014-05-28T18:34:01.436Z,1401302041.436 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-28T18:34:03.060Z,1401302043.060 [DVL_micro](ERROR): No DVL communication! Re-initializing
2014-05-28T18:34:03.060Z,1401302043.060 [DVL_micro] Communications Fault, FailCount= 2
2014-05-28T18:34:03.060Z,1401302043.060 [DVL_micro](ERROR): Communications Fault
2014-05-28T18:34:03.148Z,1401302043.148 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-05-28T18:34:03.148Z,1401302043.148 [Default:CallIridium:B] Stopped
2014-05-28T18:34:03.148Z,1401302043.148 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-28T18:34:03.148Z,1401302043.148 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-05-28T18:34:03.148Z,1401302043.148 [Default:CallIridium] Stopped
2014-05-28T18:34:03.148Z,1401302043.148 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-28T18:34:03.219Z,1401302043.219 [CBIT](ERROR): Communications Fault in component: DVL_micro
2014-05-28T18:34:05.350Z,1401302045.350 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T18:34:05.398Z,1401302045.398 [NAL9602](INFO): NAL9602 initialized
2014-05-28T18:34:06.299Z,1401302046.299 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T18:34:06.299Z,1401302046.299 [DVL_micro] Hardware Fault, FailCount= 2
2014-05-28T18:34:06.299Z,1401302046.299 [DVL_micro](ERROR): Hardware Fault
2014-05-28T18:34:06.848Z,1401302046.848 [DVL_micro](INFO): Initializing
2014-05-28T18:34:07.018Z,1401302047.018 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T18:34:07.018Z,1401302047.018 [DVL_micro] No Fault, FailCount= 2
2014-05-28T18:35:47.702Z,1401302147.702 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 41 of 46
2014-05-28T18:35:47.702Z,1401302147.702 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 -529 -497 -515 -533 2 2 3 2 -18.7 48.0 -559.2 2 46.7 -21.7 -559.2 2 -18 48 -559 2 46 -21 -559 2 -0.39 0.04 223.8 4 0.005 35.0 1489 109
2014-05-28T18:36:47.070Z,1401302207.070 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T18:36:47.070Z,1401302207.070 [DVL_micro] Data Fault, FailCount= 1
2014-05-28T18:36:47.070Z,1401302207.070 [DVL_micro](ERROR): Data Fault
2014-05-28T18:36:47.230Z,1401302207.230 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T18:36:47.869Z,1401302207.869 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T18:36:48.396Z,1401302208.396 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T18:36:48.396Z,1401302208.396 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T18:36:48.396Z,1401302208.396 [DVL_micro](ERROR): Hardware Fault
2014-05-28T18:36:49.035Z,1401302209.035 [DVL_micro](INFO): Initializing
2014-05-28T18:36:49.196Z,1401302209.196 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T18:36:49.196Z,1401302209.196 [DVL_micro] No Fault, FailCount= 1
2014-05-28T18:38:48.567Z,1401302328.567 [Default:CallIridium] Running Loop=1
2014-05-28T18:38:48.567Z,1401302328.567 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-05-28T18:38:48.567Z,1401302328.567 [Default:CallIridium:A] Running Loop=1
2014-05-28T18:38:48.567Z,1401302328.567 [Default:CallIridium:A] Stopped
2014-05-28T18:38:48.567Z,1401302328.567 [Default:CallIridium:B] Running Loop=1
2014-05-28T18:38:48.567Z,1401302328.567 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-05-28T18:38:49.112Z,1401302329.112 [Default:Iridium] Running Loop=1
2014-05-28T18:38:49.112Z,1401302329.112 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-28T18:38:49.112Z,1401302329.112 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-28T18:38:49.113Z,1401302329.113 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-28T18:38:49.113Z,1401302329.113 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-28T18:38:49.133Z,1401302329.133 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-28T18:38:49.134Z,1401302329.134 [Default:Iridium:B.GoToSurface] Stopped
2014-05-28T18:38:49.134Z,1401302329.134 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-28T18:38:49.134Z,1401302329.134 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-28T18:38:54.598Z,1401302334.598 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20140528T171454/Courier0064.lzma
2014-05-28T18:38:55.704Z,1401302335.704 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Courier0064.lzma.bak
2014-05-28T18:38:55.704Z,1401302335.704 [DataOverHttps](INFO): SBD MOMSN=980643
2014-05-28T18:39:06.292Z,1401302346.292 [DataOverHttps](INFO): Sending 290 bytes from file Logs/20140528T171454/Express0065.lzma
2014-05-28T18:39:07.434Z,1401302347.434 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Express0065.lzma.bak
2014-05-28T18:39:07.434Z,1401302347.434 [DataOverHttps](INFO): SBD MOMSN=980645
2014-05-28T18:39:19.406Z,1401302359.406 [HFRadarModelCalc](IMPORTANT): Forecast time 20140528T160000: published 50 modes in rows, 61 hours in columns, 3050 elements.
2014-05-28T18:39:21.916Z,1401302361.916 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients.
2014-05-28T18:39:21.952Z,1401302361.952 [Default:Iridium:Read_Iridium] Stopped
2014-05-28T18:39:21.952Z,1401302361.952 [Default:Iridium](INFO): Completed Default:Iridium
2014-05-28T18:39:21.952Z,1401302361.952 [Default:Iridium] Stopped
2014-05-28T18:39:21.952Z,1401302361.952 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-28T18:39:21.952Z,1401302361.952 [Default:Iridium:A.SetSpeed] Stopped
2014-05-28T18:39:21.953Z,1401302361.953 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-28T18:39:23.641Z,1401302363.641 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-05-28T18:39:23.641Z,1401302363.641 [Default:CallIridium:B] Stopped
2014-05-28T18:39:23.641Z,1401302363.641 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-28T18:39:23.641Z,1401302363.641 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-05-28T18:39:23.641Z,1401302363.641 [Default:CallIridium] Stopped
2014-05-28T18:39:23.641Z,1401302363.641 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-28T18:39:53.957Z,1401302393.957 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T18:39:53.957Z,1401302393.957 [DVL_micro] Data Fault, FailCount= 1
2014-05-28T18:39:53.957Z,1401302393.957 [DVL_micro](ERROR): Data Fault
2014-05-28T18:39:54.102Z,1401302394.102 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T18:39:54.555Z,1401302394.555 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T18:39:55.170Z,1401302395.170 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T18:39:55.170Z,1401302395.170 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T18:39:55.170Z,1401302395.170 [DVL_micro](ERROR): Hardware Fault
2014-05-28T18:39:55.701Z,1401302395.701 [DVL_micro](INFO): Initializing
2014-05-28T18:39:55.856Z,1401302395.856 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T18:39:55.856Z,1401302395.856 [DVL_micro] No Fault, FailCount= 1
2014-05-28T18:41:30.323Z,1401302490.323 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:96 Calculated:124
2014-05-28T18:41:30.324Z,1401302490.324 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -491 -496 -513 -669 2 3 3 2 29 -584.8 2 139.2 -186.5 -584.8 2 29 230 -584 2 139 -186 -584 2 -0.44 0.08 224.0 -3.0 19.5 0.005 35.0 1489 96
2014-05-28T18:41:40.531Z,1401302500.531 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:100 Calculated:112
2014-05-28T18:41:40.531Z,1401302500.531 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -460 -5-629 2 3 3 2 60.1 148.1 -569.5 2 59.4 -148.4 -569.5 2 60 148 -569 2 59 -148 -569 2 -0.42 0.04 223.9 -3.0 19.5 0.005 35.0 1489 100
2014-05-28T18:43:00.889Z,1401302580.889 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T18:43:00.889Z,1401302580.889 [DVL_micro] Data Fault, FailCount= 1
2014-05-28T18:43:00.889Z,1401302580.889 [DVL_micro](ERROR): Data Fault
2014-05-28T18:43:01.006Z,1401302581.006 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T18:43:01.424Z,1401302581.424 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T18:43:01.912Z,1401302581.912 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T18:43:01.912Z,1401302581.912 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T18:43:01.912Z,1401302581.912 [DVL_micro](ERROR): Hardware Fault
2014-05-28T18:43:02.418Z,1401302582.418 [DVL_micro](INFO): Initializing
2014-05-28T18:43:02.564Z,1401302582.564 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T18:43:02.564Z,1401302582.564 [DVL_micro] No Fault, FailCount= 1
2014-05-28T18:43:53.345Z,1401302633.345 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 43 of 46
2014-05-28T18:43:53.345Z,1401302633.345 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 -484 -490 -529 -593 2 3 3 2 60.1 137.5 -565.2 2 52.0 -140.8 -565.2 2 60 137 -565 2 52 -140 -565 2 -0.41 0.07 223.9 -3.0 19.6 0.005 35.0 1489 108
2014-05-28T18:44:07.610Z,1401302647.610 [NAL9602](FAULT): GPS failed to acquire within timeout.
2014-05-28T18:44:07.610Z,1401302647.610 [NAL9602] Data Fault, FailCount= 2
2014-05-28T18:44:07.610Z,1401302647.610 [NAL9602](ERROR): Data Fault
2014-05-28T18:44:07.728Z,1401302647.728 [CBIT](ERROR): Data Fault in component: NAL9602
2014-05-28T18:44:07.728Z,1401302647.728 [CBIT](CRITICAL): Data Fault in component: NAL9602
2014-05-28T18:44:08.230Z,1401302648.230 [NAL9602](INFO): Powering down
2014-05-28T18:44:09.289Z,1401302649.289 [Default:CallIridium] Running Loop=1
2014-05-28T18:44:09.289Z,1401302649.289 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-05-28T18:44:09.289Z,1401302649.289 [Default:CallIridium:A] Running Loop=1
2014-05-28T18:44:09.289Z,1401302649.289 [Default:CallIridium:A] Stopped
2014-05-28T18:44:09.289Z,1401302649.289 [Default:CallIridium:B] Running Loop=1
2014-05-28T18:44:09.290Z,1401302649.290 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-05-28T18:44:09.857Z,1401302649.857 [Default:Iridium] Running Loop=1
2014-05-28T18:44:09.857Z,1401302649.857 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-28T18:44:09.857Z,1401302649.857 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-28T18:44:09.857Z,1401302649.857 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-28T18:44:09.857Z,1401302649.857 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-28T18:44:09.858Z,1401302649.858 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-28T18:44:09.879Z,1401302649.879 [Default:Iridium:B.GoToSurface] Stopped
2014-05-28T18:44:09.879Z,1401302649.879 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-28T18:44:09.879Z,1401302649.879 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-28T18:44:13.853Z,1401302653.853 [DataOverHttps](INFO): Sending 87 bytes from file Logs/20140528T171454/Courier0068.lzma
2014-05-28T18:44:14.782Z,1401302654.782 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Courier0068.lzma.bak
2014-05-28T18:44:14.782Z,1401302654.782 [DataOverHttps](INFO): SBD MOMSN=980654
2014-05-28T18:44:22.567Z,1401302662.567 [DataOverHttps](INFO): Sending 268 bytes from file Logs/20140528T171454/Express0069.lzma
2014-05-28T18:44:23.500Z,1401302663.500 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Express0069.lzma.bak
2014-05-28T18:44:23.500Z,1401302663.500 [DataOverHttps](INFO): SBD MOMSN=980657
2014-05-28T18:44:31.624Z,1401302671.624 [HFRadarModelCalc](IMPORTANT): Forecast time 20140528T160000: published 50 modes in rows, 61 hours in columns, 3050 elements.
2014-05-28T18:44:33.207Z,1401302673.207 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients.
2014-05-28T18:44:33.238Z,1401302673.238 [Default:Iridium:Read_Iridium] Stopped
2014-05-28T18:44:33.243Z,1401302673.243 [Default:Iridium](INFO): Completed Default:Iridium
2014-05-28T18:44:33.243Z,1401302673.243 [Default:Iridium] Stopped
2014-05-28T18:44:33.243Z,1401302673.243 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-28T18:44:33.243Z,1401302673.243 [Default:Iridium:A.SetSpeed] Stopped
2014-05-28T18:44:33.243Z,1401302673.243 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-28T18:44:34.146Z,1401302674.146 [DVL_micro](ERROR): No DVL communication! Re-initializing
2014-05-28T18:44:34.146Z,1401302674.146 [DVL_micro] Communications Fault, FailCount= 1
2014-05-28T18:44:34.146Z,1401302674.146 [DVL_micro](ERROR): Communications Fault
2014-05-28T18:44:34.242Z,1401302674.242 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-05-28T18:44:34.242Z,1401302674.242 [Default:CallIridium:B] Stopped
2014-05-28T18:44:34.242Z,1401302674.242 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-28T18:44:34.242Z,1401302674.242 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-05-28T18:44:34.242Z,1401302674.242 [Default:CallIridium] Stopped
2014-05-28T18:44:34.242Z,1401302674.242 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-28T18:44:34.252Z,1401302674.252 [CBIT](ERROR): Communications Fault in component: DVL_micro
2014-05-28T18:44:35.727Z,1401302675.727 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T18:44:36.331Z,1401302676.331 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T18:44:36.331Z,1401302676.331 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T18:44:36.331Z,1401302676.331 [DVL_micro](ERROR): Hardware Fault
2014-05-28T18:44:36.858Z,1401302676.858 [DVL_micro](INFO): Initializing
2014-05-28T18:44:36.951Z,1401302676.951 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T18:44:36.951Z,1401302676.951 [DVL_micro] No Fault, FailCount= 1
2014-05-28T18:46:07.423Z,1401302767.423 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T18:46:07.423Z,1401302767.423 [DVL_micro] Data Fault, FailCount= 1
2014-05-28T18:46:07.423Z,1401302767.423 [DVL_micro](ERROR): Data Fault
2014-05-28T18:46:07.549Z,1401302767.549 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T18:46:07.978Z,1401302767.978 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T18:46:08.084Z,1401302768.084 [CBIT](INFO): Clearing failed count for component NAL9602
2014-05-28T18:46:08.084Z,1401302768.084 [NAL9602] No Fault, FailCount= 2
2014-05-28T18:46:08.516Z,1401302768.516 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T18:46:08.516Z,1401302768.516 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T18:46:08.516Z,1401302768.516 [DVL_micro](ERROR): Hardware Fault
2014-05-28T18:46:08.518Z,1401302768.518 [NAL9602](INFO): Powering up NAL9602
2014-05-28T18:46:09.079Z,1401302769.079 [DVL_micro](INFO): Initializing
2014-05-28T18:46:09.193Z,1401302769.193 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T18:46:09.193Z,1401302769.193 [DVL_micro] No Fault, FailCount= 1
2014-05-28T18:46:19.477Z,1401302779.477 [NAL9602](INFO): NAL9602 initialized
2014-05-28T18:48:35.072Z,1401302915.072 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46
2014-05-28T18:48:35.072Z,1401302915.072 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -555 -520 -589 -523 2 .4 4.0 -589.7 2 -29.8 -34.5 -589.7 2 45 4 -589 2 -29 -34 -589 2 -0.40 0.13 224.1 -3.0 19.6 0.005 35.0 1489 101
2014-05-28T18:49:13.504Z,1401302953.504 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T18:49:13.504Z,1401302953.504 [DVL_micro] Data Fault, FailCount= 1
2014-05-28T18:49:13.504Z,1401302953.504 [DVL_micro](ERROR): Data Fault
2014-05-28T18:49:13.615Z,1401302953.615 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T18:49:14.050Z,1401302954.050 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T18:49:14.516Z,1401302954.516 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T18:49:14.517Z,1401302954.517 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T18:49:14.517Z,1401302954.517 [DVL_micro](ERROR): Hardware Fault
2014-05-28T18:49:15.008Z,1401302955.008 [DVL_micro](INFO): Initializing
2014-05-28T18:49:15.116Z,1401302955.116 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T18:49:15.116Z,1401302955.116 [DVL_micro] No Fault, FailCount= 1
2014-05-28T18:49:24.602Z,1401302964.602 [Default:CallIridium] Running Loop=1
2014-05-28T18:49:24.602Z,1401302964.602 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-05-28T18:49:24.602Z,1401302964.602 [Default:CallIridium:A] Running Loop=1
2014-05-28T18:49:24.602Z,1401302964.602 [Default:CallIridium:A] Stopped
2014-05-28T18:49:24.602Z,1401302964.602 [Default:CallIridium:B] Running Loop=1
2014-05-28T18:49:24.602Z,1401302964.602 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-05-28T18:49:25.028Z,1401302965.028 [Default:Iridium] Running Loop=1
2014-05-28T18:49:25.028Z,1401302965.028 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-28T18:49:25.028Z,1401302965.028 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-28T18:49:25.029Z,1401302965.029 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-28T18:49:25.029Z,1401302965.029 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-28T18:49:25.029Z,1401302965.029 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-28T18:49:25.029Z,1401302965.029 [Default:Iridium:B.GoToSurface] Stopped
2014-05-28T18:49:25.030Z,1401302965.030 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-28T18:49:25.030Z,1401302965.030 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-28T18:49:29.591Z,1401302969.591 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20140528T171454/Courier0072.lzma
2014-05-28T18:49:30.612Z,1401302970.612 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Courier0072.lzma.bak
2014-05-28T18:49:30.612Z,1401302970.612 [DataOverHttps](INFO): SBD MOMSN=980665
2014-05-28T18:49:38.343Z,1401302978.343 [DataOverHttps](INFO): Sending 269 bytes from file Logs/20140528T171454/Express0073.lzma
2014-05-28T18:49:39.478Z,1401302979.478 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Express0073.lzma.bak
2014-05-28T18:49:39.478Z,1401302979.478 [DataOverHttps](INFO): SBD MOMSN=980667
2014-05-28T18:49:47.083Z,1401302987.083 [HFRadarModelCalc](IMPORTANT): Forecast time 20140528T160000: published 50 modes in rows, 61 hours in columns, 3050 elements.
2014-05-28T18:49:48.632Z,1401302988.632 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients.
2014-05-28T18:49:48.651Z,1401302988.651 [Default:Iridium:Read_Iridium] Stopped
2014-05-28T18:49:48.651Z,1401302988.651 [Default:Iridium](INFO): Completed Default:Iridium
2014-05-28T18:49:48.651Z,1401302988.651 [Default:Iridium] Stopped
2014-05-28T18:49:48.652Z,1401302988.652 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-28T18:49:48.652Z,1401302988.652 [Default:Iridium:A.SetSpeed] Stopped
2014-05-28T18:49:48.652Z,1401302988.652 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-28T18:49:49.643Z,1401302989.643 [DVL_micro](ERROR): No DVL communication! Re-initializing
2014-05-28T18:49:49.643Z,1401302989.643 [DVL_micro] Communications Fault, FailCount= 1
2014-05-28T18:49:49.643Z,1401302989.643 [DVL_micro](ERROR): Communications Fault
2014-05-28T18:49:49.724Z,1401302989.724 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-05-28T18:49:49.724Z,1401302989.724 [Default:CallIridium:B] Stopped
2014-05-28T18:49:49.724Z,1401302989.724 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-28T18:49:49.725Z,1401302989.725 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-05-28T18:49:49.725Z,1401302989.725 [Default:CallIridium] Stopped
2014-05-28T18:49:49.725Z,1401302989.725 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-28T18:49:49.748Z,1401302989.748 [CBIT](ERROR): Communications Fault in component: DVL_micro
2014-05-28T18:49:51.268Z,1401302991.268 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T18:49:51.786Z,1401302991.786 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T18:49:51.786Z,1401302991.786 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T18:49:51.786Z,1401302991.786 [DVL_micro](ERROR): Hardware Fault
2014-05-28T18:49:52.342Z,1401302992.342 [DVL_micro](INFO): Initializing
2014-05-28T18:49:52.504Z,1401302992.504 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T18:49:52.504Z,1401302992.504 [DVL_micro] No Fault, FailCount= 1
2014-05-28T18:52:19.868Z,1401303139.868 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T18:52:19.868Z,1401303139.868 [DVL_micro] Data Fault, FailCount= 1
2014-05-28T18:52:19.868Z,1401303139.868 [DVL_micro](ERROR): Data Fault
2014-05-28T18:52:19.998Z,1401303139.998 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T18:52:20.415Z,1401303140.415 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T18:52:20.845Z,1401303140.845 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T18:52:20.845Z,1401303140.845 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T18:52:20.846Z,1401303140.846 [DVL_micro](ERROR): Hardware Fault
2014-05-28T18:52:21.313Z,1401303141.313 [DVL_micro](INFO): Initializing
2014-05-28T18:52:21.450Z,1401303141.450 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T18:52:21.450Z,1401303141.450 [DVL_micro] No Fault, FailCount= 1
2014-05-28T18:53:33.095Z,1401303213.095 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 44 of 46
2014-05-28T18:53:33.100Z,1401303213.100 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -451 -478 -472 -533 2 2 3 2 28.0 73.4 -521.5 2 30.6 -72.4 -521.3 -521 2 30 -72 -521 2 -0.40 0.03 223.8 -3.0 19.7 0.005 35.0 1489 105
2014-05-28T18:54:40.661Z,1401303280.661 [Default:CallIridium] Running Loop=1
2014-05-28T18:54:40.661Z,1401303280.661 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-05-28T18:54:40.661Z,1401303280.661 [Default:CallIridium:A] Running Loop=1
2014-05-28T18:54:40.661Z,1401303280.661 [Default:CallIridium:A] Stopped
2014-05-28T18:54:40.661Z,1401303280.661 [Default:CallIridium:B] Running Loop=1
2014-05-28T18:54:40.661Z,1401303280.661 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-05-28T18:54:41.140Z,1401303281.140 [Default:Iridium] Running Loop=1
2014-05-28T18:54:41.140Z,1401303281.140 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-28T18:54:41.140Z,1401303281.140 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-28T18:54:41.141Z,1401303281.141 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-28T18:54:41.141Z,1401303281.141 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-28T18:54:41.141Z,1401303281.141 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-28T18:54:41.146Z,1401303281.146 [Default:Iridium:B.GoToSurface] Stopped
2014-05-28T18:54:41.146Z,1401303281.146 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-28T18:54:41.146Z,1401303281.146 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-28T18:54:45.041Z,1401303285.041 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20140528T171454/Courier0076.lzma
2014-05-28T18:54:46.089Z,1401303286.089 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Courier0076.lzma.bak
2014-05-28T18:54:46.089Z,1401303286.089 [DataOverHttps](INFO): SBD MOMSN=980675
2014-05-28T18:54:53.324Z,1401303293.324 [DataOverHttps](INFO): Sending 261 bytes from file Logs/20140528T171454/Express0077.lzma
2014-05-28T18:54:54.380Z,1401303294.380 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Express0077.lzma.bak
2014-05-28T18:54:54.380Z,1401303294.380 [DataOverHttps](INFO): SBD MOMSN=980677
2014-05-28T18:55:01.989Z,1401303301.989 [HFRadarModelCalc](IMPORTANT): Forecast time 20140528T160000: published 50 modes in rows, 61 hours in columns, 3050 elements.
2014-05-28T18:55:03.521Z,1401303303.521 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients.
2014-05-28T18:55:03.547Z,1401303303.547 [Default:Iridium:Read_Iridium] Stopped
2014-05-28T18:55:03.547Z,1401303303.547 [Default:Iridium](INFO): Completed Default:Iridium
2014-05-28T18:55:03.547Z,1401303303.547 [Default:Iridium] Stopped
2014-05-28T18:55:03.569Z,1401303303.569 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-28T18:55:03.569Z,1401303303.569 [Default:Iridium:A.SetSpeed] Stopped
2014-05-28T18:55:03.569Z,1401303303.569 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-28T18:55:04.467Z,1401303304.467 [DVL_micro](ERROR): No DVL communication! Re-initializing
2014-05-28T18:55:04.468Z,1401303304.468 [DVL_micro] Communications Fault, FailCount= 1
2014-05-28T18:55:04.468Z,1401303304.468 [DVL_micro](ERROR): Communications Fault
2014-05-28T18:55:04.548Z,1401303304.548 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-05-28T18:55:04.548Z,1401303304.548 [Default:CallIridium:B] Stopped
2014-05-28T18:55:04.548Z,1401303304.548 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-28T18:55:04.548Z,1401303304.548 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-05-28T18:55:04.549Z,1401303304.549 [Default:CallIridium] Stopped
2014-05-28T18:55:04.549Z,1401303304.549 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-28T18:55:04.617Z,1401303304.617 [CBIT](ERROR): Communications Fault in component: DVL_micro
2014-05-28T18:55:06.196Z,1401303306.196 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T18:55:06.747Z,1401303306.747 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T18:55:06.747Z,1401303306.747 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T18:55:06.747Z,1401303306.747 [DVL_micro](ERROR): Hardware Fault
2014-05-28T18:55:07.234Z,1401303307.234 [DVL_micro](INFO): Initializing
2014-05-28T18:55:07.338Z,1401303307.338 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T18:55:07.338Z,1401303307.338 [DVL_micro] No Fault, FailCount= 1
2014-05-28T18:55:21.473Z,1401303321.473 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:55:23.896Z,1401303323.896 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:55:25.961Z,1401303325.961 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T18:55:25.961Z,1401303325.961 [DVL_micro] Data Fault, FailCount= 1
2014-05-28T18:55:25.961Z,1401303325.961 [DVL_micro](ERROR): Data Fault
2014-05-28T18:55:26.080Z,1401303326.080 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T18:55:26.502Z,1401303326.502 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:55:26.596Z,1401303326.596 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T18:55:27.106Z,1401303327.106 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T18:55:27.106Z,1401303327.106 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T18:55:27.106Z,1401303327.106 [DVL_micro](ERROR): Hardware Fault
2014-05-28T18:55:27.581Z,1401303327.581 [DVL_micro](INFO): Initializing
2014-05-28T18:55:27.706Z,1401303327.706 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T18:55:27.706Z,1401303327.706 [DVL_micro] No Fault, FailCount= 1
2014-05-28T18:55:29.047Z,1401303329.047 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:55:31.587Z,1401303331.587 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:55:34.050Z,1401303334.050 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:55:36.596Z,1401303336.596 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:55:38.552Z,1401303338.552 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:55:41.444Z,1401303341.444 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:55:43.617Z,1401303343.617 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:55:46.136Z,1401303346.136 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:55:48.695Z,1401303348.695 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:55:51.128Z,1401303351.128 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:55:53.688Z,1401303353.688 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:55:56.188Z,1401303356.188 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:55:58.429Z,1401303358.429 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:56:00.926Z,1401303360.926 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:56:03.545Z,1401303363.545 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:56:05.996Z,1401303365.996 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:56:08.153Z,1401303368.153 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:56:10.606Z,1401303370.606 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:56:13.324Z,1401303373.324 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:56:15.779Z,1401303375.779 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:56:18.304Z,1401303378.304 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-05-28T18:56:20.722Z,1401303380.722 [NAL9602](FAULT): GPS failed to acquire within timeout.
2014-05-28T18:56:20.722Z,1401303380.722 [NAL9602] Data Fault, FailCount= 1
2014-05-28T18:56:20.722Z,1401303380.722 [NAL9602](ERROR): Data Fault
2014-05-28T18:56:20.833Z,1401303380.833 [CBIT](ERROR): Data Fault in component: NAL9602
2014-05-28T18:56:21.179Z,1401303381.179 [NAL9602](INFO): Powering down
2014-05-28T18:56:22.279Z,1401303382.279 [CBIT](INFO): Clearing failed state for component NAL9602
2014-05-28T18:56:22.279Z,1401303382.279 [NAL9602] No Fault, FailCount= 1
2014-05-28T18:56:26.649Z,1401303386.649 [NAL9602](INFO): Powering up NAL9602
2014-05-28T18:56:37.314Z,1401303397.314 [NAL9602](INFO): NAL9602 initialized
2014-05-28T18:56:38.383Z,1401303398.383 [NAL9602](ERROR): getFix uart error: serial timeout
2014-05-28T18:58:32.983Z,1401303512.983 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T18:58:32.983Z,1401303512.983 [DVL_micro] Data Fault, FailCount= 1
2014-05-28T18:58:32.983Z,1401303512.983 [DVL_micro](ERROR): Data Fault
2014-05-28T18:58:33.127Z,1401303513.127 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T18:58:33.554Z,1401303513.554 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T18:58:34.032Z,1401303514.032 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T18:58:34.032Z,1401303514.032 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T18:58:34.032Z,1401303514.032 [DVL_micro](ERROR): Hardware Fault
2014-05-28T18:58:34.576Z,1401303514.576 [DVL_micro](INFO): Initializing
2014-05-28T18:58:34.674Z,1401303514.674 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T18:58:34.674Z,1401303514.674 [DVL_micro] No Fault, FailCount= 1
2014-05-28T18:59:55.539Z,1401303595.539 [Default:CallIridium] Running Loop=1
2014-05-28T18:59:55.539Z,1401303595.539 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-05-28T18:59:55.539Z,1401303595.539 [Default:CallIridium:A] Running Loop=1
2014-05-28T18:59:55.540Z,1401303595.540 [Default:CallIridium:A] Stopped
2014-05-28T18:59:55.540Z,1401303595.540 [Default:CallIridium:B] Running Loop=1
2014-05-28T18:59:55.540Z,1401303595.540 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-05-28T18:59:55.980Z,1401303595.980 [Default:Iridium] Running Loop=1
2014-05-28T18:59:55.980Z,1401303595.980 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-28T18:59:55.980Z,1401303595.980 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-28T18:59:55.980Z,1401303595.980 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-28T18:59:55.981Z,1401303595.981 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-28T18:59:55.981Z,1401303595.981 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-28T18:59:56.014Z,1401303596.014 [Default:Iridium:B.GoToSurface] Stopped
2014-05-28T18:59:56.014Z,1401303596.014 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-28T18:59:56.014Z,1401303596.014 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-28T19:00:00.294Z,1401303600.294 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20140528T171454/Courier0080.lzma
2014-05-28T19:00:01.320Z,1401303601.320 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Courier0080.lzma.bak
2014-05-28T19:00:01.321Z,1401303601.321 [DataOverHttps](INFO): SBD MOMSN=980683
2014-05-28T19:00:13.115Z,1401303613.115 [DataOverHttps](INFO): Sending 288 bytes from file Logs/20140528T171454/Express0081.lzma
2014-05-28T19:00:14.078Z,1401303614.078 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Express0081.lzma.bak
2014-05-28T19:00:14.078Z,1401303614.078 [DataOverHttps](INFO): SBD MOMSN=980685
2014-05-28T19:00:21.792Z,1401303621.792 [HFRadarModelCalc](IMPORTANT): Forecast time 20140528T160000: published 50 modes in rows, 61 hours in columns, 3050 elements.
2014-05-28T19:00:23.333Z,1401303623.333 [HFRadarCompactModelForecaster](DEBUG): Found new ECs!
2014-05-28T19:00:29.955Z,1401303629.955 [HFRadarCompactModelForecaster](IMPORTANT): Forecast time 201405281600: published 50 modes in rows, 61 hours in columns, 3050 elements.
2014-05-28T19:00:29.981Z,1401303629.981 [Default:Iridium:Read_Iridium] Stopped
2014-05-28T19:00:29.982Z,1401303629.982 [Default:Iridium](INFO): Completed Default:Iridium
2014-05-28T19:00:29.982Z,1401303629.982 [Default:Iridium] Stopped
2014-05-28T19:00:29.982Z,1401303629.982 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-28T19:00:29.982Z,1401303629.982 [Default:Iridium:A.SetSpeed] Stopped
2014-05-28T19:00:29.982Z,1401303629.982 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-28T19:00:31.238Z,1401303631.238 [DVL_micro](ERROR): No DVL communication! Re-initializing
2014-05-28T19:00:31.238Z,1401303631.238 [DVL_micro] Communications Fault, FailCount= 1
2014-05-28T19:00:31.238Z,1401303631.238 [DVL_micro](ERROR): Communications Fault
2014-05-28T19:00:31.321Z,1401303631.321 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-05-28T19:00:31.321Z,1401303631.321 [Default:CallIridium:B] Stopped
2014-05-28T19:00:31.321Z,1401303631.321 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-28T19:00:31.321Z,1401303631.321 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-05-28T19:00:31.321Z,1401303631.321 [Default:CallIridium] Stopped
2014-05-28T19:00:31.321Z,1401303631.321 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-28T19:00:31.335Z,1401303631.335 [CBIT](ERROR): Communications Fault in component: DVL_micro
2014-05-28T19:00:32.895Z,1401303632.895 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T19:00:33.397Z,1401303633.397 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T19:00:33.397Z,1401303633.397 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T19:00:33.397Z,1401303633.397 [DVL_micro](ERROR): Hardware Fault
2014-05-28T19:00:33.881Z,1401303633.881 [DVL_micro](INFO): Initializing
2014-05-28T19:00:34.001Z,1401303634.001 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T19:00:34.002Z,1401303634.002 [DVL_micro] No Fault, FailCount= 1
2014-05-28T19:00:46.409Z,1401303646.409 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#5 STATUS: 65535
2014-05-28T19:00:50.905Z,1401303650.905 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#5 STATUS: 65535
2014-05-28T19:00:54.984Z,1401303654.984 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#5 STATUS: 65535
2014-05-28T19:00:59.534Z,1401303659.534 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#5 STATUS: 65535
2014-05-28T19:01:03.713Z,1401303663.713 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#5 STATUS: 65535
2014-05-28T19:01:08.225Z,1401303668.225 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#5 STATUS: 65535
2014-05-28T19:01:12.265Z,1401303672.265 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#5 STATUS: 65535
2014-05-28T19:01:17.701Z,1401303677.701 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#5 STATUS: 65535
2014-05-28T19:01:20.839Z,1401303680.839 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#5 STATUS: 65535
2014-05-28T19:01:25.314Z,1401303685.314 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#5 STATUS: 65535
2014-05-28T19:01:29.387Z,1401303689.387 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#5 STATUS: 65535
2014-05-28T19:01:33.967Z,1401303693.967 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#5 STATUS: 65535
2014-05-28T19:01:39.372Z,1401303699.372 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T19:01:39.372Z,1401303699.372 [DVL_micro] Data Fault, FailCount= 1
2014-05-28T19:01:39.372Z,1401303699.372 [DVL_micro](ERROR): Data Fault
2014-05-28T19:01:39.523Z,1401303699.523 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T19:01:39.963Z,1401303699.963 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T19:01:40.433Z,1401303700.433 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T19:01:40.433Z,1401303700.433 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T19:01:40.433Z,1401303700.433 [DVL_micro](ERROR): Hardware Fault
2014-05-28T19:01:40.902Z,1401303700.902 [DVL_micro](INFO): Initializing
2014-05-28T19:01:41.022Z,1401303701.022 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T19:01:41.022Z,1401303701.022 [DVL_micro] No Fault, FailCount= 1
2014-05-28T19:04:32.706Z,1401303872.706 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:111 Calculated:120
2014-05-28T19:04:32.707Z,1401303872.707 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -4-442 -394 2 2 3 2 22.7 -4.0 -447.1 2 -19.2 -12.8 -447.1 2 22 -4 -447 2 -19 -12 -447 2 -0.39 0.02 223.8 -3.0 19.8 0.005 35.0 1489 111
2014-05-28T19:04:45.612Z,1401303885.612 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T19:04:45.612Z,1401303885.612 [DVL_micro] Data Fault, FailCount= 1
2014-05-28T19:04:45.612Z,1401303885.612 [DVL_micro](ERROR): Data Fault
2014-05-28T19:04:45.748Z,1401303885.748 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T19:04:46.187Z,1401303886.187 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T19:04:46.646Z,1401303886.646 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T19:04:46.646Z,1401303886.646 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T19:04:46.646Z,1401303886.646 [DVL_micro](ERROR): Hardware Fault
2014-05-28T19:04:47.112Z,1401303887.112 [DVL_micro](INFO): Initializing
2014-05-28T19:04:47.230Z,1401303887.230 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T19:04:47.230Z,1401303887.230 [DVL_micro] No Fault, FailCount= 1
2014-05-28T19:05:15.586Z,1401303915.586 [Default:CallIridium] Running Loop=1
2014-05-28T19:05:15.587Z,1401303915.587 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-05-28T19:05:15.587Z,1401303915.587 [Default:CallIridium:A] Running Loop=1
2014-05-28T19:05:15.587Z,1401303915.587 [Default:CallIridium:A] Stopped
2014-05-28T19:05:15.587Z,1401303915.587 [Default:CallIridium:B] Running Loop=1
2014-05-28T19:05:15.587Z,1401303915.587 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-05-28T19:05:16.067Z,1401303916.067 [Default:Iridium] Running Loop=1
2014-05-28T19:05:16.068Z,1401303916.068 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-28T19:05:16.068Z,1401303916.068 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-28T19:05:16.068Z,1401303916.068 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-28T19:05:16.068Z,1401303916.068 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-28T19:05:16.068Z,1401303916.068 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-28T19:05:16.069Z,1401303916.069 [Default:Iridium:B.GoToSurface] Stopped
2014-05-28T19:05:16.069Z,1401303916.069 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-28T19:05:16.069Z,1401303916.069 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-28T19:05:19.960Z,1401303919.960 [DataOverHttps](INFO): Sending 47 bytes from file Logs/20140528T171454/Courier0084.lzma
2014-05-28T19:05:21.011Z,1401303921.011 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Courier0084.lzma.bak
2014-05-28T19:05:21.012Z,1401303921.012 [DataOverHttps](INFO): SBD MOMSN=980694
2014-05-28T19:05:32.345Z,1401303932.345 [DataOverHttps](INFO): Sending 273 bytes from file Logs/20140528T171454/Express0085.lzma
2014-05-28T19:05:33.357Z,1401303933.357 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Express0085.lzma.bak
2014-05-28T19:05:33.357Z,1401303933.357 [DataOverHttps](INFO): SBD MOMSN=980696
2014-05-28T19:05:40.973Z,1401303940.973 [HFRadarModelCalc](IMPORTANT): Forecast time 20140528T160000: published 50 modes in rows, 61 hours in columns, 3050 elements.
2014-05-28T19:05:42.508Z,1401303942.508 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients.
2014-05-28T19:05:42.520Z,1401303942.520 [Default:Iridium:Read_Iridium] Stopped
2014-05-28T19:05:42.521Z,1401303942.521 [Default:Iridium](INFO): Completed Default:Iridium
2014-05-28T19:05:42.521Z,1401303942.521 [Default:Iridium] Stopped
2014-05-28T19:05:42.521Z,1401303942.521 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-28T19:05:42.521Z,1401303942.521 [Default:Iridium:A.SetSpeed] Stopped
2014-05-28T19:05:42.521Z,1401303942.521 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-28T19:05:43.466Z,1401303943.466 [DVL_micro](ERROR): No DVL communication! Re-initializing
2014-05-28T19:05:43.467Z,1401303943.467 [DVL_micro] Communications Fault, FailCount= 1
2014-05-28T19:05:43.467Z,1401303943.467 [DVL_micro](ERROR): Communications Fault
2014-05-28T19:05:43.566Z,1401303943.566 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-05-28T19:05:43.566Z,1401303943.566 [Default:CallIridium:B] Stopped
2014-05-28T19:05:43.566Z,1401303943.566 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-28T19:05:43.566Z,1401303943.566 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-05-28T19:05:43.566Z,1401303943.566 [Default:CallIridium] Stopped
2014-05-28T19:05:43.567Z,1401303943.567 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-28T19:05:43.609Z,1401303943.609 [CBIT](ERROR): Communications Fault in component: DVL_micro
2014-05-28T19:05:45.131Z,1401303945.131 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T19:05:45.710Z,1401303945.710 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T19:05:45.710Z,1401303945.710 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T19:05:45.710Z,1401303945.710 [DVL_micro](ERROR): Hardware Fault
2014-05-28T19:05:46.327Z,1401303946.327 [DVL_micro](INFO): Initializing
2014-05-28T19:05:46.459Z,1401303946.459 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T19:05:46.459Z,1401303946.459 [DVL_micro] No Fault, FailCount= 1
2014-05-28T19:06:27.176Z,1401303987.176 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 42 of 46
2014-05-28T19:06:27.177Z,1401303987.177 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 -266 -441 -567 -436 2 2 3 2 401.7 -6.7 -461.1 2 -293.6 -274.2 -461.-6 -461 2 -293 -274 -461 2 -0.42 0.03 224.0 -3.0 19.8 0.005 35.0 1489 96
2014-05-28T19:06:40.766Z,1401304000.766 [NAL9602](FAULT): GPS failed to acquire within timeout.
2014-05-28T19:06:40.766Z,1401304000.766 [NAL9602] Data Fault, FailCount= 2
2014-05-28T19:06:40.766Z,1401304000.766 [NAL9602](ERROR): Data Fault
2014-05-28T19:06:40.907Z,1401304000.907 [CBIT](ERROR): Data Fault in component: NAL9602
2014-05-28T19:06:40.907Z,1401304000.907 [CBIT](CRITICAL): Data Fault in component: NAL9602
2014-05-28T19:06:41.316Z,1401304001.316 [NAL9602](INFO): Powering down
2014-05-28T19:06:44.306Z,1401304004.306 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 43 of 46
2014-05-28T19:06:44.307Z,1401304004.307 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -437 -489 -407 -406 2 0.0 -110.8 -468.9 2 -48.0 107.6 -468.9 2 -40 -110 -468 2 -48 107 -468 2 -0.42 0.03 223.9 -3.0 19.8 0.005 35.02
2014-05-28T19:07:51.905Z,1401304071.905 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T19:07:51.905Z,1401304071.905 [DVL_micro] Data Fault, FailCount= 1
2014-05-28T19:07:51.905Z,1401304071.905 [DVL_micro](ERROR): Data Fault
2014-05-28T19:07:52.036Z,1401304072.036 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T19:07:52.456Z,1401304072.456 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T19:07:52.926Z,1401304072.926 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T19:07:52.927Z,1401304072.927 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T19:07:52.927Z,1401304072.927 [DVL_micro](ERROR): Hardware Fault
2014-05-28T19:07:53.381Z,1401304073.381 [DVL_micro](INFO): Initializing
2014-05-28T19:07:53.466Z,1401304073.466 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T19:07:53.466Z,1401304073.466 [DVL_micro] No Fault, FailCount= 1
2014-05-28T19:08:41.208Z,1401304121.208 [CBIT](INFO): Clearing failed count for component NAL9602
2014-05-28T19:08:41.208Z,1401304121.208 [NAL9602] No Fault, FailCount= 2
2014-05-28T19:08:41.627Z,1401304121.627 [NAL9602](INFO): Powering up NAL9602
2014-05-28T19:08:52.123Z,1401304132.123 [NAL9602](INFO): NAL9602 initialized
2014-05-28T19:10:34.566Z,1401304234.566 [Default:CallIridium] Running Loop=1
2014-05-28T19:10:34.566Z,1401304234.566 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-05-28T19:10:34.566Z,1401304234.566 [Default:CallIridium:A] Running Loop=1
2014-05-28T19:10:34.567Z,1401304234.567 [Default:CallIridium:A] Stopped
2014-05-28T19:10:34.567Z,1401304234.567 [Default:CallIridium:B] Running Loop=1
2014-05-28T19:10:34.587Z,1401304234.587 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-05-28T19:10:35.307Z,1401304235.307 [Default:Iridium] Running Loop=1
2014-05-28T19:10:35.307Z,1401304235.307 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-28T19:10:35.308Z,1401304235.308 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-28T19:10:35.308Z,1401304235.308 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-28T19:10:35.308Z,1401304235.308 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-28T19:10:35.308Z,1401304235.308 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-28T19:10:35.309Z,1401304235.309 [Default:Iridium:B.GoToSurface] Stopped
2014-05-28T19:10:35.309Z,1401304235.309 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-28T19:10:35.309Z,1401304235.309 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-28T19:10:39.676Z,1401304239.676 [DataOverHttps](INFO): Sending 88 bytes from file Logs/20140528T171454/Courier0088.lzma
2014-05-28T19:10:40.768Z,1401304240.768 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Courier0088.lzma.bak
2014-05-28T19:10:40.768Z,1401304240.768 [DataOverHttps](INFO): SBD MOMSN=980705
2014-05-28T19:10:52.768Z,1401304252.768 [DataOverHttps](INFO): Sending 278 bytes from file Logs/20140528T171454/Express0089.lzma
2014-05-28T19:10:53.714Z,1401304253.714 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Express0089.lzma.bak
2014-05-28T19:10:53.714Z,1401304253.714 [DataOverHttps](INFO): SBD MOMSN=980708
2014-05-28T19:11:01.337Z,1401304261.337 [HFRadarModelCalc](IMPORTANT): Forecast time 20140528T160000: published 50 modes in rows, 61 hours in columns, 3050 elements.
2014-05-28T19:11:02.885Z,1401304262.885 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients.
2014-05-28T19:11:02.924Z,1401304262.924 [Default:Iridium:Read_Iridium] Stopped
2014-05-28T19:11:02.924Z,1401304262.924 [Default:Iridium](INFO): Completed Default:Iridium
2014-05-28T19:11:02.924Z,1401304262.924 [Default:Iridium] Stopped
2014-05-28T19:11:02.925Z,1401304262.925 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-28T19:11:02.925Z,1401304262.925 [Default:Iridium:A.SetSpeed] Stopped
2014-05-28T19:11:02.925Z,1401304262.925 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-28T19:11:03.875Z,1401304263.875 [DVL_micro](ERROR): No DVL communication! Re-initializing
2014-05-28T19:11:03.875Z,1401304263.875 [DVL_micro] Communications Fault, FailCount= 1
2014-05-28T19:11:03.875Z,1401304263.875 [DVL_micro](ERROR): Communications Fault
2014-05-28T19:11:03.973Z,1401304263.973 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-05-28T19:11:03.973Z,1401304263.973 [Default:CallIridium:B] Stopped
2014-05-28T19:11:03.974Z,1401304263.974 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-28T19:11:03.974Z,1401304263.974 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-05-28T19:11:03.974Z,1401304263.974 [Default:CallIridium] Stopped
2014-05-28T19:11:03.974Z,1401304263.974 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-28T19:11:03.992Z,1401304263.992 [CBIT](ERROR): Communications Fault in component: DVL_micro
2014-05-28T19:11:05.508Z,1401304265.508 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T19:11:06.090Z,1401304266.090 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T19:11:06.091Z,1401304266.091 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T19:11:06.091Z,1401304266.091 [DVL_micro](ERROR): Hardware Fault
2014-05-28T19:11:06.661Z,1401304266.661 [DVL_micro](INFO): Initializing
2014-05-28T19:11:06.786Z,1401304266.786 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T19:11:06.786Z,1401304266.786 [DVL_micro] No Fault, FailCount= 1
2014-05-28T19:11:11.106Z,1401304271.106 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T19:11:11.106Z,1401304271.106 [DVL_micro] Data Fault, FailCount= 2
2014-05-28T19:11:11.106Z,1401304271.106 [DVL_micro](ERROR): Data Fault
2014-05-28T19:11:11.250Z,1401304271.250 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T19:11:11.857Z,1401304271.857 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T19:11:12.384Z,1401304272.384 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T19:11:12.384Z,1401304272.384 [DVL_micro] Hardware Fault, FailCount= 2
2014-05-28T19:11:12.384Z,1401304272.384 [DVL_micro](ERROR): Hardware Fault
2014-05-28T19:11:12.884Z,1401304272.884 [DVL_micro](INFO): Initializing
2014-05-28T19:11:13.049Z,1401304273.049 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T19:11:13.049Z,1401304273.049 [DVL_micro] No Fault, FailCount= 2
2014-05-28T19:14:17.415Z,1401304457.415 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-28T19:14:17.415Z,1401304457.415 [DVL_micro] Data Fault, FailCount= 1
2014-05-28T19:14:17.415Z,1401304457.415 [DVL_micro](ERROR): Data Fault
2014-05-28T19:14:17.552Z,1401304457.552 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-28T19:14:17.982Z,1401304457.982 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T19:14:18.508Z,1401304458.508 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-28T19:14:18.509Z,1401304458.509 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-28T19:14:18.509Z,1401304458.509 [DVL_micro](ERROR): Hardware Fault
2014-05-28T19:14:19.002Z,1401304459.002 [DVL_micro](INFO): Initializing
2014-05-28T19:14:19.114Z,1401304459.114 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-28T19:14:19.114Z,1401304459.114 [DVL_micro] No Fault, FailCount= 1
2014-05-28T19:15:54.992Z,1401304554.992 [Default:CallIridium] Running Loop=1
2014-05-28T19:15:54.992Z,1401304554.992 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-05-28T19:15:54.996Z,1401304554.996 [Default:CallIridium:A] Running Loop=1
2014-05-28T19:15:54.997Z,1401304554.997 [Default:CallIridium:A] Stopped
2014-05-28T19:15:54.997Z,1401304554.997 [Default:CallIridium:B] Running Loop=1
2014-05-28T19:15:54.997Z,1401304554.997 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-05-28T19:15:55.640Z,1401304555.640 [Default:Iridium] Running Loop=1
2014-05-28T19:15:55.640Z,1401304555.640 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-28T19:15:55.640Z,1401304555.640 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-28T19:15:55.640Z,1401304555.640 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-28T19:15:55.640Z,1401304555.640 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-28T19:15:55.640Z,1401304555.640 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-28T19:15:55.650Z,1401304555.650 [Default:Iridium:B.GoToSurface] Stopped
2014-05-28T19:15:55.650Z,1401304555.650 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-28T19:15:55.650Z,1401304555.650 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-28T19:15:58.946Z,1401304558.946 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20140528T171454/Courier0092.lzma
2014-05-28T19:15:59.936Z,1401304559.936 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Courier0092.lzma.bak
2014-05-28T19:15:59.936Z,1401304559.936 [DataOverHttps](INFO): SBD MOMSN=980715
2014-05-28T19:16:03.124Z,1401304563.124 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:72 Calculated:84
2014-05-28T19:16:03.124Z,1401304563.124 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -387 -546 -394 -419 2 2 3 2 9.3 -16.8 2 -124.2 115.7 -470.8 2 9 -169 -470 2 -124 115 -470 2 -0.43 0 223.9 -3.0 20.0 0.005 35.0 1489 72
2014-05-28T19:16:08.775Z,1401304568.775 [DataOverHttps](IMPORTANT): SBD MTMSN=20140528T191607
2014-05-28T19:16:11.951Z,1401304571.951 [DataOverHttps](INFO): Sending 271 bytes from file Logs/20140528T171454/Express0093.lzma
2014-05-28T19:16:12.002Z,1401304572.002 [DataOverHttps](INFO): Received command:restart app
2014-05-28T19:16:12.035Z,1401304572.035 [CommandLine](IMPORTANT): got command restart application
2014-05-28T19:16:13.047Z,1401304573.047 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-28T19:16:13.048Z,1401304573.048 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-05-28T19:16:13.216Z,1401304573.216 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2014-05-28T19:16:13.217Z,1401304573.217 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-05-28T19:16:13.217Z,1401304573.217 [CommandLine](INFO): Join timeout helper Thread ID is 1086
2014-05-28T19:16:13.237Z,1401304573.237 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2014-05-28T19:16:13.237Z,1401304573.237 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-05-28T19:16:13.237Z,1401304573.237 [NavChartDb](INFO): Join timeout helper Thread ID is 1087
2014-05-28T19:16:13.369Z,1401304573.369 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-28T19:16:13.369Z,1401304573.369 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-05-28T19:16:13.385Z,1401304573.385 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2014-05-28T19:16:13.385Z,1401304573.385 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-05-28T19:16:13.385Z,1401304573.385 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1088
2014-05-28T19:16:13.526Z,1401304573.526 [DataOverHttps](INFO): Moved sent file to Logs/20140528T171454/Express0093.lzma.bak
2014-05-28T19:16:13.526Z,1401304573.526 [DataOverHttps](INFO): SBD MOMSN=980718
2014-05-28T19:16:13.545Z,1401304573.545 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-28T19:16:13.546Z,1401304573.546 [WetLabsBB2FL](INFO): Powering down
2014-05-28T19:16:13.546Z,1401304573.546 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-05-28T19:16:13.557Z,1401304573.557 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2014-05-28T19:16:13.557Z,1401304573.557 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-05-28T19:16:13.558Z,1401304573.558 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 1089
2014-05-28T19:16:13.958Z,1401304573.958 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-28T19:16:13.958Z,1401304573.958 [CTD_NeilBrown](INFO): Powering down
2014-05-28T19:16:13.959Z,1401304573.959 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-05-28T19:16:13.966Z,1401304573.966 [ComponentRegistry](INFO): Shutting down Radio_Freewave ThreadHandler
2014-05-28T19:16:13.966Z,1401304573.966 [Radio_Freewave ThreadHandler](INFO): Thread cancelled.
2014-05-28T19:16:13.966Z,1401304573.966 [Radio_Freewave](INFO): Join timeout helper Thread ID is 1090
2014-05-28T19:16:14.006Z,1401304574.006 [Radio_Freewave ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-28T19:16:14.359Z,1401304574.359 [Radio_Freewave](INFO): Powering down
2014-05-28T19:16:14.764Z,1401304574.764 [Radio_Freewave ThreadHandler](INFO): Thread cancelled.
2014-05-28T19:16:14.784Z,1401304574.784 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2014-05-28T19:16:14.784Z,1401304574.784 [logger ThreadHandler](INFO): Thread cancelled.
2014-05-28T19:16:14.785Z,1401304574.785 [logger](INFO): Join timeout helper Thread ID is 1093
2014-05-28T19:16:14.827Z,1401304574.827 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-28T19:16:14.828Z,1401304574.828 [logger ThreadHandler](INFO): Thread cancelled.
2014-05-28T19:16:14.844Z,1401304574.844 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2014-05-28T19:16:14.844Z,1401304574.844 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-05-28T19:16:14.844Z,1401304574.844 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2014-05-28T19:16:14.844Z,1401304574.844 [controlThread ThreadHandler](INFO): Thread cancelled.
2014-05-28T19:16:14.845Z,1401304574.845 [controlThread](INFO): Join timeout helper Thread ID is 1094
2014-05-28T19:16:15.172Z,1401304575.172 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-28T19:16:15.172Z,1401304575.172 [controlThread](DEBUG): Uninitializing ControlThread
2014-05-28T19:16:15.173Z,1401304575.173 [AHRS_sp3003D](INFO): Powering down
2014-05-28T19:16:15.332Z,1401304575.332 [DVL_micro](INFO): uninitialize:Powering down
2014-05-28T19:16:15.333Z,1401304575.333 [NAL9602](INFO): Powering down
2014-05-28T19:16:15.336Z,1401304575.336 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2014-05-28T19:16:15.339Z,1401304575.339 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2014-05-28T19:16:15.340Z,1401304575.340 [Default] Stopped
2014-05-28T19:16:15.340Z,1401304575.340 [Default](INFO): Aggregate::uninitialize Default
2014-05-28T19:16:15.340Z,1401304575.340 [Default:GPS] Stopped
2014-05-28T19:16:15.340Z,1401304575.340 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-05-28T19:16:15.340Z,1401304575.340 [Default:GPS:A.SetSpeed] Stopped
2014-05-28T19:16:15.340Z,1401304575.340 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-05-28T19:16:15.340Z,1401304575.340 [Default:GPS:Read_GPS] Stopped
2014-05-28T19:16:15.340Z,1401304575.340 [Default:Iridium] Stopped
2014-05-28T19:16:15.341Z,1401304575.341 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-28T19:16:15.341Z,1401304575.341 [Default:Iridium:A.SetSpeed] Stopped
2014-05-28T19:16:15.341Z,1401304575.341 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-28T19:16:15.341Z,1401304575.341 [Default:Iridium:Read_Iridium] Stopped
2014-05-28T19:16:15.341Z,1401304575.341 [Default:CallIridium] Stopped
2014-05-28T19:16:15.341Z,1401304575.341 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-28T19:16:15.341Z,1401304575.341 [Default:CallIridium:B] Stopped
2014-05-28T19:16:15.341Z,1401304575.341 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-28T19:16:15.341Z,1401304575.341 [Default:WaitAtTheSurface] Stopped
2014-05-28T19:16:15.341Z,1401304575.341 [Default:WaitAtTheSurface](INFO): Aggregate::uninitialize Default:WaitAtTheSurface
2014-05-28T19:16:15.341Z,1401304575.341 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Stopped
2014-05-28T19:16:15.341Z,1401304575.341 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Uninitialize.
2014-05-28T19:16:15.342Z,1401304575.342 [Default:WaitAtTheSurface:B.GoToSurface] Stopped
2014-05-28T19:16:15.342Z,1401304575.342 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-28T19:16:15.347Z,1401304575.347 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2014-05-28T19:16:15.347Z,1401304575.347 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2014-05-28T19:16:15.352Z,1401304575.352 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2014-05-28T19:16:15.352Z,1401304575.352 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2014-05-28T19:16:15.352Z,1401304575.352 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2014-05-28T19:16:15.353Z,1401304575.353 [BuoyancyServo](INFO): Powering down
2014-05-28T19:16:15.368Z,1401304575.368 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2014-05-28T19:16:15.368Z,1401304575.368 [ElevatorServo](INFO): Powering down
2014-05-28T19:16:15.369Z,1401304575.369 [MassServo](DEBUG): Uninitialize Mass Servo.
2014-05-28T19:16:15.369Z,1401304575.369 [MassServo](INFO): Powering down
2014-05-28T19:16:15.370Z,1401304575.370 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2014-05-28T19:16:15.370Z,1401304575.370 [RudderServo](INFO): Powering down
2014-05-28T19:16:15.371Z,1401304575.371 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2014-05-28T19:16:15.371Z,1401304575.371 [ThrusterServo](INFO): Powering down
2014-05-28T19:16:15.372Z,1401304575.372 [SBIT](DEBUG): Uninitialize SBIT Component.
2014-05-28T19:16:15.373Z,1401304575.373 [IBIT](DEBUG): Uninitialize IBIT Component.
2014-05-28T19:16:15.373Z,1401304575.373 [CBIT](DEBUG): Uninitialize CBIT Component.
2014-05-28T19:16:15.405Z,1401304575.405 [controlThread ThreadHandler](INFO): Thread cancelled.
2014-05-28T19:16:15.426Z,1401304575.426 [Radio_Freewave ThreadHandler](INFO): Thread cancelled.
2014-05-28T19:16:15.619Z,1401304575.619 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-05-28T19:16:15.622Z,1401304575.622 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-05-28T19:16:15.737Z,1401304575.737 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-05-28T19:16:15.822Z,1401304575.822 [logger ThreadHandler](INFO): Thread cancelled.