2014-05-21T01:01:43.734Z,1400634103.734 [Supervisor](DEBUG): Initializing supervisor.
2014-05-21T01:01:43.740Z,1400634103.740 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0
2014-05-21T01:01:43.741Z,1400634103.741 [SyncHandler](INFO): Protected caller Thread ID is 781
2014-05-21T01:01:43.741Z,1400634103.741 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2014-05-21T01:01:43.766Z,1400634103.766 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0
2014-05-21T01:01:43.767Z,1400634103.767 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 782
2014-05-21T01:01:43.770Z,1400634103.770 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2014-05-21T01:01:43.781Z,1400634103.781 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2014-05-21T01:01:43.784Z,1400634103.784 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0
2014-05-21T01:01:43.784Z,1400634103.784 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 783
2014-05-21T01:01:43.785Z,1400634103.785 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2014-05-21T01:01:43.788Z,1400634103.788 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0
2014-05-21T01:01:43.788Z,1400634103.788 [logger ThreadHandler](INFO): Protected caller Thread ID is 784
2014-05-21T01:01:43.790Z,1400634103.790 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2014-05-21T01:01:43.791Z,1400634103.791 [Supervisor](INFO): Looking for Config files in directory: Config/
2014-05-21T01:01:43.795Z,1400634103.795 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2014-05-21T01:01:44.198Z,1400634104.198 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2014-05-21T01:01:44.199Z,1400634104.199 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2014-05-21T01:01:44.523Z,1400634104.523 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2014-05-21T01:01:44.523Z,1400634104.523 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2014-05-21T01:01:44.620Z,1400634104.620 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2014-05-21T01:01:44.623Z,1400634104.623 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2014-05-21T01:01:44.823Z,1400634104.823 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2014-05-21T01:01:44.824Z,1400634104.824 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2014-05-21T01:01:45.007Z,1400634105.007 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2014-05-21T01:01:45.009Z,1400634105.009 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2014-05-21T01:01:45.360Z,1400634105.360 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2014-05-21T01:01:45.360Z,1400634105.360 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2014-05-21T01:01:45.564Z,1400634105.564 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2014-05-21T01:01:45.566Z,1400634105.566 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2014-05-21T01:01:45.953Z,1400634105.953 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2014-05-21T01:01:45.955Z,1400634105.955 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2014-05-21T01:01:46.081Z,1400634106.081 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2014-05-21T01:01:46.081Z,1400634106.081 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2014-05-21T01:01:46.646Z,1400634106.646 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2014-05-21T01:01:46.647Z,1400634106.647 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2014-05-21T01:01:48.815Z,1400634108.815 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2014-05-21T01:01:48.816Z,1400634108.816 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2014-05-21T01:01:48.916Z,1400634108.916 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2014-05-21T01:01:49.041Z,1400634109.041 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2014-05-21T01:01:49.042Z,1400634109.042 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2014-05-21T01:01:49.157Z,1400634109.157 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2014-05-21T01:01:49.159Z,1400634109.159 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2014-05-21T01:01:49.314Z,1400634109.314 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2014-05-21T01:01:49.316Z,1400634109.316 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2014-05-21T01:01:49.320Z,1400634109.320 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2014-05-21T01:01:49.448Z,1400634109.448 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2014-05-21T01:01:49.598Z,1400634109.598 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2014-05-21T01:01:49.707Z,1400634109.707 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2014-05-21T01:01:49.811Z,1400634109.811 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2014-05-21T01:01:49.975Z,1400634109.975 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2014-05-21T01:01:50.113Z,1400634110.113 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2014-05-21T01:01:50.210Z,1400634110.210 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2014-05-21T01:01:50.332Z,1400634110.332 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2014-05-21T01:01:50.444Z,1400634110.444 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2014-05-21T01:01:50.553Z,1400634110.553 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2014-05-21T01:01:50.654Z,1400634110.654 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Estimation.cfg
2014-05-21T01:01:50.764Z,1400634110.764 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2014-05-21T01:01:50.772Z,1400634110.772 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2014-05-21T01:01:51.406Z,1400634111.406 [AHRS_sp3003D] Loaded
2014-05-21T01:01:51.407Z,1400634111.407 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2014-05-21T01:01:51.736Z,1400634111.736 [Batt_Ocean_Server] Loaded
2014-05-21T01:01:51.736Z,1400634111.736 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2014-05-21T01:01:51.922Z,1400634111.922 [DataOverHttps] Loaded
2014-05-21T01:01:51.923Z,1400634111.923 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2014-05-21T01:01:51.936Z,1400634111.936 [Depth_Keller] Loaded
2014-05-21T01:01:51.937Z,1400634111.937 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2014-05-21T01:01:52.096Z,1400634112.096 [DVL_micro] Loaded
2014-05-21T01:01:52.096Z,1400634112.096 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2014-05-21T01:01:52.210Z,1400634112.210 [NAL9602] Loaded
2014-05-21T01:01:52.210Z,1400634112.210 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2014-05-21T01:01:52.274Z,1400634112.274 [Onboard] Loaded
2014-05-21T01:01:52.275Z,1400634112.275 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2014-05-21T01:01:52.282Z,1400634112.282 [Radio_Freewave] Loaded
2014-05-21T01:01:52.282Z,1400634112.282 [ComponentRegistry](DEBUG): Component "Radio_Freewave" handled in its own thread.
2014-05-21T01:01:52.285Z,1400634112.285 [Radio_Freewave ThreadHandler](DEBUG): Created PCaller Thread at 4060F4E0
2014-05-21T01:01:52.285Z,1400634112.285 [Radio_Freewave ThreadHandler](INFO): Protected caller Thread ID is 866
2014-05-21T01:01:52.292Z,1400634112.292 [SCPI] Loaded
2014-05-21T01:01:52.292Z,1400634112.292 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread.
2014-05-21T01:01:52.293Z,1400634112.293 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2014-05-21T01:01:52.294Z,1400634112.294 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2014-05-21T01:01:55.897Z,1400634115.897 [InternalSim] Loaded
2014-05-21T01:01:55.897Z,1400634115.897 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2014-05-21T01:01:55.898Z,1400634115.898 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2014-05-21T01:01:55.898Z,1400634115.898 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2014-05-21T01:01:56.219Z,1400634116.219 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2014-05-21T01:01:56.220Z,1400634116.220 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2014-05-21T01:01:56.229Z,1400634116.229 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2014-05-21T01:01:56.229Z,1400634116.229 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2014-05-21T01:01:56.335Z,1400634116.335 [DeadReckonUsingMultipleVelocitySources] Loaded
2014-05-21T01:01:56.335Z,1400634116.335 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2014-05-21T01:01:56.390Z,1400634116.390 [DeadReckonWithRespectToWater] Loaded
2014-05-21T01:01:56.390Z,1400634116.390 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToWater" handled in the control thread.
2014-05-21T01:01:56.441Z,1400634116.441 [DeadReckonWithRespectToSeafloor] Loaded
2014-05-21T01:01:56.441Z,1400634116.441 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToSeafloor" handled in the control thread.
2014-05-21T01:01:56.496Z,1400634116.496 [DeadReckonUsingDVLWaterTrack] Loaded
2014-05-21T01:01:56.496Z,1400634116.496 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingDVLWaterTrack" handled in the control thread.
2014-05-21T01:01:56.549Z,1400634116.549 [DeadReckonUsingCompactModelForecast] Loaded
2014-05-21T01:01:56.549Z,1400634116.549 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingCompactModelForecast" handled in the control thread.
2014-05-21T01:01:56.565Z,1400634116.565 [NavChart] Loaded
2014-05-21T01:01:56.565Z,1400634116.565 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2014-05-21T01:01:56.570Z,1400634116.570 [UniversalFixResidualReporter] Loaded
2014-05-21T01:01:56.570Z,1400634116.570 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2014-05-21T01:01:56.570Z,1400634116.570 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2014-05-21T01:01:56.571Z,1400634116.571 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2014-05-21T01:01:56.647Z,1400634116.647 [VerticalControl](DEBUG): Construct VerticalControl.
2014-05-21T01:01:56.774Z,1400634116.774 [VerticalControl] Loaded
2014-05-21T01:01:56.774Z,1400634116.774 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2014-05-21T01:01:56.775Z,1400634116.775 [HorizontalControl](DEBUG): Construct HorizontalControl.
2014-05-21T01:01:56.851Z,1400634116.851 [HorizontalControl] Loaded
2014-05-21T01:01:56.851Z,1400634116.851 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2014-05-21T01:01:56.852Z,1400634116.852 [SpeedControl](DEBUG): Construct SpeedControl.
2014-05-21T01:01:56.853Z,1400634116.853 [SpeedControl] Loaded
2014-05-21T01:01:56.854Z,1400634116.854 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2014-05-21T01:01:56.854Z,1400634116.854 [LoopControl](DEBUG): Construct LoopControl.
2014-05-21T01:01:56.855Z,1400634116.855 [LoopControl] Loaded
2014-05-21T01:01:56.855Z,1400634116.855 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2014-05-21T01:01:56.856Z,1400634116.856 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2014-05-21T01:01:56.856Z,1400634116.856 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2014-05-21T01:01:56.884Z,1400634116.884 [DepthRateCalculator] Loaded
2014-05-21T01:01:56.885Z,1400634116.885 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2014-05-21T01:01:56.896Z,1400634116.896 [PitchRateCalculator] Loaded
2014-05-21T01:01:56.896Z,1400634116.896 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2014-05-21T01:01:56.903Z,1400634116.903 [SpeedCalculator] Loaded
2014-05-21T01:01:56.904Z,1400634116.904 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2014-05-21T01:01:56.920Z,1400634116.920 [TempGradientCalculator] Loaded
2014-05-21T01:01:56.921Z,1400634116.921 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2014-05-21T01:01:56.926Z,1400634116.926 [YawRateCalculator] Loaded
2014-05-21T01:01:56.926Z,1400634116.926 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2014-05-21T01:01:56.927Z,1400634116.927 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2014-05-21T01:01:56.928Z,1400634116.928 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2014-05-21T01:01:57.070Z,1400634117.070 [CTD_NeilBrown] Loaded
2014-05-21T01:01:57.070Z,1400634117.070 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2014-05-21T01:01:57.072Z,1400634117.072 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4075E4E0
2014-05-21T01:01:57.073Z,1400634117.073 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 867
2014-05-21T01:01:57.086Z,1400634117.086 [ISUS] Loaded
2014-05-21T01:01:57.086Z,1400634117.086 [ComponentRegistry](DEBUG): SyncComponent "ISUS" handled in the control thread.
2014-05-21T01:01:57.105Z,1400634117.105 [PAR_Licor] Loaded
2014-05-21T01:01:57.105Z,1400634117.105 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2014-05-21T01:01:57.144Z,1400634117.144 [WetLabsBB2FL] Loaded
2014-05-21T01:01:57.145Z,1400634117.145 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2014-05-21T01:01:57.149Z,1400634117.149 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4078E4E0
2014-05-21T01:01:57.149Z,1400634117.149 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 868
2014-05-21T01:01:57.149Z,1400634117.149 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2014-05-21T01:01:57.150Z,1400634117.150 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2014-05-21T01:01:57.284Z,1400634117.284 [SBIT](DEBUG): Construct Startup Built In Test.
2014-05-21T01:01:57.296Z,1400634117.296 [SBIT] Loaded
2014-05-21T01:01:57.296Z,1400634117.296 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2014-05-21T01:01:57.297Z,1400634117.297 [IBIT](DEBUG): Construct Initiated Built In Test.
2014-05-21T01:01:57.309Z,1400634117.309 [IBIT] Loaded
2014-05-21T01:01:57.310Z,1400634117.310 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2014-05-21T01:01:57.312Z,1400634117.312 [CBIT](DEBUG): Construct CBIT Built In Test.
2014-05-21T01:01:57.394Z,1400634117.394 [CBIT] Loaded
2014-05-21T01:01:57.395Z,1400634117.395 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2014-05-21T01:01:57.395Z,1400634117.395 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2014-05-21T01:01:57.396Z,1400634117.396 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2014-05-21T01:02:02.982Z,1400634122.982 [HFRadarModelCalc] Loaded
2014-05-21T01:02:02.982Z,1400634122.982 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2014-05-21T01:02:07.154Z,1400634127.154 [HFRadarCompactModelForecaster] Loaded
2014-05-21T01:02:07.154Z,1400634127.154 [ComponentRegistry](DEBUG): SyncComponent "HFRadarCompactModelForecaster" handled in the control thread.
2014-05-21T01:02:08.244Z,1400634128.244 [HFRCMSpaceInterpolator] Loaded
2014-05-21T01:02:08.244Z,1400634128.244 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSpaceInterpolator" handled in the control thread.
2014-05-21T01:02:08.246Z,1400634128.246 [HFRCMTimeInterpolator] Loaded
2014-05-21T01:02:08.247Z,1400634128.247 [ComponentRegistry](DEBUG): SyncComponent "HFRCMTimeInterpolator" handled in the control thread.
2014-05-21T01:02:08.260Z,1400634128.260 [HFRCMSurfaceCurrentAtVehicleLocation] Loaded
2014-05-21T01:02:08.260Z,1400634128.260 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSurfaceCurrentAtVehicleLocation" handled in the control thread.
2014-05-21T01:02:08.292Z,1400634128.292 [HFRCMVirtualSurfaceDrifter] Loaded
2014-05-21T01:02:08.293Z,1400634128.293 [ComponentRegistry](DEBUG): SyncComponent "HFRCMVirtualSurfaceDrifter" handled in the control thread.
2014-05-21T01:02:08.293Z,1400634128.293 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2014-05-21T01:02:08.294Z,1400634128.294 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2014-05-21T01:02:08.429Z,1400634128.429 [BuoyancyServo] Loaded
2014-05-21T01:02:08.429Z,1400634128.429 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2014-05-21T01:02:08.441Z,1400634128.441 [ElevatorServo] Loaded
2014-05-21T01:02:08.441Z,1400634128.441 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2014-05-21T01:02:08.457Z,1400634128.457 [MassServo] Loaded
2014-05-21T01:02:08.457Z,1400634128.457 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2014-05-21T01:02:08.469Z,1400634128.469 [RudderServo] Loaded
2014-05-21T01:02:08.470Z,1400634128.470 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2014-05-21T01:02:08.485Z,1400634128.485 [ThrusterServo] Loaded
2014-05-21T01:02:08.486Z,1400634128.486 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2014-05-21T01:02:08.486Z,1400634128.486 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2014-05-21T01:02:08.487Z,1400634128.487 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2014-05-21T01:02:08.531Z,1400634128.531 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2014-05-21T01:02:08.533Z,1400634128.533 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2014-05-21T01:02:08.534Z,1400634128.534 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2014-05-21T01:02:08.540Z,1400634128.540 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2014-05-21T01:02:08.542Z,1400634128.542 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A4D4E0
2014-05-21T01:02:08.543Z,1400634128.543 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 870
2014-05-21T01:02:08.547Z,1400634128.547 [Supervisor](INFO): Main Thread ID is 769
2014-05-21T01:02:08.548Z,1400634128.548 [Supervisor](DEBUG): Running supervisor.
2014-05-21T01:02:08.548Z,1400634128.548 [CommandLine ThreadHandler](INFO): Handler Thread ID is 871
2014-05-21T01:02:08.555Z,1400634128.555 [controlThread ThreadHandler](INFO): Handler Thread ID is 872
2014-05-21T01:02:08.555Z,1400634128.555 [controlThread](DEBUG): Initializing ControlThread
2014-05-21T01:02:08.559Z,1400634128.559 [logger ThreadHandler](INFO): Handler Thread ID is 873
2014-05-21T01:02:08.595Z,1400634128.595 [Radio_Freewave ThreadHandler](INFO): Handler Thread ID is 874
2014-05-21T01:02:08.607Z,1400634128.607 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 875
2014-05-21T01:02:08.608Z,1400634128.608 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2014-05-21T01:02:08.611Z,1400634128.611 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2014-05-21T01:02:08.620Z,1400634128.620 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 877
2014-05-21T01:02:08.622Z,1400634128.622 [WetLabsBB2FL](INFO): Powering down
2014-05-21T01:02:08.651Z,1400634128.651 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 878
2014-05-21T01:02:08.674Z,1400634128.674 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2014-05-21T01:02:08.675Z,1400634128.675 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2014-05-21T01:02:08.675Z,1400634128.675 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2014-05-21T01:02:08.675Z,1400634128.675 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2014-05-21T01:02:08.676Z,1400634128.676 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2014-05-21T01:02:08.676Z,1400634128.676 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2014-05-21T01:02:08.676Z,1400634128.676 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2014-05-21T01:02:08.676Z,1400634128.676 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2014-05-21T01:02:08.677Z,1400634128.677 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2014-05-21T01:02:10.090Z,1400634130.090 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2014-05-21T01:02:10.119Z,1400634130.119 [InternalSim](DEBUG): InternalSim initializing...
2014-05-21T01:02:10.469Z,1400634130.469 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2014-05-21T01:02:10.470Z,1400634130.470 [DeadReckonWithRespectToWater](DEBUG): Initializing DeadReckonWithRespectToWater component.
2014-05-21T01:02:10.470Z,1400634130.470 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component.
2014-05-21T01:02:10.471Z,1400634130.471 [DeadReckonUsingDVLWaterTrack](DEBUG): Initializing DeadReckonUsingDVLWaterTrack component.
2014-05-21T01:02:10.471Z,1400634130.471 [DeadReckonUsingCompactModelForecast](DEBUG): Initializing DeadReckonUsingCompactModelForecast component.
2014-05-21T01:02:10.471Z,1400634130.471 [NavChart](DEBUG): Initialize NavChart Navigation.
2014-05-21T01:02:10.472Z,1400634130.472 [UniversalFixResidualReporter](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2014-05-21T01:02:10.472Z,1400634130.472 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2014-05-21T01:02:10.485Z,1400634130.485 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2014-05-21T01:02:10.486Z,1400634130.486 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2014-05-21T01:02:10.487Z,1400634130.487 [LoopControl](DEBUG): Initialize LoopControlComponent.
2014-05-21T01:02:10.487Z,1400634130.487 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2014-05-21T01:02:10.487Z,1400634130.487 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2014-05-21T01:02:10.488Z,1400634130.488 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2014-05-21T01:02:10.488Z,1400634130.488 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2014-05-21T01:02:10.489Z,1400634130.489 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2014-05-21T01:02:10.498Z,1400634130.498 [SBIT](INFO): Initialize SBIT Component.
2014-05-21T01:02:10.499Z,1400634130.499 [SBIT](IMPORTANT): Tethys CM Info:
$Rev:11321
2014-05-21T01:02:10.499Z,1400634130.499 [SBIT](IMPORTANT): Kernel Release:2.6.27.8
2014-05-21T01:02:10.499Z,1400634130.499 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2014-05-21T01:02:10.500Z,1400634130.500 [IBIT](INFO): Initialize IBIT Component.
2014-05-21T01:02:10.501Z,1400634130.501 [CBIT](DEBUG): Initialize CBIT Component.
2014-05-21T01:02:10.509Z,1400634130.509 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2014-05-21T01:02:10.545Z,1400634130.545 [HFRadarCompactModelForecaster](DEBUG): Found new ECs!
2014-05-21T01:02:10.886Z,1400634130.886 [Radio_Freewave](INFO): Powering up
2014-05-21T01:02:11.696Z,1400634131.696 [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-21T01:02:20.289Z,1400634140.289 [HFRadarCompactModelForecaster](IMPORTANT): Forecast time 201405202200: published 50 modes in rows, 61 hours in columns, 3050 elements.
2014-05-21T01:02:20.293Z,1400634140.293 [HFRCMSpaceInterpolator](DEBUG): Initializing HFRCMSpaceInterpolator component.
2014-05-21T01:02:20.294Z,1400634140.294 [HFRCMTimeInterpolator](DEBUG): Initializing HFRCMTimeInterpolator component.
2014-05-21T01:02:20.295Z,1400634140.295 [HFRCMSurfaceCurrentAtVehicleLocation](DEBUG): Initializing HFRCMSurfaceCurrentAtVehicleLocation component.
2014-05-21T01:02:20.295Z,1400634140.295 [HFRCMVirtualSurfaceDrifter](DEBUG): Initializing HFRCMVirtualSurfaceDrifter component.
2014-05-21T01:02:20.314Z,1400634140.314 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2014-05-21T01:02:20.338Z,1400634140.338 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2014-05-21T01:02:20.357Z,1400634140.357 [MissionManager](DEBUG):
2014-05-21T01:02:20.358Z,1400634140.358 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2014-05-21T01:02:20.441Z,1400634140.441 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2014-05-21T01:02:20.454Z,1400634140.454 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2014-05-21T01:02:20.457Z,1400634140.457 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-05-21T01:02:20.478Z,1400634140.478 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2014-05-21T01:02:20.497Z,1400634140.497 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-05-21T01:02:20.516Z,1400634140.516 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2014-05-21T01:02:20.542Z,1400634140.542 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Construct.
2014-05-21T01:02:20.562Z,1400634140.562 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-05-21T01:02:20.585Z,1400634140.585 [MissionManager](DEBUG):
400
400
Burn 300
Dropped drop weight due to communications timeout
5.0
1.0
5
2014-05-21T01:02:20.603Z,1400634140.603 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,DataOverHttps,Depth_Keller,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-21T01:02:20.773Z,1400634140.773 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2014-05-21T01:02:21.523Z,1400634141.523 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar
2014-05-21T01:02:21.558Z,1400634141.558 [DVL_micro](INFO): Initializing
2014-05-21T01:02:21.583Z,1400634141.583 [NAL9602](INFO): Powering up NAL9602
2014-05-21T01:02:22.120Z,1400634142.120 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2014-05-21T01:02:22.128Z,1400634142.128 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2014-05-21T01:02:22.138Z,1400634142.138 [ElevatorServo](DEBUG): Initializing EZServoServo.
2014-05-21T01:02:22.144Z,1400634142.144 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2014-05-21T01:02:22.165Z,1400634142.165 [MassServo](DEBUG): Initializing EZServoServo.
2014-05-21T01:02:22.172Z,1400634142.172 [MassServo](DEBUG): Initializing MassServo.
2014-05-21T01:02:22.193Z,1400634142.193 [RudderServo](DEBUG): Initializing EZServoServo.
2014-05-21T01:02:22.205Z,1400634142.205 [RudderServo](DEBUG): Initializing RudderServo.
2014-05-21T01:02:22.233Z,1400634142.233 [ThrusterServo](DEBUG): Initializing EZServoServo.
2014-05-21T01:02:22.256Z,1400634142.256 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2014-05-21T01:02:26.289Z,1400634146.289 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003807
2014-05-21T01:02:26.567Z,1400634146.567 [SBIT](IMPORTANT): Beginning Startup BIT
2014-05-21T01:02:26.570Z,1400634146.570 [CBIT](IMPORTANT): Beginning GF scan
2014-05-21T01:02:32.165Z,1400634152.165 [NAL9602](INFO): NAL9602 initialized
2014-05-21T01:02:53.605Z,1400634173.605 [CBIT](IMPORTANT): No ground fault detected
2014-05-21T01:02:59.965Z,1400634179.965 [CommandLine](IMPORTANT): got command configSet list
2014-05-21T01:02:59.966Z,1400634179.966 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2014-05-21T01:02:59.967Z,1400634179.967 [CommandLine](IMPORTANT): DataOverHttps.loadAtStartup=1 bool;
2014-05-21T01:02:59.967Z,1400634179.967 [CommandLine](IMPORTANT): DropWeight.loadAtStartup=0 bool;
2014-05-21T01:03:20.531Z,1400634200.531 [SBIT](IMPORTANT): SBIT PASSED
2014-05-21T01:03:20.931Z,1400634200.931 [MissionManager](IMPORTANT): Started mission Startup
2014-05-21T01:03:20.931Z,1400634200.931 [Startup] Running Loop=1
2014-05-21T01:03:20.931Z,1400634200.931 [Startup](INFO): Aggregate::initialize Startup
2014-05-21T01:03:20.931Z,1400634200.931 [Startup:A.GoToSurface] Running Loop=1
2014-05-21T01:03:20.931Z,1400634200.931 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-21T01:03:20.937Z,1400634200.937 [Startup:StartupSatComms] Running Loop=1
2014-05-21T01:03:20.937Z,1400634200.937 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2014-05-21T01:03:20.938Z,1400634200.938 [Startup:StartupSatComms:A] Running Loop=1
2014-05-21T01:03:21.382Z,1400634201.382 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2014-05-21T01:03:31.569Z,1400634211.569 [CommandLine](IMPORTANT): got command report mod HFRadarModelCalc.surface_eastward_sea_water_velocity
2014-05-21T01:03:31.571Z,1400634211.571 [CommandLine](IMPORTANT): got command report mod HFRadarModelCalc.surface_northward_sea_water_velocity
2014-05-21T01:03:31.764Z,1400634211.764 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity no_value
2014-05-21T01:03:31.764Z,1400634211.764 [Reporter](INFO): HFRadarModelCalc.surface_northward_sea_water_velocity no_value
2014-05-21T01:03:40.701Z,1400634220.701 [CommandLine](IMPORTANT): got command report mod HFRCMSurfaceCurrentAtVehicleLocation.surface_eastward_sea_water_velocity
2014-05-21T01:03:40.702Z,1400634220.702 [CommandLine](IMPORTANT): got command report mod HFRCMSurfaceCurrentAtVehicleLocation.surface_northward_sea_water_velocity
2014-05-21T01:03:40.939Z,1400634220.939 [Reporter](INFO): HFRCMSurfaceCurrentAtVehicleLocation.surface_eastward_sea_water_velocity no_value
2014-05-21T01:03:40.940Z,1400634220.940 [Reporter](INFO): HFRCMSurfaceCurrentAtVehicleLocation.surface_northward_sea_water_velocity no_value
2014-05-21T01:04:21.176Z,1400634261.176 [Startup:StartupSatComms:A](INFO): Timed out from 2014-05-21T01:03:20.9Z
2014-05-21T01:04:21.176Z,1400634261.176 [Startup:StartupSatComms:A] Stopped
2014-05-21T01:04:21.176Z,1400634261.176 [Startup:StartupSatComms:B] Running Loop=1
2014-05-21T01:04:21.572Z,1400634261.572 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2014-05-21T01:04:23.935Z,1400634263.935 [DataOverHttps](INFO): Sending 290 bytes from file Logs/20140521T002034/Courier0000.lzma
2014-05-21T01:04:24.791Z,1400634264.791 [DataOverHttps](INFO): Moved sent file to Logs/20140521T002034/Courier0000.lzma.bak
2014-05-21T01:04:24.792Z,1400634264.792 [DataOverHttps](INFO): SBD MOMSN=964811
2014-05-21T01:04:29.984Z,1400634269.984 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20140521T002034/Courier0004.lzma
2014-05-21T01:04:30.795Z,1400634270.795 [DataOverHttps](INFO): Moved sent file to Logs/20140521T002034/Courier0004.lzma.bak
2014-05-21T01:04:30.795Z,1400634270.795 [DataOverHttps](INFO): SBD MOMSN=964816
2014-05-21T01:04:35.991Z,1400634275.991 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20140521T002034/Courier0008.lzma
2014-05-21T01:04:36.840Z,1400634276.840 [DataOverHttps](INFO): Moved sent file to Logs/20140521T002034/Courier0008.lzma.bak
2014-05-21T01:04:36.841Z,1400634276.841 [DataOverHttps](INFO): SBD MOMSN=964818
2014-05-21T01:04:42.038Z,1400634282.038 [DataOverHttps](INFO): Sending 287 bytes from file Logs/20140521T003052/Courier0000.lzma
2014-05-21T01:04:42.902Z,1400634282.902 [DataOverHttps](INFO): Moved sent file to Logs/20140521T003052/Courier0000.lzma.bak
2014-05-21T01:04:42.902Z,1400634282.902 [DataOverHttps](INFO): SBD MOMSN=964820
2014-05-21T01:04:48.031Z,1400634288.031 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20140521T003052/Courier0004.lzma
2014-05-21T01:04:48.969Z,1400634288.969 [DataOverHttps](INFO): Moved sent file to Logs/20140521T003052/Courier0004.lzma.bak
2014-05-21T01:04:48.969Z,1400634288.969 [DataOverHttps](INFO): SBD MOMSN=964825
2014-05-21T01:04:54.137Z,1400634294.137 [DataOverHttps](INFO): Sending 287 bytes from file Logs/20140521T003511/Courier0000.lzma
2014-05-21T01:04:54.989Z,1400634294.989 [DataOverHttps](INFO): Moved sent file to Logs/20140521T003511/Courier0000.lzma.bak
2014-05-21T01:04:54.989Z,1400634294.989 [DataOverHttps](INFO): SBD MOMSN=964827
2014-05-21T01:05:00.138Z,1400634300.138 [DataOverHttps](INFO): Sending 249 bytes from file Logs/20140521T003738/Courier0000.lzma
2014-05-21T01:05:00.985Z,1400634300.985 [DataOverHttps](INFO): Moved sent file to Logs/20140521T003738/Courier0000.lzma.bak
2014-05-21T01:05:00.986Z,1400634300.986 [DataOverHttps](INFO): SBD MOMSN=964832
2014-05-21T01:05:06.141Z,1400634306.141 [DataOverHttps](INFO): Sending 47 bytes from file Logs/20140521T003738/Courier0004.lzma
2014-05-21T01:05:06.995Z,1400634306.995 [DataOverHttps](INFO): Moved sent file to Logs/20140521T003738/Courier0004.lzma.bak
2014-05-21T01:05:06.995Z,1400634306.995 [DataOverHttps](INFO): SBD MOMSN=964836
2014-05-21T01:05:12.195Z,1400634312.195 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20140521T003738/Courier0008.lzma
2014-05-21T01:05:13.060Z,1400634313.060 [DataOverHttps](INFO): Moved sent file to Logs/20140521T003738/Courier0008.lzma.bak
2014-05-21T01:05:13.060Z,1400634313.060 [DataOverHttps](INFO): SBD MOMSN=964838
2014-05-21T01:05:18.217Z,1400634318.217 [DataOverHttps](INFO): Sending 193 bytes from file Logs/20140521T004727/Courier0000.lzma
2014-05-21T01:05:19.562Z,1400634319.562 [DataOverHttps](INFO): Moved sent file to Logs/20140521T004727/Courier0000.lzma.bak
2014-05-21T01:05:19.563Z,1400634319.563 [DataOverHttps](INFO): SBD MOMSN=964840
2014-05-21T01:05:21.387Z,1400634321.387 [Startup:StartupSatComms:B](INFO): Timed out from 2014-05-21T01:04:21.2Z
2014-05-21T01:05:21.387Z,1400634321.387 [Startup:StartupSatComms:B] Stopped
2014-05-21T01:05:21.387Z,1400634321.387 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2014-05-21T01:05:21.387Z,1400634321.387 [Startup:StartupSatComms] Stopped
2014-05-21T01:05:21.387Z,1400634321.387 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2014-05-21T01:05:21.388Z,1400634321.388 [Startup](INFO): Completed Startup
2014-05-21T01:05:21.388Z,1400634321.388 [Startup] Stopped
2014-05-21T01:05:21.388Z,1400634321.388 [Startup](INFO): Aggregate::uninitialize Startup
2014-05-21T01:05:21.388Z,1400634321.388 [Startup:A.GoToSurface] Stopped
2014-05-21T01:05:21.388Z,1400634321.388 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-21T01:05:21.861Z,1400634321.861 [MissionManager](IMPORTANT): Started mission Default
2014-05-21T01:05:21.861Z,1400634321.861 [Default] Running Loop=1
2014-05-21T01:05:21.861Z,1400634321.861 [Default](INFO): Aggregate::initialize Default
2014-05-21T01:05:21.861Z,1400634321.861 [Default:Iridium] Running Loop=1
2014-05-21T01:05:21.861Z,1400634321.861 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-21T01:05:21.861Z,1400634321.861 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-21T01:05:21.861Z,1400634321.861 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-21T01:05:21.862Z,1400634321.862 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-21T01:05:21.862Z,1400634321.862 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-21T01:05:21.866Z,1400634321.866 [Default:CallIridium] Running Loop=1
2014-05-21T01:05:21.867Z,1400634321.867 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-05-21T01:05:21.867Z,1400634321.867 [Default:CallIridium:A] Running Loop=1
2014-05-21T01:05:21.869Z,1400634321.869 [Default:CallIridium:A] Stopped
2014-05-21T01:05:21.869Z,1400634321.869 [Default:CallIridium:B] Running Loop=1
2014-05-21T01:05:21.869Z,1400634321.869 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-05-21T01:05:21.883Z,1400634321.883 [Default:Iridium:B.GoToSurface] Stopped
2014-05-21T01:05:21.883Z,1400634321.883 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-21T01:05:21.883Z,1400634321.883 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-21T01:05:21.883Z,1400634321.883 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-21T01:05:21.892Z,1400634321.892 [Default:GPS] Running Loop=1
2014-05-21T01:05:21.893Z,1400634321.893 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-05-21T01:05:21.893Z,1400634321.893 [Default:GPS:A.SetSpeed] Running Loop=1
2014-05-21T01:05:21.893Z,1400634321.893 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-05-21T01:05:21.893Z,1400634321.893 [Default:GPS:B.GoToSurface] Running Loop=1
2014-05-21T01:05:21.893Z,1400634321.893 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-21T01:05:21.919Z,1400634321.919 [Default:GPS:B.GoToSurface] Stopped
2014-05-21T01:05:21.919Z,1400634321.919 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-21T01:05:21.919Z,1400634321.919 [Default:GPS:Read_GPS] Running Loop=1
2014-05-21T01:05:21.919Z,1400634321.919 [Default:GPS:A.SetSpeed] Running Loop=1
2014-05-21T01:05:22.339Z,1400634322.339 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2014-05-21T01:05:22.342Z,1400634322.342 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2014-05-21T01:05:25.115Z,1400634325.115 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20140521T004727/Courier0004.lzma
2014-05-21T01:05:25.986Z,1400634325.986 [DataOverHttps](INFO): Moved sent file to Logs/20140521T004727/Courier0004.lzma.bak
2014-05-21T01:05:25.986Z,1400634325.986 [DataOverHttps](INFO): SBD MOMSN=964843
2014-05-21T01:05:27.664Z,1400634327.664 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-21T01:05:27.664Z,1400634327.664 [DVL_micro] Data Fault, FailCount= 1
2014-05-21T01:05:27.664Z,1400634327.664 [DVL_micro](ERROR): Data Fault
2014-05-21T01:05:27.697Z,1400634327.697 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-21T01:05:28.172Z,1400634328.172 [DVL_micro](INFO): uninitialize:Powering down
2014-05-21T01:05:28.632Z,1400634328.632 [DVL_micro](FAULT): LCB fault: Software Overcurrent.
2014-05-21T01:05:28.632Z,1400634328.632 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-21T01:05:28.632Z,1400634328.632 [DVL_micro](ERROR): Hardware Fault
2014-05-21T01:05:29.067Z,1400634329.067 [DVL_micro](INFO): Initializing
2014-05-21T01:05:29.145Z,1400634329.145 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-21T01:05:29.145Z,1400634329.145 [DVL_micro] No Fault, FailCount= 1
2014-05-21T01:05:31.254Z,1400634331.254 [DataOverHttps](INFO): Sending 195 bytes from file Logs/20140521T005110/Courier0000.lzma
2014-05-21T01:05:32.065Z,1400634332.065 [DataOverHttps](INFO): Moved sent file to Logs/20140521T005110/Courier0000.lzma.bak
2014-05-21T01:05:32.066Z,1400634332.066 [DataOverHttps](INFO): SBD MOMSN=964845
2014-05-21T01:05:37.217Z,1400634337.217 [DataOverHttps](INFO): Sending 47 bytes from file Logs/20140521T005110/Courier0004.lzma
2014-05-21T01:05:38.016Z,1400634338.016 [DataOverHttps](INFO): Moved sent file to Logs/20140521T005110/Courier0004.lzma.bak
2014-05-21T01:05:38.016Z,1400634338.016 [DataOverHttps](INFO): SBD MOMSN=964848
2014-05-21T01:05:43.269Z,1400634343.269 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20140521T005110/Courier0008.lzma
2014-05-21T01:05:44.077Z,1400634344.077 [DataOverHttps](INFO): Moved sent file to Logs/20140521T005110/Courier0008.lzma.bak
2014-05-21T01:05:44.077Z,1400634344.077 [DataOverHttps](INFO): SBD MOMSN=964850
2014-05-21T01:05:49.281Z,1400634349.281 [DataOverHttps](INFO): Sending 249 bytes from file Logs/20140521T005838/Courier0000.lzma
2014-05-21T01:05:50.098Z,1400634350.098 [DataOverHttps](INFO): Moved sent file to Logs/20140521T005838/Courier0000.lzma.bak
2014-05-21T01:05:50.098Z,1400634350.098 [DataOverHttps](INFO): SBD MOMSN=964852
2014-05-21T01:05:55.362Z,1400634355.362 [DataOverHttps](INFO): Sending 193 bytes from file Logs/20140521T010143/Courier0000.lzma
2014-05-21T01:05:56.291Z,1400634356.291 [DataOverHttps](INFO): Moved sent file to Logs/20140521T010143/Courier0000.lzma.bak
2014-05-21T01:05:56.291Z,1400634356.291 [DataOverHttps](INFO): SBD MOMSN=964856
2014-05-21T01:06:01.439Z,1400634361.439 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20140521T010143/Courier0004.lzma
2014-05-21T01:06:02.309Z,1400634362.309 [DataOverHttps](INFO): Moved sent file to Logs/20140521T010143/Courier0004.lzma.bak
2014-05-21T01:06:02.309Z,1400634362.309 [DataOverHttps](INFO): SBD MOMSN=964859
2014-05-21T01:06:07.576Z,1400634367.576 [DataOverHttps](INFO): Sending 718 bytes from file Logs/20140521T002034/Express0001.lzma
2014-05-21T01:06:08.450Z,1400634368.450 [DataOverHttps](INFO): Moved sent file to Logs/20140521T002034/Express0001.lzma.bak
2014-05-21T01:06:08.450Z,1400634368.450 [DataOverHttps](INFO): SBD MOMSN=964861
2014-05-21T01:06:13.617Z,1400634373.617 [DataOverHttps](INFO): Sending 194 bytes from file Logs/20140521T002034/Express0005.lzma
2014-05-21T01:06:14.472Z,1400634374.472 [DataOverHttps](INFO): Moved sent file to Logs/20140521T002034/Express0005.lzma.bak
2014-05-21T01:06:14.472Z,1400634374.472 [DataOverHttps](INFO): SBD MOMSN=964875
2014-05-21T01:06:19.644Z,1400634379.644 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20140521T002034/Express0009.lzma
2014-05-21T01:06:20.485Z,1400634380.485 [DataOverHttps](INFO): Moved sent file to Logs/20140521T002034/Express0009.lzma.bak
2014-05-21T01:06:20.485Z,1400634380.485 [DataOverHttps](INFO): SBD MOMSN=964880
2014-05-21T01:06:25.674Z,1400634385.674 [DataOverHttps](INFO): Sending 745 bytes from file Logs/20140521T003052/Express0001.lzma
2014-05-21T01:06:26.560Z,1400634386.560 [DataOverHttps](INFO): Moved sent file to Logs/20140521T003052/Express0001.lzma.bak
2014-05-21T01:06:26.560Z,1400634386.560 [DataOverHttps](INFO): SBD MOMSN=964882
2014-05-21T01:06:31.857Z,1400634391.857 [DataOverHttps](INFO): Sending 92 bytes from file Logs/20140521T003052/Express0005.lzma
2014-05-21T01:06:32.676Z,1400634392.676 [DataOverHttps](INFO): Moved sent file to Logs/20140521T003052/Express0005.lzma.bak
2014-05-21T01:06:32.676Z,1400634392.676 [DataOverHttps](INFO): SBD MOMSN=964897
2014-05-21T01:06:37.862Z,1400634397.862 [DataOverHttps](INFO): Sending 961 bytes from file Logs/20140521T003511/Express0001.lzma
2014-05-21T01:06:38.685Z,1400634398.685 [DataOverHttps](INFO): Moved sent file to Logs/20140521T003511/Express0001.lzma.bak
2014-05-21T01:06:38.685Z,1400634398.685 [DataOverHttps](INFO): SBD MOMSN=964900
2014-05-21T01:06:44.025Z,1400634404.025 [DataOverHttps](INFO): Sending 861 bytes from file Logs/20140521T003738/Express0001.lzma
2014-05-21T01:06:44.867Z,1400634404.867 [DataOverHttps](INFO): Moved sent file to Logs/20140521T003738/Express0001.lzma.bak
2014-05-21T01:06:44.867Z,1400634404.867 [DataOverHttps](INFO): SBD MOMSN=964917
2014-05-21T01:06:50.060Z,1400634410.060 [DataOverHttps](INFO): Sending 106 bytes from file Logs/20140521T003738/Express0005.lzma
2014-05-21T01:06:50.880Z,1400634410.880 [DataOverHttps](INFO): Moved sent file to Logs/20140521T003738/Express0005.lzma.bak
2014-05-21T01:06:50.880Z,1400634410.880 [DataOverHttps](INFO): SBD MOMSN=964931
2014-05-21T01:06:56.095Z,1400634416.095 [DataOverHttps](INFO): Sending 461 bytes from file Logs/20140521T003738/Express0009.lzma
2014-05-21T01:06:56.905Z,1400634416.905 [DataOverHttps](INFO): Moved sent file to Logs/20140521T003738/Express0009.lzma.bak
2014-05-21T01:06:56.906Z,1400634416.906 [DataOverHttps](INFO): SBD MOMSN=964934
2014-05-21T01:07:02.120Z,1400634422.120 [DataOverHttps](INFO): Sending 907 bytes from file Logs/20140521T004727/Express0001.lzma
2014-05-21T01:07:02.999Z,1400634422.999 [DataOverHttps](INFO): Moved sent file to Logs/20140521T004727/Express0001.lzma.bak
2014-05-21T01:07:02.999Z,1400634422.999 [DataOverHttps](INFO): SBD MOMSN=964943
2014-05-21T01:07:08.154Z,1400634428.154 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20140521T004727/Express0005.lzma
2014-05-21T01:07:09.016Z,1400634429.016 [DataOverHttps](INFO): Moved sent file to Logs/20140521T004727/Express0005.lzma.bak
2014-05-21T01:07:09.016Z,1400634429.016 [DataOverHttps](INFO): SBD MOMSN=964958
2014-05-21T01:07:14.242Z,1400634434.242 [DataOverHttps](INFO): Sending 870 bytes from file Logs/20140521T005110/Express0001.lzma
2014-05-21T01:07:15.065Z,1400634435.065 [DataOverHttps](INFO): Moved sent file to Logs/20140521T005110/Express0001.lzma.bak
2014-05-21T01:07:15.066Z,1400634435.066 [DataOverHttps](INFO): SBD MOMSN=964960
2014-05-21T01:07:20.262Z,1400634440.262 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20140521T005110/Express0005.lzma
2014-05-21T01:07:21.123Z,1400634441.123 [DataOverHttps](INFO): Moved sent file to Logs/20140521T005110/Express0005.lzma.bak
2014-05-21T01:07:21.123Z,1400634441.123 [DataOverHttps](INFO): SBD MOMSN=964974
2014-05-21T01:07:26.332Z,1400634446.332 [DataOverHttps](INFO): Sending 767 bytes from file Logs/20140521T005110/Express0009.lzma
2014-05-21T01:07:27.173Z,1400634447.173 [DataOverHttps](INFO): Moved sent file to Logs/20140521T005110/Express0009.lzma.bak
2014-05-21T01:07:27.173Z,1400634447.173 [DataOverHttps](INFO): SBD MOMSN=964979
2014-05-21T01:07:32.335Z,1400634452.335 [DataOverHttps](INFO): Sending 946 bytes from file Logs/20140521T005838/Express0001.lzma
2014-05-21T01:07:33.222Z,1400634453.222 [DataOverHttps](INFO): Moved sent file to Logs/20140521T005838/Express0001.lzma.bak
2014-05-21T01:07:33.222Z,1400634453.222 [DataOverHttps](INFO): SBD MOMSN=964998
2014-05-21T01:07:36.235Z,1400634456.235 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2014-05-21T01:07:38.398Z,1400634458.398 [DataOverHttps](INFO): Sending 1025 bytes from file Logs/20140521T010143/Express0001.lzma
2014-05-21T01:07:39.303Z,1400634459.303 [DataOverHttps](INFO): Moved sent file to Logs/20140521T010143/Express0001.lzma.bak
2014-05-21T01:07:39.303Z,1400634459.303 [DataOverHttps](INFO): SBD MOMSN=965016
2014-05-21T01:07:44.490Z,1400634464.490 [DataOverHttps](INFO): Sending 106 bytes from file Logs/20140521T010143/Express0005.lzma
2014-05-21T01:07:45.389Z,1400634465.389 [DataOverHttps](INFO): Moved sent file to Logs/20140521T010143/Express0005.lzma.bak
2014-05-21T01:07:45.390Z,1400634465.390 [DataOverHttps](INFO): SBD MOMSN=965037
2014-05-21T01:07:48.810Z,1400634468.810 [HFRadarModelCalc](IMPORTANT): Forecast time 20140520T220000: published 50 modes in rows, 61 hours in columns, 3050 elements.
2014-05-21T01:07:49.540Z,1400634469.540 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients.
2014-05-21T01:07:49.554Z,1400634469.554 [Default:Iridium:Read_Iridium] Stopped
2014-05-21T01:07:49.555Z,1400634469.555 [Default:Iridium](INFO): Completed Default:Iridium
2014-05-21T01:07:49.555Z,1400634469.555 [Default:Iridium] Stopped
2014-05-21T01:07:49.555Z,1400634469.555 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-21T01:07:49.555Z,1400634469.555 [Default:Iridium:A.SetSpeed] Stopped
2014-05-21T01:07:49.555Z,1400634469.555 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-21T01:07:49.555Z,1400634469.555 [Default:WaitAtTheSurface] Running Loop=1
2014-05-21T01:07:49.556Z,1400634469.556 [Default:WaitAtTheSurface](INFO): Aggregate::initialize Default:WaitAtTheSurface
2014-05-21T01:07:49.556Z,1400634469.556 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Running Loop=1
2014-05-21T01:07:49.556Z,1400634469.556 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Initialize.
2014-05-21T01:07:49.556Z,1400634469.556 [Default:WaitAtTheSurface:B.GoToSurface] Running Loop=1
2014-05-21T01:07:49.556Z,1400634469.556 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-21T01:07:50.238Z,1400634470.238 [Default:WaitAtTheSurface:B.GoToSurface] Running Loop=1
2014-05-21T01:07:50.243Z,1400634470.243 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Running Loop=1
2014-05-21T01:07:50.258Z,1400634470.258 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-05-21T01:07:50.258Z,1400634470.258 [Default:CallIridium:B] Stopped
2014-05-21T01:07:50.258Z,1400634470.258 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-21T01:07:50.258Z,1400634470.258 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-05-21T01:07:50.258Z,1400634470.258 [Default:CallIridium] Stopped
2014-05-21T01:07:50.258Z,1400634470.258 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-21T01:08:33.506Z,1400634513.506 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-21T01:08:33.506Z,1400634513.506 [DVL_micro] Data Fault, FailCount= 1
2014-05-21T01:08:33.506Z,1400634513.506 [DVL_micro](ERROR): Data Fault
2014-05-21T01:08:33.586Z,1400634513.586 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-21T01:08:34.008Z,1400634514.008 [DVL_micro](INFO): uninitialize:Powering down
2014-05-21T01:08:34.402Z,1400634514.402 [DVL_micro](FAULT): LCB fault: Software Overcurrent.
2014-05-21T01:08:34.402Z,1400634514.402 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-21T01:08:34.402Z,1400634514.402 [DVL_micro](ERROR): Hardware Fault
2014-05-21T01:08:34.837Z,1400634514.837 [DVL_micro](INFO): Initializing
2014-05-21T01:08:34.903Z,1400634514.903 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-21T01:08:34.903Z,1400634514.903 [DVL_micro] No Fault, FailCount= 1
2014-05-21T01:10:53.512Z,1400634653.512 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#6 STATUS: 65535
2014-05-21T01:10:58.043Z,1400634658.043 [CommandLine](IMPORTANT): got command maintain sensor NAL9602.latitude_fix 36.830002 degree
2014-05-21T01:10:58.044Z,1400634658.044 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.latitude_fix" handled in the control thread.
2014-05-21T01:10:58.045Z,1400634658.045 [CommandLine](IMPORTANT): got command maintain sensor NAL9602.longitude_fix -121.870003 degree
2014-05-21T01:10:58.046Z,1400634658.046 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.longitude_fix" handled in the control thread.
2014-05-21T01:10:58.046Z,1400634658.046 [CommandLine](IMPORTANT): got command ! echo "pretend you are at the nominal start point for the HF Radar tests"
2014-05-21T01:10:58.148Z,1400634658.148 [CommandLine](IMPORTANT): pretend you are at the nominal start point for the HF Radar tests
2014-05-21T01:10:58.310Z,1400634658.310 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,DataOverHttps,Depth_Keller,DVL_micro,NAL9602,Onboard,SCPI,ISUS,PAR_Licor,Depth_Keller,PAR_Licor,Maintain_NAL9602.latitude_fix,Maintain_NAL9602.longitude_fix,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-21T01:10:58.769Z,1400634658.769 [Default:GPS:Read_GPS] Stopped
2014-05-21T01:10:58.769Z,1400634658.769 [Default:GPS:D] Running Loop=1
2014-05-21T01:10:59.166Z,1400634659.166 [Default:GPS:D] Stopped
2014-05-21T01:10:59.166Z,1400634659.166 [Default:GPS](INFO): Completed Default:GPS
2014-05-21T01:10:59.166Z,1400634659.166 [Default:GPS] Stopped
2014-05-21T01:10:59.166Z,1400634659.166 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-05-21T01:10:59.167Z,1400634659.167 [Default:GPS:A.SetSpeed] Stopped
2014-05-21T01:10:59.167Z,1400634659.167 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-05-21T01:10:59.177Z,1400634659.177 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.063472 m/s
2014-05-21T01:10:59.178Z,1400634659.178 [Reporter](INFO): HFRadarModelCalc.surface_northward_sea_water_velocity -0.077975 m/s
2014-05-21T01:10:59.179Z,1400634659.179 [Reporter](INFO): HFRCMSurfaceCurrentAtVehicleLocation.surface_eastward_sea_water_velocity 0.000000 m/s
2014-05-21T01:10:59.180Z,1400634659.180 [Reporter](INFO): HFRCMSurfaceCurrentAtVehicleLocation.surface_northward_sea_water_velocity 0.000000 m/s
2014-05-21T01:11:04.887Z,1400634664.887 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.063473 m/s
2014-05-21T01:11:14.779Z,1400634674.779 [NAL9602](INFO): Powering down
2014-05-21T01:11:14.853Z,1400634674.853 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.063475 m/s
2014-05-21T01:11:14.854Z,1400634674.854 [Reporter](INFO): HFRadarModelCalc.surface_northward_sea_water_velocity -0.077982 m/s
2014-05-21T01:11:29.801Z,1400634689.801 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.062786 m/s
2014-05-21T01:11:29.802Z,1400634689.802 [Reporter](INFO): HFRadarModelCalc.surface_northward_sea_water_velocity -0.077926 m/s
2014-05-21T01:11:39.799Z,1400634699.799 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.062788 m/s
2014-05-21T01:11:39.800Z,1400634699.800 [Reporter](INFO): HFRadarModelCalc.surface_northward_sea_water_velocity -0.077933 m/s
2014-05-21T01:11:44.741Z,1400634704.741 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-21T01:11:44.741Z,1400634704.741 [DVL_micro] Data Fault, FailCount= 1
2014-05-21T01:11:44.741Z,1400634704.741 [DVL_micro](ERROR): Data Fault
2014-05-21T01:11:44.826Z,1400634704.826 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-21T01:11:44.832Z,1400634704.832 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.062787 m/s
2014-05-21T01:11:49.828Z,1400634709.828 [DVL_micro](INFO): uninitialize:Powering down
2014-05-21T01:11:54.680Z,1400634714.680 [DVL_micro](FAULT): LCB fault: Software Overcurrent.
2014-05-21T01:11:54.680Z,1400634714.680 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-21T01:11:54.680Z,1400634714.680 [DVL_micro](ERROR): Hardware Fault
2014-05-21T01:12:00.260Z,1400634720.260 [DVL_micro](INFO): Initializing
2014-05-21T01:12:00.313Z,1400634720.313 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-21T01:12:00.313Z,1400634720.313 [DVL_micro] No Fault, FailCount= 1
2014-05-21T01:12:04.766Z,1400634724.766 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.062788 m/s
2014-05-21T01:12:04.787Z,1400634724.787 [Reporter](INFO): HFRadarModelCalc.surface_northward_sea_water_velocity -0.077940 m/s
2014-05-21T01:12:20.091Z,1400634740.091 [CommandLine](IMPORTANT): got command maintain sensor NAL9602.latitude_fix 36.799999 degree
2014-05-21T01:12:20.091Z,1400634740.091 [CommandLine](IMPORTANT): got command maintain sensor NAL9602.longitude_fix -121.900002 degree
2014-05-21T01:12:29.882Z,1400634749.882 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.062790 m/s
2014-05-21T01:12:29.883Z,1400634749.883 [Reporter](INFO): HFRadarModelCalc.surface_northward_sea_water_velocity -0.077946 m/s
2014-05-21T01:12:34.764Z,1400634754.764 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.062789 m/s
2014-05-21T01:12:49.857Z,1400634769.857 [Default:CallIridium] Running Loop=1
2014-05-21T01:12:49.858Z,1400634769.858 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-05-21T01:12:49.858Z,1400634769.858 [Default:CallIridium:A] Running Loop=1
2014-05-21T01:12:49.858Z,1400634769.858 [Default:CallIridium:A] Stopped
2014-05-21T01:12:49.858Z,1400634769.858 [Default:CallIridium:B] Running Loop=1
2014-05-21T01:12:49.858Z,1400634769.858 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-05-21T01:12:49.883Z,1400634769.883 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.062791 m/s
2014-05-21T01:12:49.884Z,1400634769.884 [Reporter](INFO): HFRadarModelCalc.surface_northward_sea_water_velocity -0.077953 m/s
2014-05-21T01:12:54.774Z,1400634774.774 [Default:Iridium] Running Loop=1
2014-05-21T01:12:54.774Z,1400634774.774 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-21T01:12:54.774Z,1400634774.774 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-21T01:12:54.775Z,1400634774.775 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-21T01:12:54.775Z,1400634774.775 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-21T01:12:54.775Z,1400634774.775 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-21T01:12:54.776Z,1400634774.776 [Default:Iridium:B.GoToSurface] Stopped
2014-05-21T01:12:54.776Z,1400634774.776 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-21T01:12:54.776Z,1400634774.776 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-21T01:12:54.776Z,1400634774.776 [Default:GPS] Running Loop=1
2014-05-21T01:12:54.776Z,1400634774.776 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-05-21T01:12:54.777Z,1400634774.777 [Default:GPS:A.SetSpeed] Running Loop=1
2014-05-21T01:12:54.777Z,1400634774.777 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-05-21T01:12:54.777Z,1400634774.777 [Default:GPS:B.GoToSurface] Running Loop=1
2014-05-21T01:12:54.777Z,1400634774.777 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-21T01:12:54.778Z,1400634774.778 [Default:GPS:B.GoToSurface] Stopped
2014-05-21T01:12:54.778Z,1400634774.778 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-21T01:12:54.778Z,1400634774.778 [Default:GPS:Read_GPS] Running Loop=1
2014-05-21T01:12:55.740Z,1400634775.740 [Default:GPS:Read_GPS] Stopped
2014-05-21T01:12:55.740Z,1400634775.740 [Default:GPS:D] Running Loop=1
2014-05-21T01:12:55.754Z,1400634775.754 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.062790 m/s
2014-05-21T01:12:56.590Z,1400634776.590 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20140521T010143/Courier0008.lzma
2014-05-21T01:12:56.649Z,1400634776.649 [Default:GPS:D] Stopped
2014-05-21T01:12:56.649Z,1400634776.649 [Default:GPS](INFO): Completed Default:GPS
2014-05-21T01:12:56.649Z,1400634776.649 [Default:GPS] Stopped
2014-05-21T01:12:56.649Z,1400634776.649 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-05-21T01:12:56.650Z,1400634776.650 [Default:GPS:A.SetSpeed] Stopped
2014-05-21T01:12:56.650Z,1400634776.650 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-05-21T01:12:57.474Z,1400634777.474 [DataOverHttps](INFO): Moved sent file to Logs/20140521T010143/Courier0008.lzma.bak
2014-05-21T01:12:57.474Z,1400634777.474 [DataOverHttps](INFO): SBD MOMSN=965040
2014-05-21T01:12:59.452Z,1400634779.452 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.062791 m/s
2014-05-21T01:13:03.101Z,1400634783.101 [DataOverHttps](INFO): Sending 841 bytes from file Logs/20140521T010143/Express0009.lzma
2014-05-21T01:13:03.978Z,1400634783.978 [DataOverHttps](INFO): Moved sent file to Logs/20140521T010143/Express0009.lzma.bak
2014-05-21T01:13:03.979Z,1400634783.979 [DataOverHttps](INFO): SBD MOMSN=965042
2014-05-21T01:13:08.537Z,1400634788.537 [CommandLine](IMPORTANT): got command maintain sensor NAL9602.latitude_fix 36.799999 degree
2014-05-21T01:13:08.538Z,1400634788.538 [CommandLine](IMPORTANT): got command maintain sensor NAL9602.longitude_fix -121.900002 degree
2014-05-21T01:13:08.935Z,1400634788.935 [HFRadarModelCalc](IMPORTANT): Forecast time 20140520T220000: published 50 modes in rows, 61 hours in columns, 3050 elements.
2014-05-21T01:13:09.701Z,1400634789.701 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients.
2014-05-21T01:13:09.714Z,1400634789.714 [Default:Iridium:Read_Iridium] Stopped
2014-05-21T01:13:09.714Z,1400634789.714 [Default:Iridium](INFO): Completed Default:Iridium
2014-05-21T01:13:09.714Z,1400634789.714 [Default:Iridium] Stopped
2014-05-21T01:13:09.715Z,1400634789.714 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-21T01:13:09.715Z,1400634789.714 [Default:Iridium:A.SetSpeed] Stopped
2014-05-21T01:13:09.715Z,1400634789.715 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-21T01:13:10.387Z,1400634790.387 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-05-21T01:13:10.387Z,1400634790.387 [Default:CallIridium:B] Stopped
2014-05-21T01:13:10.388Z,1400634790.388 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-21T01:13:10.388Z,1400634790.388 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-05-21T01:13:10.388Z,1400634790.388 [Default:CallIridium] Stopped
2014-05-21T01:13:10.388Z,1400634790.388 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-21T01:13:10.401Z,1400634790.401 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.062794 m/s
2014-05-21T01:13:10.402Z,1400634790.402 [Reporter](INFO): HFRadarModelCalc.surface_northward_sea_water_velocity -0.077960 m/s
2014-05-21T01:13:15.781Z,1400634795.781 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.062795 m/s
2014-05-21T01:13:20.346Z,1400634800.346 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.062796 m/s
2014-05-21T01:13:25.319Z,1400634805.319 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.062797 m/s
2014-05-21T01:13:30.373Z,1400634810.373 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.062798 m/s
2014-05-21T01:13:40.383Z,1400634820.383 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.062111 m/s
2014-05-21T01:13:40.384Z,1400634820.384 [Reporter](INFO): HFRadarModelCalc.surface_northward_sea_water_velocity -0.077911 m/s
2014-05-21T01:13:45.415Z,1400634825.415 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.062112 m/s
2014-05-21T01:13:45.416Z,1400634825.416 [Reporter](INFO): HFRadarModelCalc.surface_northward_sea_water_velocity -0.077912 m/s
2014-05-21T01:13:55.319Z,1400634835.319 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.062113 m/s
2014-05-21T01:14:10.373Z,1400634850.373 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.062115 m/s
2014-05-21T01:14:10.374Z,1400634850.374 [Reporter](INFO): HFRadarModelCalc.surface_northward_sea_water_velocity -0.077918 m/s
2014-05-21T01:14:20.359Z,1400634860.359 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.062116 m/s
2014-05-21T01:14:35.325Z,1400634875.325 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.062117 m/s
2014-05-21T01:14:40.440Z,1400634880.440 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.062118 m/s
2014-05-21T01:14:40.456Z,1400634880.456 [Reporter](INFO): HFRadarModelCalc.surface_northward_sea_water_velocity -0.077925 m/s
2014-05-21T01:15:05.310Z,1400634905.310 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.062120 m/s
2014-05-21T01:15:05.311Z,1400634905.311 [Reporter](INFO): HFRadarModelCalc.surface_northward_sea_water_velocity -0.077932 m/s
2014-05-21T01:15:20.731Z,1400634920.731 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-21T01:15:20.731Z,1400634920.731 [DVL_micro] Data Fault, FailCount= 1
2014-05-21T01:15:20.731Z,1400634920.731 [DVL_micro](ERROR): Data Fault
2014-05-21T01:15:20.767Z,1400634920.767 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-21T01:15:25.370Z,1400634925.370 [DVL_micro](INFO): uninitialize:Powering down
2014-05-21T01:15:30.261Z,1400634930.261 [DVL_micro](FAULT): LCB fault: Software Overcurrent.
2014-05-21T01:15:30.261Z,1400634930.261 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-21T01:15:30.261Z,1400634930.261 [DVL_micro](ERROR): Hardware Fault
2014-05-21T01:15:30.345Z,1400634930.345 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.062122 m/s
2014-05-21T01:15:30.346Z,1400634930.346 [Reporter](INFO): HFRadarModelCalc.surface_northward_sea_water_velocity -0.077939 m/s
2014-05-21T01:15:35.283Z,1400634935.283 [DVL_micro](INFO): Initializing
2014-05-21T01:15:35.345Z,1400634935.345 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-21T01:15:35.345Z,1400634935.345 [DVL_micro] No Fault, FailCount= 1
2014-05-21T01:15:45.328Z,1400634945.328 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.061432 m/s
2014-05-21T01:15:45.329Z,1400634945.329 [Reporter](INFO): HFRadarModelCalc.surface_northward_sea_water_velocity -0.077883 m/s
2014-05-21T01:15:50.317Z,1400634950.317 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.061434 m/s
2014-05-21T01:15:50.318Z,1400634950.318 [Reporter](INFO): HFRadarModelCalc.surface_northward_sea_water_velocity -0.077890 m/s
2014-05-21T01:16:05.348Z,1400634965.348 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.061433 m/s
2014-05-21T01:16:15.318Z,1400634975.318 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.061434 m/s
2014-05-21T01:16:15.319Z,1400634975.319 [Reporter](INFO): HFRadarModelCalc.surface_northward_sea_water_velocity -0.077896 m/s
2014-05-21T01:16:35.362Z,1400634995.362 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.061436 m/s
2014-05-21T01:16:35.363Z,1400634995.363 [Reporter](INFO): HFRadarModelCalc.surface_northward_sea_water_velocity -0.077903 m/s
2014-05-21T01:16:40.292Z,1400635000.292 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.061435 m/s
2014-05-21T01:16:55.354Z,1400635015.354 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.061437 m/s
2014-05-21T01:16:55.355Z,1400635015.355 [Reporter](INFO): HFRadarModelCalc.surface_northward_sea_water_velocity -0.077910 m/s
2014-05-21T01:17:00.318Z,1400635020.318 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.061436 m/s
2014-05-21T01:17:15.375Z,1400635035.375 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.061438 m/s
2014-05-21T01:17:15.376Z,1400635035.376 [Reporter](INFO): HFRadarModelCalc.surface_northward_sea_water_velocity -0.077917 m/s
2014-05-21T01:17:20.322Z,1400635040.322 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.061437 m/s
2014-05-21T01:17:35.363Z,1400635055.363 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.061439 m/s
2014-05-21T01:17:35.364Z,1400635055.364 [Reporter](INFO): HFRadarModelCalc.surface_northward_sea_water_velocity -0.077923 m/s
2014-05-21T01:17:45.402Z,1400635065.402 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.061438 m/s
2014-05-21T01:17:50.313Z,1400635070.313 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.061440 m/s
2014-05-21T01:17:50.314Z,1400635070.314 [Reporter](INFO): HFRadarModelCalc.surface_northward_sea_water_velocity -0.077930 m/s
2014-05-21T01:17:55.368Z,1400635075.368 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.060750 m/s
2014-05-21T01:17:55.369Z,1400635075.369 [Reporter](INFO): HFRadarModelCalc.surface_northward_sea_water_velocity -0.077874 m/s
2014-05-21T01:18:05.357Z,1400635085.357 [Default:CallIridium] Running Loop=1
2014-05-21T01:18:05.357Z,1400635085.357 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-05-21T01:18:05.358Z,1400635085.358 [Default:CallIridium:A] Running Loop=1
2014-05-21T01:18:05.358Z,1400635085.358 [Default:CallIridium:A] Stopped
2014-05-21T01:18:05.358Z,1400635085.358 [Default:CallIridium:B] Running Loop=1
2014-05-21T01:18:05.358Z,1400635085.358 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-05-21T01:18:10.282Z,1400635090.282 [Default:Iridium] Running Loop=1
2014-05-21T01:18:10.282Z,1400635090.282 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-21T01:18:10.283Z,1400635090.283 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-21T01:18:10.283Z,1400635090.283 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-21T01:18:10.283Z,1400635090.283 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-21T01:18:10.283Z,1400635090.283 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-21T01:18:10.284Z,1400635090.284 [Default:Iridium:B.GoToSurface] Stopped
2014-05-21T01:18:10.284Z,1400635090.284 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-21T01:18:10.284Z,1400635090.284 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-21T01:18:10.284Z,1400635090.284 [Default:GPS] Running Loop=1
2014-05-21T01:18:10.284Z,1400635090.284 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-05-21T01:18:10.284Z,1400635090.284 [Default:GPS:A.SetSpeed] Running Loop=1
2014-05-21T01:18:10.284Z,1400635090.284 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-05-21T01:18:10.284Z,1400635090.284 [Default:GPS:B.GoToSurface] Running Loop=1
2014-05-21T01:18:10.285Z,1400635090.285 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-21T01:18:10.285Z,1400635090.285 [Default:GPS:B.GoToSurface] Stopped
2014-05-21T01:18:10.286Z,1400635090.286 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-21T01:18:10.286Z,1400635090.286 [Default:GPS:Read_GPS] Running Loop=1
2014-05-21T01:18:10.313Z,1400635090.313 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.060751 m/s
2014-05-21T01:18:10.318Z,1400635090.318 [Reporter](INFO): HFRadarModelCalc.surface_northward_sea_water_velocity -0.077881 m/s
2014-05-21T01:18:10.733Z,1400635090.733 [Default:GPS:Read_GPS] Stopped
2014-05-21T01:18:10.733Z,1400635090.733 [Default:GPS:D] Running Loop=1
2014-05-21T01:18:11.346Z,1400635091.346 [Default:GPS:D] Stopped
2014-05-21T01:18:11.371Z,1400635091.371 [Default:GPS](INFO): Completed Default:GPS
2014-05-21T01:18:11.371Z,1400635091.371 [Default:GPS] Stopped
2014-05-21T01:18:11.371Z,1400635091.371 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-05-21T01:18:11.371Z,1400635091.371 [Default:GPS:A.SetSpeed] Stopped
2014-05-21T01:18:11.371Z,1400635091.371 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-05-21T01:18:13.226Z,1400635093.226 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20140521T010143/Courier0012.lzma
2014-05-21T01:18:14.173Z,1400635094.173 [DataOverHttps](INFO): Moved sent file to Logs/20140521T010143/Courier0012.lzma.bak
2014-05-21T01:18:14.173Z,1400635094.173 [DataOverHttps](INFO): SBD MOMSN=965058
2014-05-21T01:18:18.305Z,1400635098.305 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.060752 m/s
2014-05-21T01:18:19.600Z,1400635099.600 [DataOverHttps](INFO): Sending 354 bytes from file Logs/20140521T010143/Express0013.lzma
2014-05-21T01:18:20.509Z,1400635100.509 [DataOverHttps](INFO): Moved sent file to Logs/20140521T010143/Express0013.lzma.bak
2014-05-21T01:18:20.509Z,1400635100.509 [DataOverHttps](INFO): SBD MOMSN=965060
2014-05-21T01:18:24.174Z,1400635104.174 [HFRadarModelCalc](IMPORTANT): Forecast time 20140520T220000: published 50 modes in rows, 61 hours in columns, 3050 elements.
2014-05-21T01:18:24.901Z,1400635104.901 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients.
2014-05-21T01:18:24.921Z,1400635104.921 [Default:Iridium:Read_Iridium] Stopped
2014-05-21T01:18:24.922Z,1400635104.922 [Default:Iridium](INFO): Completed Default:Iridium
2014-05-21T01:18:24.922Z,1400635104.922 [Default:Iridium] Stopped
2014-05-21T01:18:24.922Z,1400635104.922 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-21T01:18:24.922Z,1400635104.922 [Default:Iridium:A.SetSpeed] Stopped
2014-05-21T01:18:24.922Z,1400635104.922 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-21T01:18:25.596Z,1400635105.596 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-05-21T01:18:25.596Z,1400635105.596 [Default:CallIridium:B] Stopped
2014-05-21T01:18:25.596Z,1400635105.596 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-21T01:18:25.597Z,1400635105.597 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-05-21T01:18:25.597Z,1400635105.597 [Default:CallIridium] Stopped
2014-05-21T01:18:25.597Z,1400635105.597 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-21T01:18:25.608Z,1400635105.608 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.060753 m/s
2014-05-21T01:18:31.003Z,1400635111.003 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.060754 m/s
2014-05-21T01:18:35.587Z,1400635115.587 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.060755 m/s
2014-05-21T01:18:40.502Z,1400635120.502 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.060756 m/s
2014-05-21T01:18:45.566Z,1400635125.566 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.060758 m/s
2014-05-21T01:18:45.567Z,1400635125.567 [Reporter](INFO): HFRadarModelCalc.surface_northward_sea_water_velocity -0.077888 m/s
2014-05-21T01:18:50.551Z,1400635130.551 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.060759 m/s
2014-05-21T01:18:55.483Z,1400635135.483 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-21T01:18:55.483Z,1400635135.483 [DVL_micro] Data Fault, FailCount= 1
2014-05-21T01:18:55.483Z,1400635135.483 [DVL_micro](ERROR): Data Fault
2014-05-21T01:18:55.520Z,1400635135.520 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-21T01:19:00.572Z,1400635140.572 [DVL_micro](INFO): uninitialize:Powering down
2014-05-21T01:19:00.632Z,1400635140.632 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.060760 m/s
2014-05-21T01:19:05.473Z,1400635145.473 [DVL_micro](FAULT): LCB fault: Software Overcurrent.
2014-05-21T01:19:05.473Z,1400635145.473 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-21T01:19:05.474Z,1400635145.474 [DVL_micro](ERROR): Hardware Fault
2014-05-21T01:19:10.482Z,1400635150.482 [DVL_micro](INFO): Initializing
2014-05-21T01:19:10.557Z,1400635150.557 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-21T01:19:10.558Z,1400635150.558 [DVL_micro] No Fault, FailCount= 1
2014-05-21T01:19:10.560Z,1400635150.560 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.060761 m/s
2014-05-21T01:19:20.541Z,1400635160.541 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.060763 m/s
2014-05-21T01:19:20.542Z,1400635160.542 [Reporter](INFO): HFRadarModelCalc.surface_northward_sea_water_velocity -0.077895 m/s
2014-05-21T01:19:25.527Z,1400635165.527 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.060764 m/s
2014-05-21T01:19:40.616Z,1400635180.616 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.060765 m/s
2014-05-21T01:19:50.573Z,1400635190.573 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.060767 m/s
2014-05-21T01:19:50.574Z,1400635190.574 [Reporter](INFO): HFRadarModelCalc.surface_northward_sea_water_velocity -0.077902 m/s
2014-05-21T01:20:00.573Z,1400635200.573 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.060077 m/s
2014-05-21T01:20:00.574Z,1400635200.574 [Reporter](INFO): HFRadarModelCalc.surface_northward_sea_water_velocity -0.077846 m/s
2014-05-21T01:20:15.535Z,1400635215.535 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.060079 m/s
2014-05-21T01:20:15.536Z,1400635215.536 [Reporter](INFO): HFRadarModelCalc.surface_northward_sea_water_velocity -0.077853 m/s
2014-05-21T01:20:40.616Z,1400635240.616 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.060081 m/s
2014-05-21T01:20:40.617Z,1400635240.617 [Reporter](INFO): HFRadarModelCalc.surface_northward_sea_water_velocity -0.077860 m/s
2014-05-21T01:21:00.571Z,1400635260.571 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.060080 m/s
2014-05-21T01:21:05.782Z,1400635265.782 [Reporter](INFO): HFRadarModelCalc.surface_eastward_sea_water_velocity 0.060082 m/s
2014-05-21T01:21:05.783Z,1400635265.783 [Reporter](INFO): HFRadarModelCalc.surface_northward_sea_water_velocity -0.077866 m/s
2014-05-21T01:21:21.322Z,1400635281.322 [CommandLine](IMPORTANT): got command restart application
2014-05-21T01:21:22.330Z,1400635282.330 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-21T01:21:22.330Z,1400635282.330 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-05-21T01:21:22.403Z,1400635282.403 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2014-05-21T01:21:22.403Z,1400635282.403 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-05-21T01:21:22.404Z,1400635282.404 [CommandLine](INFO): Join timeout helper Thread ID is 1021
2014-05-21T01:21:22.404Z,1400635282.404 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2014-05-21T01:21:22.405Z,1400635282.405 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-05-21T01:21:22.405Z,1400635282.405 [NavChartDb](INFO): Join timeout helper Thread ID is 1022
2014-05-21T01:21:22.464Z,1400635282.464 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-21T01:21:22.465Z,1400635282.465 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-05-21T01:21:22.483Z,1400635282.483 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2014-05-21T01:21:22.483Z,1400635282.483 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-05-21T01:21:22.484Z,1400635282.484 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1023
2014-05-21T01:21:22.564Z,1400635282.564 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-21T01:21:22.566Z,1400635282.566 [WetLabsBB2FL](INFO): Powering down
2014-05-21T01:21:22.567Z,1400635282.567 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-05-21T01:21:22.584Z,1400635282.584 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2014-05-21T01:21:22.584Z,1400635282.584 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-05-21T01:21:22.584Z,1400635282.584 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 1024
2014-05-21T01:21:22.632Z,1400635282.632 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-21T01:21:22.632Z,1400635282.632 [CTD_NeilBrown](INFO): Powering down
2014-05-21T01:21:22.633Z,1400635282.633 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-05-21T01:21:22.644Z,1400635282.644 [ComponentRegistry](INFO): Shutting down Radio_Freewave ThreadHandler
2014-05-21T01:21:22.644Z,1400635282.644 [Radio_Freewave ThreadHandler](INFO): Thread cancelled.
2014-05-21T01:21:22.644Z,1400635282.644 [Radio_Freewave](INFO): Join timeout helper Thread ID is 1025
2014-05-21T01:21:22.990Z,1400635282.990 [Radio_Freewave ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-21T01:21:23.100Z,1400635283.100 [Radio_Freewave](INFO): Powering down
2014-05-21T01:21:23.505Z,1400635283.505 [Radio_Freewave ThreadHandler](INFO): Thread cancelled.
2014-05-21T01:21:23.518Z,1400635283.518 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2014-05-21T01:21:23.518Z,1400635283.518 [logger ThreadHandler](INFO): Thread cancelled.
2014-05-21T01:21:23.519Z,1400635283.519 [logger](INFO): Join timeout helper Thread ID is 1028
2014-05-21T01:21:23.565Z,1400635283.565 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-21T01:21:23.565Z,1400635283.565 [logger ThreadHandler](INFO): Thread cancelled.
2014-05-21T01:21:23.578Z,1400635283.578 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2014-05-21T01:21:23.578Z,1400635283.578 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-05-21T01:21:23.578Z,1400635283.578 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2014-05-21T01:21:23.578Z,1400635283.578 [controlThread ThreadHandler](INFO): Thread cancelled.
2014-05-21T01:21:23.579Z,1400635283.579 [controlThread](INFO): Join timeout helper Thread ID is 1029
2014-05-21T01:21:24.935Z,1400635284.935 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-21T01:21:24.936Z,1400635284.936 [controlThread](DEBUG): Uninitializing ControlThread
2014-05-21T01:21:24.936Z,1400635284.936 [AHRS_sp3003D](INFO): Powering down
2014-05-21T01:21:25.096Z,1400635285.096 [DVL_micro](INFO): uninitialize:Powering down
2014-05-21T01:21:25.097Z,1400635285.097 [NAL9602](INFO): Powering down
2014-05-21T01:21:25.100Z,1400635285.100 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2014-05-21T01:21:25.103Z,1400635285.103 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2014-05-21T01:21:25.104Z,1400635285.104 [Default] Stopped
2014-05-21T01:21:25.104Z,1400635285.104 [Default](INFO): Aggregate::uninitialize Default
2014-05-21T01:21:25.104Z,1400635285.104 [Default:WaitAtTheSurface] Stopped
2014-05-21T01:21:25.104Z,1400635285.104 [Default:WaitAtTheSurface](INFO): Aggregate::uninitialize Default:WaitAtTheSurface
2014-05-21T01:21:25.104Z,1400635285.104 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Stopped
2014-05-21T01:21:25.104Z,1400635285.104 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Uninitialize.
2014-05-21T01:21:25.105Z,1400635285.105 [Default:WaitAtTheSurface:B.GoToSurface] Stopped
2014-05-21T01:21:25.105Z,1400635285.105 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-21T01:21:25.112Z,1400635285.112 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2014-05-21T01:21:25.112Z,1400635285.112 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2014-05-21T01:21:25.113Z,1400635285.113 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2014-05-21T01:21:25.113Z,1400635285.113 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2014-05-21T01:21:25.113Z,1400635285.113 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2014-05-21T01:21:25.114Z,1400635285.114 [BuoyancyServo](INFO): Powering down
2014-05-21T01:21:25.128Z,1400635285.128 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2014-05-21T01:21:25.128Z,1400635285.128 [ElevatorServo](INFO): Powering down
2014-05-21T01:21:25.129Z,1400635285.129 [MassServo](DEBUG): Uninitialize Mass Servo.
2014-05-21T01:21:25.129Z,1400635285.129 [MassServo](INFO): Powering down
2014-05-21T01:21:25.130Z,1400635285.130 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2014-05-21T01:21:25.130Z,1400635285.130 [RudderServo](INFO): Powering down
2014-05-21T01:21:25.131Z,1400635285.131 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2014-05-21T01:21:25.131Z,1400635285.131 [ThrusterServo](INFO): Powering down
2014-05-21T01:21:25.132Z,1400635285.132 [SBIT](DEBUG): Uninitialize SBIT Component.
2014-05-21T01:21:25.132Z,1400635285.132 [IBIT](DEBUG): Uninitialize IBIT Component.
2014-05-21T01:21:25.133Z,1400635285.133 [CBIT](DEBUG): Uninitialize CBIT Component.
2014-05-21T01:21:25.164Z,1400635285.164 [controlThread ThreadHandler](INFO): Thread cancelled.
2014-05-21T01:21:25.181Z,1400635285.181 [Radio_Freewave ThreadHandler](INFO): Thread cancelled.
2014-05-21T01:21:25.263Z,1400635285.263 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-05-21T01:21:25.267Z,1400635285.267 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-05-21T01:21:25.322Z,1400635285.322 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-05-21T01:21:25.366Z,1400635285.366 [logger ThreadHandler](INFO): Thread cancelled.