2014-04-13T16:39:46.725Z,1397407186.725 [Supervisor](DEBUG): Initializing supervisor.
2014-04-13T16:39:46.728Z,1397407186.728 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0
2014-04-13T16:39:46.729Z,1397407186.729 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2014-04-13T16:39:46.730Z,1397407186.730 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0
2014-04-13T16:39:46.733Z,1397407186.733 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2014-04-13T16:39:46.744Z,1397407186.744 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2014-04-13T16:39:46.745Z,1397407186.745 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0
2014-04-13T16:39:46.746Z,1397407186.746 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2014-04-13T16:39:46.747Z,1397407186.747 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0
2014-04-13T16:39:46.749Z,1397407186.749 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2014-04-13T16:39:46.750Z,1397407186.750 [Supervisor](INFO): Looking for Config files in directory: Config/
2014-04-13T16:39:46.751Z,1397407186.751 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2014-04-13T16:39:47.278Z,1397407187.278 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2014-04-13T16:39:47.279Z,1397407187.279 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2014-04-13T16:39:47.565Z,1397407187.565 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2014-04-13T16:39:47.566Z,1397407187.566 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2014-04-13T16:39:47.656Z,1397407187.656 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2014-04-13T16:39:47.657Z,1397407187.657 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2014-04-13T16:39:47.857Z,1397407187.857 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2014-04-13T16:39:47.858Z,1397407187.858 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2014-04-13T16:39:48.019Z,1397407188.019 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2014-04-13T16:39:48.020Z,1397407188.020 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2014-04-13T16:39:48.326Z,1397407188.326 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2014-04-13T16:39:48.327Z,1397407188.327 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2014-04-13T16:39:48.518Z,1397407188.518 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2014-04-13T16:39:48.521Z,1397407188.521 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2014-04-13T16:39:48.861Z,1397407188.861 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2014-04-13T16:39:48.862Z,1397407188.862 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2014-04-13T16:39:48.979Z,1397407188.979 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2014-04-13T16:39:48.980Z,1397407188.980 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2014-04-13T16:39:49.489Z,1397407189.489 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2014-04-13T16:39:49.490Z,1397407189.490 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2014-04-13T16:39:49.603Z,1397407189.603 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2014-04-13T16:39:49.603Z,1397407189.603 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2014-04-13T16:39:49.692Z,1397407189.692 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2014-04-13T16:39:49.801Z,1397407189.801 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2014-04-13T16:39:49.803Z,1397407189.803 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2014-04-13T16:39:49.909Z,1397407189.909 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2014-04-13T16:39:49.910Z,1397407189.910 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2014-04-13T16:39:50.035Z,1397407190.035 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2014-04-13T16:39:50.037Z,1397407190.037 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2014-04-13T16:39:50.038Z,1397407190.038 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2014-04-13T16:39:50.146Z,1397407190.146 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2014-04-13T16:39:50.277Z,1397407190.277 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2014-04-13T16:39:50.380Z,1397407190.380 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2014-04-13T16:39:50.563Z,1397407190.563 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2014-04-13T16:39:50.720Z,1397407190.720 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2014-04-13T16:39:50.841Z,1397407190.841 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2014-04-13T16:39:50.932Z,1397407190.932 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2014-04-13T16:39:51.038Z,1397407191.038 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2014-04-13T16:39:51.141Z,1397407191.141 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2014-04-13T16:39:51.143Z,1397407191.143 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2014-04-13T16:39:51.480Z,1397407191.480 [AHRS_sp3003D] Loaded
2014-04-13T16:39:51.480Z,1397407191.480 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2014-04-13T16:39:51.778Z,1397407191.778 [Batt_Ocean_Server] Loaded
2014-04-13T16:39:51.778Z,1397407191.778 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2014-04-13T16:39:51.792Z,1397407191.792 [Depth_Keller] Loaded
2014-04-13T16:39:51.792Z,1397407191.792 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2014-04-13T16:39:51.798Z,1397407191.798 [DropWeight] Loaded
2014-04-13T16:39:51.798Z,1397407191.798 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2014-04-13T16:39:51.939Z,1397407191.939 [DVL_micro] Loaded
2014-04-13T16:39:51.939Z,1397407191.939 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2014-04-13T16:39:52.041Z,1397407192.041 [NAL9602] Loaded
2014-04-13T16:39:52.041Z,1397407192.041 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2014-04-13T16:39:52.093Z,1397407192.093 [Onboard] Loaded
2014-04-13T16:39:52.094Z,1397407192.094 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2014-04-13T16:39:52.101Z,1397407192.101 [Radio_Freewave] Loaded
2014-04-13T16:39:52.101Z,1397407192.101 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread.
2014-04-13T16:39:52.108Z,1397407192.108 [SCPI] Loaded
2014-04-13T16:39:52.108Z,1397407192.108 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread.
2014-04-13T16:39:52.109Z,1397407192.109 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2014-04-13T16:39:52.109Z,1397407192.109 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2014-04-13T16:39:52.276Z,1397407192.276 [InternalSim] Loaded
2014-04-13T16:39:52.276Z,1397407192.276 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2014-04-13T16:39:52.276Z,1397407192.276 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2014-04-13T16:39:52.277Z,1397407192.277 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2014-04-13T16:39:52.542Z,1397407192.542 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2014-04-13T16:39:52.542Z,1397407192.542 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2014-04-13T16:39:52.548Z,1397407192.548 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator.
2014-04-13T16:39:52.553Z,1397407192.553 [AsyncPiEstimator] Loaded
2014-04-13T16:39:52.554Z,1397407192.554 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread.
2014-04-13T16:39:52.555Z,1397407192.555 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 4069E4E0
2014-04-13T16:39:52.556Z,1397407192.556 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2014-04-13T16:39:52.556Z,1397407192.556 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2014-04-13T16:39:52.637Z,1397407192.637 [DeadReckonUsingMultipleVelocitySources] Loaded
2014-04-13T16:39:52.637Z,1397407192.637 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2014-04-13T16:39:52.654Z,1397407192.654 [NavChart] Loaded
2014-04-13T16:39:52.655Z,1397407192.655 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2014-04-13T16:39:52.655Z,1397407192.655 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2014-04-13T16:39:52.656Z,1397407192.656 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2014-04-13T16:39:52.704Z,1397407192.704 [VerticalControl](DEBUG): Construct VerticalControl.
2014-04-13T16:39:52.817Z,1397407192.817 [VerticalControl] Loaded
2014-04-13T16:39:52.818Z,1397407192.818 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2014-04-13T16:39:52.819Z,1397407192.819 [HorizontalControl](DEBUG): Construct HorizontalControl.
2014-04-13T16:39:52.886Z,1397407192.886 [HorizontalControl] Loaded
2014-04-13T16:39:52.886Z,1397407192.886 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2014-04-13T16:39:52.887Z,1397407192.887 [SpeedControl](DEBUG): Construct SpeedControl.
2014-04-13T16:39:52.889Z,1397407192.889 [SpeedControl] Loaded
2014-04-13T16:39:52.889Z,1397407192.889 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2014-04-13T16:39:52.890Z,1397407192.890 [LoopControl](DEBUG): Construct LoopControl.
2014-04-13T16:39:52.890Z,1397407192.890 [LoopControl] Loaded
2014-04-13T16:39:52.891Z,1397407192.891 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2014-04-13T16:39:52.891Z,1397407192.891 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2014-04-13T16:39:52.892Z,1397407192.892 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2014-04-13T16:39:52.911Z,1397407192.911 [DepthRateCalculator] Loaded
2014-04-13T16:39:52.911Z,1397407192.911 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2014-04-13T16:39:52.916Z,1397407192.916 [PitchRateCalculator] Loaded
2014-04-13T16:39:52.917Z,1397407192.917 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2014-04-13T16:39:52.924Z,1397407192.924 [SpeedCalculator] Loaded
2014-04-13T16:39:52.924Z,1397407192.924 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2014-04-13T16:39:52.930Z,1397407192.930 [YawRateCalculator] Loaded
2014-04-13T16:39:52.930Z,1397407192.930 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2014-04-13T16:39:52.930Z,1397407192.930 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2014-04-13T16:39:52.931Z,1397407192.931 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2014-04-13T16:39:53.037Z,1397407193.037 [CTD_NeilBrown] Loaded
2014-04-13T16:39:53.037Z,1397407193.037 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2014-04-13T16:39:53.038Z,1397407193.038 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 407404E0
2014-04-13T16:39:53.053Z,1397407193.053 [PAR_Licor] Loaded
2014-04-13T16:39:53.054Z,1397407193.054 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2014-04-13T16:39:53.089Z,1397407193.089 [WetLabsBB2FL] Loaded
2014-04-13T16:39:53.089Z,1397407193.089 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2014-04-13T16:39:53.090Z,1397407193.090 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407704E0
2014-04-13T16:39:53.091Z,1397407193.091 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2014-04-13T16:39:53.091Z,1397407193.091 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2014-04-13T16:39:53.185Z,1397407193.185 [SBIT](DEBUG): Construct Startup Built In Test.
2014-04-13T16:39:53.198Z,1397407193.198 [SBIT] Loaded
2014-04-13T16:39:53.198Z,1397407193.198 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2014-04-13T16:39:53.199Z,1397407193.199 [IBIT](DEBUG): Construct Initiated Built In Test.
2014-04-13T16:39:53.211Z,1397407193.211 [IBIT] Loaded
2014-04-13T16:39:53.211Z,1397407193.211 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2014-04-13T16:39:53.213Z,1397407193.213 [CBIT](DEBUG): Construct CBIT Built In Test.
2014-04-13T16:39:53.282Z,1397407193.282 [CBIT] Loaded
2014-04-13T16:39:53.282Z,1397407193.282 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2014-04-13T16:39:53.283Z,1397407193.283 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2014-04-13T16:39:53.283Z,1397407193.283 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2014-04-13T16:39:53.324Z,1397407193.324 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2014-04-13T16:39:53.325Z,1397407193.325 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2014-04-13T16:39:53.422Z,1397407193.422 [BuoyancyServo] Loaded
2014-04-13T16:39:53.422Z,1397407193.422 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2014-04-13T16:39:53.435Z,1397407193.435 [ElevatorServo] Loaded
2014-04-13T16:39:53.435Z,1397407193.435 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2014-04-13T16:39:53.446Z,1397407193.446 [MassServo] Loaded
2014-04-13T16:39:53.447Z,1397407193.447 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2014-04-13T16:39:53.458Z,1397407193.458 [RudderServo] Loaded
2014-04-13T16:39:53.459Z,1397407193.459 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2014-04-13T16:39:53.470Z,1397407193.470 [ThrusterServo] Loaded
2014-04-13T16:39:53.471Z,1397407193.471 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2014-04-13T16:39:53.471Z,1397407193.471 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2014-04-13T16:39:53.472Z,1397407193.472 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2014-04-13T16:39:53.496Z,1397407193.496 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2014-04-13T16:39:53.498Z,1397407193.498 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2014-04-13T16:39:53.499Z,1397407193.499 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2014-04-13T16:39:53.505Z,1397407193.505 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2014-04-13T16:39:53.507Z,1397407193.507 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 4083E4E0
2014-04-13T16:39:53.511Z,1397407193.511 [Supervisor](DEBUG): Running supervisor.
2014-04-13T16:39:53.512Z,1397407193.512 [CommandLine](INFO): Thread ID is 2974
2014-04-13T16:39:53.516Z,1397407193.516 [controlThread](INFO): Thread ID is 2973
2014-04-13T16:39:53.516Z,1397407193.516 [controlThread](DEBUG): Initializing ControlThread
2014-04-13T16:39:53.516Z,1397407193.516 [CycleStarter](INFO): Thread ID is 2972
2014-04-13T16:39:53.519Z,1397407193.519 [logger](INFO): Thread ID is 2975
2014-04-13T16:39:53.544Z,1397407193.544 [AsyncPiEstimator](INFO): Thread ID is 3049
2014-04-13T16:39:53.544Z,1397407193.544 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator.
2014-04-13T16:39:53.568Z,1397407193.568 [CTD_NeilBrown](INFO): Thread ID is 3050
2014-04-13T16:39:53.568Z,1397407193.568 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2014-04-13T16:39:53.572Z,1397407193.572 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2014-04-13T16:39:53.582Z,1397407193.582 [WetLabsBB2FL](INFO): Thread ID is 3051
2014-04-13T16:39:53.583Z,1397407193.583 [WetLabsBB2FL](INFO): Powering down
2014-04-13T16:39:53.604Z,1397407193.604 [NavChartDb](INFO): Thread ID is 3052
2014-04-13T16:39:53.609Z,1397407193.609 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2014-04-13T16:39:53.612Z,1397407193.612 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2014-04-13T16:39:53.612Z,1397407193.612 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2014-04-13T16:39:53.612Z,1397407193.612 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2014-04-13T16:39:53.613Z,1397407193.613 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2014-04-13T16:39:53.613Z,1397407193.613 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2014-04-13T16:39:53.613Z,1397407193.613 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2014-04-13T16:39:53.613Z,1397407193.613 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2014-04-13T16:39:53.614Z,1397407193.614 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2014-04-13T16:39:55.181Z,1397407195.181 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2014-04-13T16:39:55.213Z,1397407195.213 [InternalSim](DEBUG):  InternalSim initializing...
2014-04-13T16:39:55.317Z,1397407195.317 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2014-04-13T16:39:55.317Z,1397407195.317 [NavChart](DEBUG): Initialize NavChart Navigation.
2014-04-13T16:39:55.318Z,1397407195.318 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2014-04-13T16:39:55.319Z,1397407195.319 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2014-04-13T16:39:55.320Z,1397407195.320 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2014-04-13T16:39:55.321Z,1397407195.321 [LoopControl](DEBUG): Initialize LoopControlComponent.
2014-04-13T16:39:55.321Z,1397407195.321 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2014-04-13T16:39:55.321Z,1397407195.321 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2014-04-13T16:39:55.338Z,1397407195.338 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2014-04-13T16:39:55.338Z,1397407195.338 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2014-04-13T16:39:55.339Z,1397407195.339 [SBIT](INFO): Initialize SBIT Component.
2014-04-13T16:39:55.340Z,1397407195.340 [SBIT](IMPORTANT): Tethys CM Info: 
 $Rev:11196
2014-04-13T16:39:55.340Z,1397407195.340 [SBIT](IMPORTANT): Kernel Release:2.6.27.8
2014-04-13T16:39:55.341Z,1397407195.341 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2014-04-13T16:39:55.341Z,1397407195.341 [IBIT](INFO): Initialize IBIT Component.
2014-04-13T16:39:55.350Z,1397407195.350 [CBIT](DEBUG): Initialize CBIT Component.
2014-04-13T16:39:55.351Z,1397407195.351 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2014-04-13T16:39:55.376Z,1397407195.376 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2014-04-13T16:39:55.396Z,1397407195.396 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2014-04-13T16:39:55.440Z,1397407195.440 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://aosn.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

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

    <Aggregate Id="StartupSatComms">

        <Sequence/>

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

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

    </Aggregate>

</Mission>


2014-04-13T16:39:55.441Z,1397407195.441 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2014-04-13T16:39:55.518Z,1397407195.518 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2014-04-13T16:39:55.521Z,1397407195.521 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2014-04-13T16:39:55.556Z,1397407195.556 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-04-13T16:39:55.576Z,1397407195.576 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2014-04-13T16:39:55.580Z,1397407195.580 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-04-13T16:39:55.599Z,1397407195.599 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2014-04-13T16:39:55.617Z,1397407195.617 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Construct.
2014-04-13T16:39:55.620Z,1397407195.620 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-04-13T16:39:55.677Z,1397407195.677 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
xmlns:Control="Tethys/Control"
xmlns:Guidance="Tethys/Guidance" 
xmlns:Units="Tethys/Units"
xmlns:Universal="Tethys/Universal"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="Tethys http://aosn.mbari.org/tethys/Xml/Tethys.xsd
Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
Id="Default">

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

    <Aggregate Id="GPS">

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

<!-- Run at high speed -->

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

<!-- Get to the surface -->

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

<!-- Get GPS fix -->

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

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

    </Aggregate>

    <Aggregate Id="Iridium">

        <Sequence/>

<!-- Run at high speed -->

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

<!-- Get to the surface -->

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

<!-- Do data comms -->

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

    </Aggregate>

    <Aggregate Id="CallIridium">

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

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

        <Call RefId="Iridium"/>

    </Aggregate>

    <Aggregate Id="WaitAtTheSurface">

        <Sequence/>

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

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

    </Aggregate>

</Mission>


2014-04-13T16:39:55.682Z,1397407195.682 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,Radio_Freewave,SCPI,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2014-04-13T16:39:55.718Z,1397407195.718 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2014-04-13T16:39:55.905Z,1397407195.905 [DVL_micro](INFO): Initializing
2014-04-13T16:39:56.004Z,1397407196.004 [Radio_Freewave](INFO): Powering up
2014-04-13T16:39:56.282Z,1397407196.282 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:39:56.409Z,1397407196.409 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2014-04-13T16:39:56.416Z,1397407196.416 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2014-04-13T16:39:56.455Z,1397407196.455 [ElevatorServo](DEBUG): Initializing EZServoServo.
2014-04-13T16:39:56.460Z,1397407196.460 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2014-04-13T16:39:56.481Z,1397407196.481 [MassServo](DEBUG): Initializing EZServoServo.
2014-04-13T16:39:56.481Z,1397407196.481 [MassServo](DEBUG): Initializing MassServo.
2014-04-13T16:39:56.488Z,1397407196.488 [RudderServo](DEBUG): Initializing EZServoServo.
2014-04-13T16:39:56.492Z,1397407196.492 [RudderServo](DEBUG): Initializing RudderServo.
2014-04-13T16:39:56.498Z,1397407196.498 [ThrusterServo](DEBUG): Initializing EZServoServo.
2014-04-13T16:39:56.504Z,1397407196.504 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2014-04-13T16:39:56.846Z,1397407196.846 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:39:57.348Z,1397407197.348 [NAL9602](INFO): Powering up NAL9602
2014-04-13T16:39:57.444Z,1397407197.444 [Radio_Freewave](IMPORTANT): Starting PPPD with command:/sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0
2014-04-13T16:39:57.515Z,1397407197.515 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:39:58.355Z,1397407198.355 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:39:58.782Z,1397407198.782 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:39:59.267Z,1397407199.267 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:39:59.855Z,1397407199.855 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:00.304Z,1397407200.304 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:01.059Z,1397407201.059 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:01.752Z,1397407201.752 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:02.288Z,1397407202.288 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:02.720Z,1397407202.720 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:03.208Z,1397407203.208 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:03.711Z,1397407203.711 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:04.174Z,1397407204.174 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:04.647Z,1397407204.647 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:05.283Z,1397407205.283 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:05.984Z,1397407205.984 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:06.569Z,1397407206.569 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:07.077Z,1397407207.077 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:07.591Z,1397407207.591 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:08.058Z,1397407208.058 [NAL9602](INFO): NAL9602 initialized
2014-04-13T16:40:08.108Z,1397407208.108 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:08.796Z,1397407208.796 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:09.282Z,1397407209.282 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:09.859Z,1397407209.859 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:10.316Z,1397407210.316 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:10.952Z,1397407210.952 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:11.008Z,1397407211.008 [SBIT](IMPORTANT): Beginning Startup BIT
2014-04-13T16:40:11.011Z,1397407211.011 [CBIT](IMPORTANT): Beginning GF scan
2014-04-13T16:40:11.542Z,1397407211.542 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:12.085Z,1397407212.085 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:12.517Z,1397407212.517 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:12.964Z,1397407212.964 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:13.460Z,1397407213.460 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:14.033Z,1397407214.033 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:14.557Z,1397407214.557 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:15.159Z,1397407215.159 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:15.659Z,1397407215.659 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:16.339Z,1397407216.339 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:16.974Z,1397407216.974 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:17.452Z,1397407217.452 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:17.927Z,1397407217.927 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:18.448Z,1397407218.448 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:18.952Z,1397407218.952 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:19.512Z,1397407219.512 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:20.015Z,1397407220.015 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:20.467Z,1397407220.467 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:20.940Z,1397407220.940 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:21.560Z,1397407221.560 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:22.050Z,1397407222.050 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:22.538Z,1397407222.538 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:23.094Z,1397407223.094 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:23.543Z,1397407223.543 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:23.931Z,1397407223.931 [NAL9602](INFO): SBD MO Status=0, MOMSN=25429, MT Status=0, MTMSN=0
2014-04-13T16:40:23.931Z,1397407223.931 [NAL9602](INFO): No messages in MT queue
2014-04-13T16:40:23.959Z,1397407223.959 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:24.394Z,1397407224.394 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:24.922Z,1397407224.922 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:25.373Z,1397407225.373 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:25.831Z,1397407225.831 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:26.334Z,1397407226.334 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:26.909Z,1397407226.909 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:27.871Z,1397407227.871 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:28.459Z,1397407228.459 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:28.976Z,1397407228.976 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:29.541Z,1397407229.541 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:30.061Z,1397407230.061 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:30.627Z,1397407230.627 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:31.147Z,1397407231.147 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:31.853Z,1397407231.853 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:32.369Z,1397407232.369 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:33.032Z,1397407233.032 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:33.510Z,1397407233.510 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:33.952Z,1397407233.952 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:34.449Z,1397407234.449 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:34.957Z,1397407234.957 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:35.423Z,1397407235.423 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:35.915Z,1397407235.915 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:36.417Z,1397407236.417 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:37.036Z,1397407237.036 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:37.508Z,1397407237.508 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:38.034Z,1397407238.034 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:38.517Z,1397407238.517 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:38.586Z,1397407238.586 [CBIT](IMPORTANT): No ground fault detected
2014-04-13T16:40:38.987Z,1397407238.987 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2014-04-13T16:40:39.398Z,1397407239.398 [NAL9602](IMPORTANT): GPS fix at: 1397407201.00
2014-04-13T16:40:39.448Z,1397407239.448 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07
2014-04-13T16:40:46.732Z,1397407246.732 [NAL9602](INFO): Powering down
2014-04-13T16:41:05.309Z,1397407265.309 [SBIT](IMPORTANT): SBIT PASSED
2014-04-13T16:41:05.720Z,1397407265.720 [MissionManager](IMPORTANT): Started mission Startup
2014-04-13T16:41:05.720Z,1397407265.720 [Startup] Running Loop=1
2014-04-13T16:41:05.721Z,1397407265.721 [Startup](INFO): Aggregate::initialize Startup
2014-04-13T16:41:05.721Z,1397407265.721 [Startup:A.GoToSurface] Running Loop=1
2014-04-13T16:41:05.721Z,1397407265.721 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-13T16:41:05.729Z,1397407265.729 [Startup:StartupSatComms] Running Loop=1
2014-04-13T16:41:05.729Z,1397407265.729 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2014-04-13T16:41:05.729Z,1397407265.729 [Startup:StartupSatComms:A] Running Loop=1
2014-04-13T16:41:06.156Z,1397407266.156 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2014-04-13T16:41:06.565Z,1397407266.565 [NAL9602](INFO): Powering up
2014-04-13T16:41:17.341Z,1397407277.341 [NAL9602](INFO): NAL9602 initialized
2014-04-13T16:41:36.642Z,1397407296.642 [NAL9602](INFO): SBD MO Status=0, MOMSN=25430, MT Status=0, MTMSN=0
2014-04-13T16:41:36.642Z,1397407296.642 [NAL9602](INFO): No messages in MT queue
2014-04-13T16:41:41.059Z,1397407301.059 [NAL9602](IMPORTANT): GPS fix at: 1397407263.00
2014-04-13T16:41:41.073Z,1397407301.073 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07
2014-04-13T16:41:41.075Z,1397407301.075 [Startup:StartupSatComms:A] Stopped
2014-04-13T16:41:41.075Z,1397407301.075 [Startup:StartupSatComms:B] Running Loop=1
2014-04-13T16:41:41.539Z,1397407301.539 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2014-04-13T16:41:59.648Z,1397407319.648 [NAL9602](INFO): SBD MO Status=1, MOMSN=25431, MT Status=0, MTMSN=0
2014-04-13T16:41:59.699Z,1397407319.699 [NAL9602](INFO): Sent 73 bytes from file Logs/20140413T132323/Courier0076.lzma
2014-04-13T16:41:59.699Z,1397407319.699 [NAL9602](INFO): Packets left to send: 0
2014-04-13T16:41:59.701Z,1397407319.701 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Courier0076.lzma.parts/0000.sbd
2014-04-13T16:41:59.701Z,1397407319.701 [NAL9602](INFO): Completed sending Logs/20140413T132323/Courier0076.lzma
2014-04-13T16:42:06.945Z,1397407326.945 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 43 of 46
2014-04-13T16:42:06.945Z,1397407326.945 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 -2616 -1511 -1450 -1308 2 2 2 2 -1556.2 -270.9 -1856.5 2 167.1 -1570.6 -1856.5 2 -1556 -270 -1856 2 167 -1570 -1856 2 -5.44 -6.85 86.2 -3.0 15.8 0.005 35.0 1489 112
2014-04-13T16:42:09.406Z,1397407329.406 [NAL9602](INFO): SBD MO Status=1, MOMSN=25432, MT Status=0, MTMSN=0
2014-04-13T16:42:09.454Z,1397407329.454 [NAL9602](INFO): Sent 294 bytes from file Logs/20140413T163946/Courier0000.lzma
2014-04-13T16:42:09.454Z,1397407329.454 [NAL9602](INFO): Packets left to send: 0
2014-04-13T16:42:09.456Z,1397407329.456 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T163946/Courier0000.lzma.parts/0000.sbd
2014-04-13T16:42:09.456Z,1397407329.456 [NAL9602](INFO): Completed sending Logs/20140413T163946/Courier0000.lzma
2014-04-13T16:42:22.322Z,1397407342.322 [NAL9602](INFO): SBD MO Status=1, MOMSN=25433, MT Status=0, MTMSN=0
2014-04-13T16:42:22.370Z,1397407342.370 [NAL9602](INFO): Sent 215 bytes from file Logs/20140413T132323/Express0073.lzma
2014-04-13T16:42:22.370Z,1397407342.370 [NAL9602](INFO): Packets left to send: 0
2014-04-13T16:42:22.372Z,1397407342.372 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Express0073.lzma.parts/0000.sbd
2014-04-13T16:42:22.372Z,1397407342.372 [NAL9602](INFO): Completed sending Logs/20140413T132323/Express0073.lzma
2014-04-13T16:42:35.947Z,1397407355.947 [NAL9602](INFO): SBD MO Status=1, MOMSN=25434, MT Status=0, MTMSN=0
2014-04-13T16:42:35.991Z,1397407355.991 [NAL9602](INFO): Sent 199 bytes from file Logs/20140413T132323/Express0077.lzma
2014-04-13T16:42:35.992Z,1397407355.992 [NAL9602](INFO): Packets left to send: 0
2014-04-13T16:42:35.993Z,1397407355.993 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T132323/Express0077.lzma.parts/0000.sbd
2014-04-13T16:42:35.994Z,1397407355.994 [NAL9602](INFO): Completed sending Logs/20140413T132323/Express0077.lzma
2014-04-13T16:42:41.475Z,1397407361.475 [Startup:StartupSatComms:B](INFO): Timed out from 2014-04-13T16:41:41.1Z
2014-04-13T16:42:41.475Z,1397407361.475 [Startup:StartupSatComms:B] Stopped
2014-04-13T16:42:41.491Z,1397407361.491 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2014-04-13T16:42:41.491Z,1397407361.491 [Startup:StartupSatComms] Stopped
2014-04-13T16:42:41.492Z,1397407361.492 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2014-04-13T16:42:41.493Z,1397407361.493 [Startup](INFO): Completed Startup
2014-04-13T16:42:41.493Z,1397407361.493 [Startup] Stopped
2014-04-13T16:42:41.493Z,1397407361.493 [Startup](INFO): Aggregate::uninitialize Startup
2014-04-13T16:42:41.493Z,1397407361.493 [Startup:A.GoToSurface] Stopped
2014-04-13T16:42:41.493Z,1397407361.493 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-13T16:42:41.914Z,1397407361.914 [MissionManager](IMPORTANT): Started mission Default
2014-04-13T16:42:41.914Z,1397407361.914 [Default] Running Loop=1
2014-04-13T16:42:41.914Z,1397407361.914 [Default](INFO): Aggregate::initialize Default
2014-04-13T16:42:41.914Z,1397407361.914 [Default:Iridium] Running Loop=1
2014-04-13T16:42:41.914Z,1397407361.914 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-04-13T16:42:41.914Z,1397407361.914 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-04-13T16:42:41.914Z,1397407361.914 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-04-13T16:42:41.915Z,1397407361.915 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-04-13T16:42:41.915Z,1397407361.915 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-13T16:42:41.915Z,1397407361.915 [Default:CallIridium] Running Loop=1
2014-04-13T16:42:41.915Z,1397407361.915 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-04-13T16:42:41.915Z,1397407361.915 [Default:CallIridium:A] Running Loop=1
2014-04-13T16:42:41.922Z,1397407361.922 [Default:CallIridium:A] Stopped
2014-04-13T16:42:41.922Z,1397407361.922 [Default:CallIridium:B] Running Loop=1
2014-04-13T16:42:41.922Z,1397407361.922 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-04-13T16:42:41.931Z,1397407361.931 [Default:Iridium:B.GoToSurface] Stopped
2014-04-13T16:42:41.931Z,1397407361.931 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-13T16:42:41.931Z,1397407361.931 [Default:Iridium:Read_Iridium] Running Loop=1
2014-04-13T16:42:41.931Z,1397407361.931 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-04-13T16:42:41.937Z,1397407361.937 [Default:GPS] Running Loop=1
2014-04-13T16:42:41.937Z,1397407361.937 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-04-13T16:42:41.937Z,1397407361.937 [Default:GPS:A.SetSpeed] Running Loop=1
2014-04-13T16:42:41.937Z,1397407361.937 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-04-13T16:42:41.937Z,1397407361.937 [Default:GPS:B.GoToSurface] Running Loop=1
2014-04-13T16:42:41.937Z,1397407361.937 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-13T16:42:41.943Z,1397407361.943 [Default:GPS:B.GoToSurface] Stopped
2014-04-13T16:42:41.943Z,1397407361.943 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-13T16:42:41.943Z,1397407361.943 [Default:GPS:Read_GPS] Running Loop=1
2014-04-13T16:42:41.943Z,1397407361.943 [Default:GPS:A.SetSpeed] Running Loop=1
2014-04-13T16:42:42.352Z,1397407362.352 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2014-04-13T16:42:42.355Z,1397407362.355 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2014-04-13T16:42:46.047Z,1397407366.047 [NAL9602](INFO): SBD MO Status=1, MOMSN=25435, MT Status=0, MTMSN=0
2014-04-13T16:42:46.107Z,1397407366.107 [NAL9602](INFO): Sent 332 bytes from file Logs/20140413T163946/Express0001.lzma
2014-04-13T16:42:46.107Z,1397407366.107 [NAL9602](INFO): Packets left to send: 2
2014-04-13T16:42:46.109Z,1397407366.109 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T163946/Express0001.lzma.parts/0002.sbd
2014-04-13T16:42:57.467Z,1397407377.467 [NAL9602](INFO): SBD MO Status=1, MOMSN=25436, MT Status=0, MTMSN=0
2014-04-13T16:42:57.517Z,1397407377.517 [NAL9602](INFO): Sent 77 bytes from file Logs/20140413T163946/Courier0004.lzma
2014-04-13T16:42:57.517Z,1397407377.517 [NAL9602](INFO): Packets left to send: 0
2014-04-13T16:42:57.519Z,1397407377.519 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T163946/Courier0004.lzma.parts/0000.sbd
2014-04-13T16:42:57.519Z,1397407377.519 [NAL9602](INFO): Completed sending Logs/20140413T163946/Courier0004.lzma
2014-04-13T16:43:01.616Z,1397407381.616 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T16:43:01.616Z,1397407381.616 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T16:43:01.617Z,1397407381.617 [DVL_micro](ERROR): Data Fault
2014-04-13T16:43:01.648Z,1397407381.648 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T16:43:02.017Z,1397407382.017 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T16:43:02.543Z,1397407382.543 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T16:43:02.543Z,1397407382.543 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T16:43:02.543Z,1397407382.543 [DVL_micro](ERROR): Hardware Fault
2014-04-13T16:43:02.975Z,1397407382.975 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T16:43:02.975Z,1397407382.975 [DVL_micro] No Fault, FailCount= 1
2014-04-13T16:43:03.349Z,1397407383.349 [DVL_micro](INFO): Initializing
2014-04-13T16:43:09.697Z,1397407389.697 [NAL9602](INFO): SBD MO Status=1, MOMSN=25437, MT Status=0, MTMSN=0
2014-04-13T16:43:09.748Z,1397407389.748 [NAL9602](INFO): Sent 332 bytes from file Logs/20140413T163946/Express0001.lzma
2014-04-13T16:43:09.748Z,1397407389.748 [NAL9602](INFO): Packets left to send: 1
2014-04-13T16:43:09.750Z,1397407389.750 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T163946/Express0001.lzma.parts/0001.sbd
2014-04-13T16:43:20.766Z,1397407400.766 [NAL9602](INFO): SBD MO Status=1, MOMSN=25438, MT Status=0, MTMSN=0
2014-04-13T16:43:20.817Z,1397407400.817 [NAL9602](INFO): Sent 2 bytes from file Logs/20140413T163946/Express0001.lzma
2014-04-13T16:43:20.817Z,1397407400.817 [NAL9602](INFO): Packets left to send: 0
2014-04-13T16:43:20.818Z,1397407400.818 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T163946/Express0001.lzma.parts/0000.sbd
2014-04-13T16:43:20.818Z,1397407400.818 [NAL9602](INFO): Completed sending Logs/20140413T163946/Express0001.lzma
2014-04-13T16:43:28.972Z,1397407408.972 [NAL9602](INFO): SBD MO Status=1, MOMSN=25439, MT Status=0, MTMSN=0
2014-04-13T16:43:29.022Z,1397407409.022 [NAL9602](INFO): Sent 145 bytes from file Logs/20140413T163946/Express0005.lzma
2014-04-13T16:43:29.022Z,1397407409.022 [NAL9602](INFO): Packets left to send: 0
2014-04-13T16:43:29.023Z,1397407409.023 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T163946/Express0005.lzma.parts/0000.sbd
2014-04-13T16:43:29.024Z,1397407409.024 [NAL9602](INFO): Completed sending Logs/20140413T163946/Express0005.lzma
2014-04-13T16:43:36.820Z,1397407416.820 [NAL9602](INFO): SBD MO Status=0, MOMSN=25440, MT Status=0, MTMSN=0
2014-04-13T16:43:36.930Z,1397407416.930 [Default:Iridium:Read_Iridium] Stopped
2014-04-13T16:43:36.930Z,1397407416.930 [Default:Iridium](INFO): Completed Default:Iridium
2014-04-13T16:43:36.930Z,1397407416.930 [Default:Iridium] Stopped
2014-04-13T16:43:36.930Z,1397407416.930 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-04-13T16:43:36.930Z,1397407416.930 [Default:Iridium:A.SetSpeed] Stopped
2014-04-13T16:43:36.930Z,1397407416.930 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-04-13T16:43:36.931Z,1397407416.931 [Default:WaitAtTheSurface] Running Loop=1
2014-04-13T16:43:36.931Z,1397407416.931 [Default:WaitAtTheSurface](INFO): Aggregate::initialize Default:WaitAtTheSurface
2014-04-13T16:43:36.931Z,1397407416.931 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Running Loop=1
2014-04-13T16:43:36.931Z,1397407416.931 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Initialize.
2014-04-13T16:43:36.931Z,1397407416.931 [Default:WaitAtTheSurface:B.GoToSurface] Running Loop=1
2014-04-13T16:43:36.931Z,1397407416.931 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-13T16:43:37.342Z,1397407417.342 [Default:WaitAtTheSurface:B.GoToSurface] Running Loop=1
2014-04-13T16:43:37.347Z,1397407417.347 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Running Loop=1
2014-04-13T16:43:37.353Z,1397407417.353 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-04-13T16:43:37.353Z,1397407417.353 [Default:CallIridium:B] Stopped
2014-04-13T16:43:37.353Z,1397407417.353 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-04-13T16:43:37.353Z,1397407417.353 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-04-13T16:43:37.353Z,1397407417.353 [Default:CallIridium] Stopped
2014-04-13T16:43:37.353Z,1397407417.353 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-04-13T16:43:38.202Z,1397407418.202 [NAL9602](IMPORTANT): GPS fix at: 1397407380.00
2014-04-13T16:43:38.229Z,1397407418.229 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07
2014-04-13T16:43:38.233Z,1397407418.233 [Default:GPS:Read_GPS] Stopped
2014-04-13T16:43:38.233Z,1397407418.233 [Default:GPS:D] Running Loop=1
2014-04-13T16:43:38.773Z,1397407418.773 [Default:GPS:D] Stopped
2014-04-13T16:43:38.773Z,1397407418.773 [Default:GPS](INFO): Completed Default:GPS
2014-04-13T16:43:38.773Z,1397407418.773 [Default:GPS] Stopped
2014-04-13T16:43:38.773Z,1397407418.773 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-04-13T16:43:38.774Z,1397407418.774 [Default:GPS:A.SetSpeed] Stopped
2014-04-13T16:43:38.774Z,1397407418.774 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-04-13T16:43:59.315Z,1397407439.315 [NAL9602](INFO): Powering down
2014-04-13T16:46:14.352Z,1397407574.352 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T16:46:14.352Z,1397407574.352 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T16:46:14.352Z,1397407574.352 [DVL_micro](ERROR): Data Fault
2014-04-13T16:46:14.416Z,1397407574.416 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T16:46:19.460Z,1397407579.460 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T16:46:24.354Z,1397407584.354 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T16:46:24.355Z,1397407584.355 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T16:46:24.355Z,1397407584.355 [DVL_micro](ERROR): Hardware Fault
2014-04-13T16:46:29.418Z,1397407589.418 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T16:46:29.418Z,1397407589.418 [DVL_micro] No Fault, FailCount= 1
2014-04-13T16:46:34.368Z,1397407594.368 [DVL_micro](INFO): Initializing
2014-04-13T16:48:39.407Z,1397407719.407 [Default:CallIridium] Running Loop=1
2014-04-13T16:48:39.407Z,1397407719.407 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-04-13T16:48:39.407Z,1397407719.407 [Default:CallIridium:A] Running Loop=1
2014-04-13T16:48:39.407Z,1397407719.407 [Default:CallIridium:A] Stopped
2014-04-13T16:48:39.407Z,1397407719.407 [Default:CallIridium:B] Running Loop=1
2014-04-13T16:48:39.407Z,1397407719.407 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-04-13T16:48:44.465Z,1397407724.465 [Default:Iridium] Running Loop=1
2014-04-13T16:48:44.466Z,1397407724.466 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-04-13T16:48:44.466Z,1397407724.466 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-04-13T16:48:44.466Z,1397407724.466 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-04-13T16:48:44.466Z,1397407724.466 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-04-13T16:48:44.466Z,1397407724.466 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-13T16:48:44.467Z,1397407724.467 [Default:Iridium:B.GoToSurface] Stopped
2014-04-13T16:48:44.467Z,1397407724.467 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-13T16:48:44.467Z,1397407724.467 [Default:Iridium:Read_Iridium] Running Loop=1
2014-04-13T16:48:44.467Z,1397407724.467 [Default:GPS] Running Loop=1
2014-04-13T16:48:44.467Z,1397407724.467 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-04-13T16:48:44.468Z,1397407724.468 [Default:GPS:A.SetSpeed] Running Loop=1
2014-04-13T16:48:44.468Z,1397407724.468 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-04-13T16:48:44.468Z,1397407724.468 [Default:GPS:B.GoToSurface] Running Loop=1
2014-04-13T16:48:44.468Z,1397407724.468 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-13T16:48:44.469Z,1397407724.469 [Default:GPS:B.GoToSurface] Stopped
2014-04-13T16:48:44.469Z,1397407724.469 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-13T16:48:44.469Z,1397407724.469 [Default:GPS:Read_GPS] Running Loop=1
2014-04-13T16:48:45.995Z,1397407725.995 [NAL9602](INFO): Powering up
2014-04-13T16:48:56.645Z,1397407736.645 [NAL9602](INFO): NAL9602 initialized
2014-04-13T16:49:12.970Z,1397407752.970 [NAL9602](INFO): SBD MO Status=2, MOMSN=25441, MT Status=2, MTMSN=0
2014-04-13T16:49:12.971Z,1397407752.971 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-04-13T16:49:14.375Z,1397407754.375 [NAL9602](IMPORTANT): GPS fix at: 1397407716.00
2014-04-13T16:49:14.417Z,1397407754.417 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07
2014-04-13T16:49:14.425Z,1397407754.425 [Default:GPS:Read_GPS] Stopped
2014-04-13T16:49:14.426Z,1397407754.426 [Default:GPS:D] Running Loop=1
2014-04-13T16:49:14.953Z,1397407754.953 [Default:GPS:D] Stopped
2014-04-13T16:49:14.953Z,1397407754.953 [Default:GPS](INFO): Completed Default:GPS
2014-04-13T16:49:14.953Z,1397407754.953 [Default:GPS] Stopped
2014-04-13T16:49:14.954Z,1397407754.954 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-04-13T16:49:14.954Z,1397407754.954 [Default:GPS:A.SetSpeed] Stopped
2014-04-13T16:49:14.954Z,1397407754.954 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-04-13T16:49:54.713Z,1397407794.713 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T16:49:54.713Z,1397407794.713 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T16:49:54.713Z,1397407794.713 [DVL_micro](ERROR): Data Fault
2014-04-13T16:49:55.249Z,1397407795.249 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T16:49:55.667Z,1397407795.667 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T16:49:56.472Z,1397407796.472 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T16:49:56.472Z,1397407796.472 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T16:49:56.472Z,1397407796.472 [DVL_micro](ERROR): Hardware Fault
2014-04-13T16:49:56.922Z,1397407796.922 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T16:49:56.922Z,1397407796.922 [DVL_micro] No Fault, FailCount= 1
2014-04-13T16:49:57.314Z,1397407797.314 [DVL_micro](INFO): Initializing
2014-04-13T16:50:29.706Z,1397407829.706 [NAL9602](INFO): SBD MO Status=1, MOMSN=25441, MT Status=0, MTMSN=0
2014-04-13T16:50:29.754Z,1397407829.754 [NAL9602](INFO): Sent 77 bytes from file Logs/20140413T163946/Courier0008.lzma
2014-04-13T16:50:29.754Z,1397407829.754 [NAL9602](INFO): Packets left to send: 0
2014-04-13T16:50:29.755Z,1397407829.755 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T163946/Courier0008.lzma.parts/0000.sbd
2014-04-13T16:50:29.756Z,1397407829.756 [NAL9602](INFO): Completed sending Logs/20140413T163946/Courier0008.lzma
2014-04-13T16:50:47.097Z,1397407847.097 [NAL9602](INFO): SBD MO Status=1, MOMSN=25442, MT Status=0, MTMSN=0
2014-04-13T16:50:47.145Z,1397407847.145 [NAL9602](INFO): Sent 253 bytes from file Logs/20140413T163946/Express0009.lzma
2014-04-13T16:50:47.145Z,1397407847.145 [NAL9602](INFO): Packets left to send: 0
2014-04-13T16:50:47.147Z,1397407847.147 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T163946/Express0009.lzma.parts/0000.sbd
2014-04-13T16:50:47.147Z,1397407847.147 [NAL9602](INFO): Completed sending Logs/20140413T163946/Express0009.lzma
2014-04-13T16:50:57.718Z,1397407857.718 [NAL9602](INFO): SBD MO Status=0, MOMSN=25443, MT Status=0, MTMSN=0
2014-04-13T16:50:57.823Z,1397407857.823 [Default:Iridium:Read_Iridium] Stopped
2014-04-13T16:50:57.823Z,1397407857.823 [Default:Iridium](INFO): Completed Default:Iridium
2014-04-13T16:50:57.824Z,1397407857.824 [Default:Iridium] Stopped
2014-04-13T16:50:57.824Z,1397407857.824 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-04-13T16:50:57.824Z,1397407857.824 [Default:Iridium:A.SetSpeed] Stopped
2014-04-13T16:50:57.824Z,1397407857.824 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-04-13T16:50:58.229Z,1397407858.229 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-04-13T16:50:58.229Z,1397407858.229 [Default:CallIridium:B] Stopped
2014-04-13T16:50:58.229Z,1397407858.229 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-04-13T16:50:58.229Z,1397407858.229 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-04-13T16:50:58.229Z,1397407858.229 [Default:CallIridium] Stopped
2014-04-13T16:50:58.233Z,1397407858.233 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-04-13T16:51:08.400Z,1397407868.400 [NAL9602](INFO): Powering down
2014-04-13T16:53:03.437Z,1397407983.437 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T16:53:03.437Z,1397407983.437 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T16:53:03.437Z,1397407983.437 [DVL_micro](ERROR): Data Fault
2014-04-13T16:53:03.465Z,1397407983.465 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T16:53:08.382Z,1397407988.382 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T16:53:13.425Z,1397407993.425 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T16:53:13.425Z,1397407993.425 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T16:53:13.425Z,1397407993.425 [DVL_micro](ERROR): Hardware Fault
2014-04-13T16:53:18.452Z,1397407998.452 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T16:53:18.453Z,1397407998.453 [DVL_micro] No Fault, FailCount= 1
2014-04-13T16:53:23.430Z,1397408003.430 [DVL_micro](INFO): Initializing
2014-04-13T16:55:58.426Z,1397408158.426 [Default:CallIridium] Running Loop=1
2014-04-13T16:55:58.426Z,1397408158.426 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-04-13T16:55:58.426Z,1397408158.426 [Default:CallIridium:A] Running Loop=1
2014-04-13T16:55:58.426Z,1397408158.426 [Default:CallIridium:A] Stopped
2014-04-13T16:55:58.427Z,1397408158.427 [Default:CallIridium:B] Running Loop=1
2014-04-13T16:55:58.427Z,1397408158.427 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-04-13T16:56:03.457Z,1397408163.457 [Default:Iridium] Running Loop=1
2014-04-13T16:56:03.457Z,1397408163.457 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-04-13T16:56:03.457Z,1397408163.457 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-04-13T16:56:03.457Z,1397408163.457 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-04-13T16:56:03.457Z,1397408163.457 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-04-13T16:56:03.457Z,1397408163.457 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-13T16:56:03.458Z,1397408163.458 [Default:Iridium:B.GoToSurface] Stopped
2014-04-13T16:56:03.458Z,1397408163.458 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-13T16:56:03.458Z,1397408163.458 [Default:Iridium:Read_Iridium] Running Loop=1
2014-04-13T16:56:03.459Z,1397408163.459 [Default:GPS] Running Loop=1
2014-04-13T16:56:03.459Z,1397408163.459 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-04-13T16:56:03.459Z,1397408163.459 [Default:GPS:A.SetSpeed] Running Loop=1
2014-04-13T16:56:03.459Z,1397408163.459 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-04-13T16:56:03.459Z,1397408163.459 [Default:GPS:B.GoToSurface] Running Loop=1
2014-04-13T16:56:03.459Z,1397408163.459 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-13T16:56:03.460Z,1397408163.460 [Default:GPS:B.GoToSurface] Stopped
2014-04-13T16:56:03.460Z,1397408163.460 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-13T16:56:03.460Z,1397408163.460 [Default:GPS:Read_GPS] Running Loop=1
2014-04-13T16:56:04.931Z,1397408164.931 [NAL9602](INFO): Powering up
2014-04-13T16:56:15.726Z,1397408175.726 [NAL9602](INFO): NAL9602 initialized
2014-04-13T16:56:35.613Z,1397408195.613 [NAL9602](INFO): SBD MO Status=1, MOMSN=25444, MT Status=0, MTMSN=0
2014-04-13T16:56:35.661Z,1397408195.661 [NAL9602](INFO): Sent 75 bytes from file Logs/20140413T163946/Courier0012.lzma
2014-04-13T16:56:35.662Z,1397408195.662 [NAL9602](INFO): Packets left to send: 0
2014-04-13T16:56:35.663Z,1397408195.663 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T163946/Courier0012.lzma.parts/0000.sbd
2014-04-13T16:56:35.664Z,1397408195.664 [NAL9602](INFO): Completed sending Logs/20140413T163946/Courier0012.lzma
2014-04-13T16:56:43.671Z,1397408203.671 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T16:56:43.671Z,1397408203.671 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T16:56:43.671Z,1397408203.671 [DVL_micro](ERROR): Data Fault
2014-04-13T16:56:43.740Z,1397408203.740 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T16:56:44.124Z,1397408204.124 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T16:56:44.508Z,1397408204.508 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T16:56:44.508Z,1397408204.508 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T16:56:44.508Z,1397408204.508 [DVL_micro](ERROR): Hardware Fault
2014-04-13T16:56:44.964Z,1397408204.964 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T16:56:44.964Z,1397408204.964 [DVL_micro] No Fault, FailCount= 1
2014-04-13T16:56:45.379Z,1397408205.379 [DVL_micro](INFO): Initializing
2014-04-13T16:56:49.209Z,1397408209.209 [NAL9602](INFO): SBD MO Status=1, MOMSN=25445, MT Status=0, MTMSN=0
2014-04-13T16:56:49.258Z,1397408209.258 [NAL9602](INFO): Sent 332 bytes from file Logs/20140413T163946/Express0013.lzma
2014-04-13T16:56:49.258Z,1397408209.258 [NAL9602](INFO): Packets left to send: 1
2014-04-13T16:56:49.260Z,1397408209.260 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T163946/Express0013.lzma.parts/0001.sbd
2014-04-13T16:57:01.305Z,1397408221.305 [NAL9602](INFO): SBD MO Status=1, MOMSN=25446, MT Status=0, MTMSN=0
2014-04-13T16:57:01.353Z,1397408221.353 [NAL9602](INFO): Sent 8 bytes from file Logs/20140413T163946/Express0013.lzma
2014-04-13T16:57:01.353Z,1397408221.353 [NAL9602](INFO): Packets left to send: 0
2014-04-13T16:57:01.354Z,1397408221.354 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T163946/Express0013.lzma.parts/0000.sbd
2014-04-13T16:57:01.355Z,1397408221.355 [NAL9602](INFO): Completed sending Logs/20140413T163946/Express0013.lzma
2014-04-13T16:57:14.065Z,1397408234.065 [NAL9602](INFO): SBD MO Status=0, MOMSN=25447, MT Status=0, MTMSN=0
2014-04-13T16:57:14.146Z,1397408234.146 [Default:Iridium:Read_Iridium] Stopped
2014-04-13T16:57:14.147Z,1397408234.147 [Default:Iridium](INFO): Completed Default:Iridium
2014-04-13T16:57:14.147Z,1397408234.147 [Default:Iridium] Stopped
2014-04-13T16:57:14.147Z,1397408234.147 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-04-13T16:57:14.147Z,1397408234.147 [Default:Iridium:A.SetSpeed] Stopped
2014-04-13T16:57:14.147Z,1397408234.147 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-04-13T16:57:14.536Z,1397408234.536 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-04-13T16:57:14.536Z,1397408234.536 [Default:CallIridium:B] Stopped
2014-04-13T16:57:14.536Z,1397408234.536 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-04-13T16:57:14.536Z,1397408234.536 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-04-13T16:57:14.536Z,1397408234.536 [Default:CallIridium] Stopped
2014-04-13T16:57:14.536Z,1397408234.536 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-04-13T16:57:15.433Z,1397408235.433 [NAL9602](IMPORTANT): GPS fix at: 1397408197.00
2014-04-13T16:57:15.447Z,1397408235.447 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07
2014-04-13T16:57:15.451Z,1397408235.451 [Default:GPS:Read_GPS] Stopped
2014-04-13T16:57:15.451Z,1397408235.451 [Default:GPS:D] Running Loop=1
2014-04-13T16:57:15.870Z,1397408235.870 [Default:GPS:D] Stopped
2014-04-13T16:57:15.871Z,1397408235.871 [Default:GPS](INFO): Completed Default:GPS
2014-04-13T16:57:15.871Z,1397408235.871 [Default:GPS] Stopped
2014-04-13T16:57:15.871Z,1397408235.871 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-04-13T16:57:15.871Z,1397408235.871 [Default:GPS:A.SetSpeed] Stopped
2014-04-13T16:57:15.871Z,1397408235.871 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-04-13T16:57:36.434Z,1397408256.434 [NAL9602](INFO): Powering down
2014-04-13T16:59:51.475Z,1397408391.475 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T16:59:51.475Z,1397408391.475 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T16:59:51.475Z,1397408391.475 [DVL_micro](ERROR): Data Fault
2014-04-13T16:59:51.527Z,1397408391.527 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T16:59:56.363Z,1397408396.363 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T17:00:01.525Z,1397408401.525 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T17:00:01.526Z,1397408401.526 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T17:00:01.526Z,1397408401.526 [DVL_micro](ERROR): Hardware Fault
2014-04-13T17:00:06.455Z,1397408406.455 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T17:00:06.455Z,1397408406.455 [DVL_micro] No Fault, FailCount= 1
2014-04-13T17:00:11.443Z,1397408411.443 [DVL_micro](INFO): Initializing
2014-04-13T17:02:16.466Z,1397408536.466 [Default:CallIridium] Running Loop=1
2014-04-13T17:02:16.466Z,1397408536.466 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-04-13T17:02:16.466Z,1397408536.466 [Default:CallIridium:A] Running Loop=1
2014-04-13T17:02:16.467Z,1397408536.467 [Default:CallIridium:A] Stopped
2014-04-13T17:02:16.467Z,1397408536.467 [Default:CallIridium:B] Running Loop=1
2014-04-13T17:02:16.467Z,1397408536.467 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-04-13T17:02:21.544Z,1397408541.544 [Default:Iridium] Running Loop=1
2014-04-13T17:02:21.544Z,1397408541.544 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-04-13T17:02:21.544Z,1397408541.544 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-04-13T17:02:21.544Z,1397408541.544 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-04-13T17:02:21.544Z,1397408541.544 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-04-13T17:02:21.544Z,1397408541.544 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-13T17:02:21.548Z,1397408541.548 [Default:Iridium:B.GoToSurface] Stopped
2014-04-13T17:02:21.548Z,1397408541.548 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-13T17:02:21.548Z,1397408541.548 [Default:Iridium:Read_Iridium] Running Loop=1
2014-04-13T17:02:21.548Z,1397408541.548 [Default:GPS] Running Loop=1
2014-04-13T17:02:21.548Z,1397408541.548 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-04-13T17:02:21.548Z,1397408541.548 [Default:GPS:A.SetSpeed] Running Loop=1
2014-04-13T17:02:21.548Z,1397408541.548 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-04-13T17:02:21.549Z,1397408541.549 [Default:GPS:B.GoToSurface] Running Loop=1
2014-04-13T17:02:21.549Z,1397408541.549 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-13T17:02:21.550Z,1397408541.550 [Default:GPS:B.GoToSurface] Stopped
2014-04-13T17:02:21.550Z,1397408541.550 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-13T17:02:21.550Z,1397408541.550 [Default:GPS:Read_GPS] Running Loop=1
2014-04-13T17:02:23.014Z,1397408543.014 [NAL9602](INFO): Powering up
2014-04-13T17:02:33.708Z,1397408553.708 [NAL9602](INFO): NAL9602 initialized
2014-04-13T17:02:49.737Z,1397408569.737 [NAL9602](INFO): SBD MO Status=1, MOMSN=25448, MT Status=0, MTMSN=0
2014-04-13T17:02:49.789Z,1397408569.789 [NAL9602](INFO): Sent 75 bytes from file Logs/20140413T163946/Courier0016.lzma
2014-04-13T17:02:49.789Z,1397408569.789 [NAL9602](INFO): Packets left to send: 0
2014-04-13T17:02:49.791Z,1397408569.791 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T163946/Courier0016.lzma.parts/0000.sbd
2014-04-13T17:02:49.791Z,1397408569.791 [NAL9602](INFO): Completed sending Logs/20140413T163946/Courier0016.lzma
2014-04-13T17:03:02.977Z,1397408582.977 [NAL9602](INFO): SBD MO Status=1, MOMSN=25449, MT Status=0, MTMSN=0
2014-04-13T17:03:03.038Z,1397408583.038 [NAL9602](INFO): Sent 224 bytes from file Logs/20140413T163946/Express0017.lzma
2014-04-13T17:03:03.038Z,1397408583.038 [NAL9602](INFO): Packets left to send: 0
2014-04-13T17:03:03.040Z,1397408583.040 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T163946/Express0017.lzma.parts/0000.sbd
2014-04-13T17:03:03.040Z,1397408583.040 [NAL9602](INFO): Completed sending Logs/20140413T163946/Express0017.lzma
2014-04-13T17:03:14.147Z,1397408594.147 [NAL9602](INFO): SBD MO Status=0, MOMSN=25450, MT Status=0, MTMSN=0
2014-04-13T17:03:14.248Z,1397408594.248 [Default:Iridium:Read_Iridium] Stopped
2014-04-13T17:03:14.248Z,1397408594.248 [Default:Iridium](INFO): Completed Default:Iridium
2014-04-13T17:03:14.248Z,1397408594.248 [Default:Iridium] Stopped
2014-04-13T17:03:14.249Z,1397408594.249 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-04-13T17:03:14.249Z,1397408594.249 [Default:Iridium:A.SetSpeed] Stopped
2014-04-13T17:03:14.249Z,1397408594.249 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-04-13T17:03:14.651Z,1397408594.651 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-04-13T17:03:14.651Z,1397408594.651 [Default:CallIridium:B] Stopped
2014-04-13T17:03:14.651Z,1397408594.651 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-04-13T17:03:14.651Z,1397408594.651 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-04-13T17:03:14.651Z,1397408594.651 [Default:CallIridium] Stopped
2014-04-13T17:03:14.652Z,1397408594.652 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-04-13T17:03:15.429Z,1397408595.429 [NAL9602](IMPORTANT): GPS fix at: 1397408557.00
2014-04-13T17:03:15.443Z,1397408595.443 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07
2014-04-13T17:03:15.447Z,1397408595.447 [Default:GPS:Read_GPS] Stopped
2014-04-13T17:03:15.448Z,1397408595.448 [Default:GPS:D] Running Loop=1
2014-04-13T17:03:15.860Z,1397408595.860 [Default:GPS:D] Stopped
2014-04-13T17:03:15.860Z,1397408595.860 [Default:GPS](INFO): Completed Default:GPS
2014-04-13T17:03:15.860Z,1397408595.860 [Default:GPS] Stopped
2014-04-13T17:03:15.860Z,1397408595.860 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-04-13T17:03:15.860Z,1397408595.860 [Default:GPS:A.SetSpeed] Stopped
2014-04-13T17:03:15.860Z,1397408595.860 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-04-13T17:03:36.408Z,1397408616.408 [NAL9602](INFO): Powering down
2014-04-13T17:03:41.455Z,1397408621.455 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T17:03:41.456Z,1397408621.456 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T17:03:41.456Z,1397408621.456 [DVL_micro](ERROR): Data Fault
2014-04-13T17:03:41.484Z,1397408621.484 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T17:03:46.407Z,1397408626.407 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T17:03:51.434Z,1397408631.434 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T17:03:51.434Z,1397408631.434 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T17:03:51.434Z,1397408631.434 [DVL_micro](ERROR): Hardware Fault
2014-04-13T17:03:56.466Z,1397408636.466 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T17:03:56.466Z,1397408636.466 [DVL_micro] No Fault, FailCount= 1
2014-04-13T17:04:01.448Z,1397408641.448 [DVL_micro](INFO): Initializing
2014-04-13T17:07:31.423Z,1397408851.423 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T17:07:31.423Z,1397408851.423 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T17:07:31.423Z,1397408851.423 [DVL_micro](ERROR): Data Fault
2014-04-13T17:07:31.457Z,1397408851.457 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T17:07:36.447Z,1397408856.447 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T17:07:41.383Z,1397408861.383 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T17:07:41.383Z,1397408861.383 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T17:07:41.383Z,1397408861.383 [DVL_micro](ERROR): Hardware Fault
2014-04-13T17:07:46.502Z,1397408866.502 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T17:07:46.502Z,1397408866.502 [DVL_micro] No Fault, FailCount= 1
2014-04-13T17:07:51.457Z,1397408871.457 [DVL_micro](INFO): Initializing
2014-04-13T17:08:16.443Z,1397408896.443 [Default:CallIridium] Running Loop=1
2014-04-13T17:08:16.443Z,1397408896.443 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-04-13T17:08:16.443Z,1397408896.443 [Default:CallIridium:A] Running Loop=1
2014-04-13T17:08:16.444Z,1397408896.444 [Default:CallIridium:A] Stopped
2014-04-13T17:08:16.444Z,1397408896.444 [Default:CallIridium:B] Running Loop=1
2014-04-13T17:08:16.444Z,1397408896.444 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-04-13T17:08:21.550Z,1397408901.550 [Default:Iridium] Running Loop=1
2014-04-13T17:08:21.551Z,1397408901.551 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-04-13T17:08:21.551Z,1397408901.551 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-04-13T17:08:21.551Z,1397408901.551 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-04-13T17:08:21.551Z,1397408901.551 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-04-13T17:08:21.551Z,1397408901.551 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-13T17:08:21.552Z,1397408901.552 [Default:Iridium:B.GoToSurface] Stopped
2014-04-13T17:08:21.552Z,1397408901.552 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-13T17:08:21.552Z,1397408901.552 [Default:Iridium:Read_Iridium] Running Loop=1
2014-04-13T17:08:21.552Z,1397408901.552 [Default:GPS] Running Loop=1
2014-04-13T17:08:21.553Z,1397408901.553 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-04-13T17:08:21.553Z,1397408901.553 [Default:GPS:A.SetSpeed] Running Loop=1
2014-04-13T17:08:21.553Z,1397408901.553 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-04-13T17:08:21.553Z,1397408901.553 [Default:GPS:B.GoToSurface] Running Loop=1
2014-04-13T17:08:21.553Z,1397408901.553 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-13T17:08:21.554Z,1397408901.554 [Default:GPS:B.GoToSurface] Stopped
2014-04-13T17:08:21.554Z,1397408901.554 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-13T17:08:21.554Z,1397408901.554 [Default:GPS:Read_GPS] Running Loop=1
2014-04-13T17:08:23.018Z,1397408903.018 [NAL9602](INFO): Powering up
2014-04-13T17:08:33.714Z,1397408913.714 [NAL9602](INFO): NAL9602 initialized
2014-04-13T17:08:47.817Z,1397408927.817 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46
2014-04-13T17:08:47.817Z,1397408927.817 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -1289 -1334 -14 2 2 2 2 14.7 -360.4 -1344.7 2 -345.3 104.0 -1344.7 2 14 -360 -1344 2 -345 104 -4.04 -6.86 250.9 -3.0 16.4 0.005 35.0 1489 76
2014-04-13T17:08:58.204Z,1397408938.204 [NAL9602](INFO): SBD MO Status=1, MOMSN=25451, MT Status=0, MTMSN=0
2014-04-13T17:08:58.252Z,1397408938.252 [NAL9602](INFO): Sent 75 bytes from file Logs/20140413T163946/Courier0020.lzma
2014-04-13T17:08:58.253Z,1397408938.253 [NAL9602](INFO): Packets left to send: 0
2014-04-13T17:08:58.254Z,1397408938.254 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T163946/Courier0020.lzma.parts/0000.sbd
2014-04-13T17:08:58.255Z,1397408938.255 [NAL9602](INFO): Completed sending Logs/20140413T163946/Courier0020.lzma
2014-04-13T17:08:59.936Z,1397408939.936 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-04-13T17:09:02.549Z,1397408942.549 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-04-13T17:09:04.247Z,1397408944.247 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-04-13T17:09:06.836Z,1397408946.836 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-04-13T17:09:07.273Z,1397408947.273 [NAL9602](INFO): SBD MO Status=1, MOMSN=25452, MT Status=0, MTMSN=0
2014-04-13T17:09:07.335Z,1397408947.335 [NAL9602](INFO): Sent 219 bytes from file Logs/20140413T163946/Express0021.lzma
2014-04-13T17:09:07.335Z,1397408947.335 [NAL9602](INFO): Packets left to send: 0
2014-04-13T17:09:07.336Z,1397408947.336 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T163946/Express0021.lzma.parts/0000.sbd
2014-04-13T17:09:07.337Z,1397408947.337 [NAL9602](INFO): Completed sending Logs/20140413T163946/Express0021.lzma
2014-04-13T17:09:09.339Z,1397408949.339 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-04-13T17:09:11.476Z,1397408951.476 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-04-13T17:09:14.013Z,1397408954.013 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-04-13T17:09:14.876Z,1397408954.876 [NAL9602](INFO): SBD MO Status=0, MOMSN=25453, MT Status=0, MTMSN=0
2014-04-13T17:09:14.959Z,1397408954.959 [Default:Iridium:Read_Iridium] Stopped
2014-04-13T17:09:14.959Z,1397408954.959 [Default:Iridium](INFO): Completed Default:Iridium
2014-04-13T17:09:14.959Z,1397408954.959 [Default:Iridium] Stopped
2014-04-13T17:09:14.959Z,1397408954.959 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-04-13T17:09:14.959Z,1397408954.959 [Default:Iridium:A.SetSpeed] Stopped
2014-04-13T17:09:14.960Z,1397408954.960 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-04-13T17:09:15.373Z,1397408955.373 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-04-13T17:09:15.373Z,1397408955.373 [Default:CallIridium:B] Stopped
2014-04-13T17:09:15.373Z,1397408955.373 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-04-13T17:09:15.373Z,1397408955.373 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-04-13T17:09:15.373Z,1397408955.373 [Default:CallIridium] Stopped
2014-04-13T17:09:15.373Z,1397408955.373 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-04-13T17:09:16.206Z,1397408956.206 [NAL9602](IMPORTANT): GPS fix at: 1397408918.00
2014-04-13T17:09:16.227Z,1397408956.227 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07
2014-04-13T17:09:16.240Z,1397408956.240 [Default:GPS:Read_GPS] Stopped
2014-04-13T17:09:16.240Z,1397408956.240 [Default:GPS:D] Running Loop=1
2014-04-13T17:09:16.715Z,1397408956.715 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-04-13T17:09:16.771Z,1397408956.771 [Default:GPS:D] Stopped
2014-04-13T17:09:16.771Z,1397408956.771 [Default:GPS](INFO): Completed Default:GPS
2014-04-13T17:09:16.771Z,1397408956.771 [Default:GPS] Stopped
2014-04-13T17:09:16.771Z,1397408956.771 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-04-13T17:09:16.771Z,1397408956.771 [Default:GPS:A.SetSpeed] Stopped
2014-04-13T17:09:16.771Z,1397408956.771 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-04-13T17:09:22.341Z,1397408962.341 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-04-13T17:09:27.341Z,1397408967.341 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-04-13T17:09:32.309Z,1397408972.309 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-04-13T17:09:37.344Z,1397408977.344 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-04-13T17:09:37.364Z,1397408977.364 [NAL9602](INFO): Powering down
2014-04-13T17:09:42.242Z,1397408982.242 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-04-13T17:09:47.370Z,1397408987.370 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-04-13T17:10:02.280Z,1397409002.280 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-04-13T17:10:07.336Z,1397409007.336 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-04-13T17:10:12.285Z,1397409012.285 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#10 STATUS: 65535
2014-04-13T17:11:12.351Z,1397409072.351 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T17:11:12.351Z,1397409072.351 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T17:11:12.351Z,1397409072.351 [DVL_micro](ERROR): Data Fault
2014-04-13T17:11:12.378Z,1397409072.378 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T17:11:17.334Z,1397409077.334 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T17:11:22.354Z,1397409082.354 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T17:11:22.354Z,1397409082.354 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T17:11:22.354Z,1397409082.354 [DVL_micro](ERROR): Hardware Fault
2014-04-13T17:11:27.387Z,1397409087.387 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T17:11:27.403Z,1397409087.403 [DVL_micro] No Fault, FailCount= 1
2014-04-13T17:11:32.348Z,1397409092.348 [DVL_micro](INFO): Initializing
2014-04-13T17:14:17.347Z,1397409257.347 [Default:CallIridium] Running Loop=1
2014-04-13T17:14:17.347Z,1397409257.347 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-04-13T17:14:17.347Z,1397409257.347 [Default:CallIridium:A] Running Loop=1
2014-04-13T17:14:17.348Z,1397409257.348 [Default:CallIridium:A] Stopped
2014-04-13T17:14:17.348Z,1397409257.348 [Default:CallIridium:B] Running Loop=1
2014-04-13T17:14:17.348Z,1397409257.348 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-04-13T17:14:22.359Z,1397409262.359 [Default:Iridium] Running Loop=1
2014-04-13T17:14:22.359Z,1397409262.359 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-04-13T17:14:22.359Z,1397409262.359 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-04-13T17:14:22.359Z,1397409262.359 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-04-13T17:14:22.360Z,1397409262.360 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-04-13T17:14:22.360Z,1397409262.360 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-13T17:14:22.360Z,1397409262.360 [Default:Iridium:B.GoToSurface] Stopped
2014-04-13T17:14:22.360Z,1397409262.360 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-13T17:14:22.361Z,1397409262.361 [Default:Iridium:Read_Iridium] Running Loop=1
2014-04-13T17:14:22.361Z,1397409262.361 [Default:GPS] Running Loop=1
2014-04-13T17:14:22.361Z,1397409262.361 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-04-13T17:14:22.361Z,1397409262.361 [Default:GPS:A.SetSpeed] Running Loop=1
2014-04-13T17:14:22.361Z,1397409262.361 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-04-13T17:14:22.361Z,1397409262.361 [Default:GPS:B.GoToSurface] Running Loop=1
2014-04-13T17:14:22.361Z,1397409262.361 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-13T17:14:22.362Z,1397409262.362 [Default:GPS:B.GoToSurface] Stopped
2014-04-13T17:14:22.362Z,1397409262.362 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-13T17:14:22.362Z,1397409262.362 [Default:GPS:Read_GPS] Running Loop=1
2014-04-13T17:14:23.882Z,1397409263.882 [NAL9602](INFO): Powering up
2014-04-13T17:14:34.538Z,1397409274.538 [NAL9602](INFO): NAL9602 initialized
2014-04-13T17:14:52.875Z,1397409292.875 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T17:14:52.876Z,1397409292.876 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T17:14:52.876Z,1397409292.876 [DVL_micro](ERROR): Data Fault
2014-04-13T17:14:52.956Z,1397409292.956 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T17:14:53.341Z,1397409293.341 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T17:14:53.765Z,1397409293.765 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T17:14:53.766Z,1397409293.766 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T17:14:53.766Z,1397409293.766 [DVL_micro](ERROR): Hardware Fault
2014-04-13T17:14:54.233Z,1397409294.233 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T17:14:54.233Z,1397409294.233 [DVL_micro] No Fault, FailCount= 1
2014-04-13T17:14:54.611Z,1397409294.611 [DVL_micro](INFO): Initializing
2014-04-13T17:14:59.204Z,1397409299.204 [NAL9602](INFO): SBD MO Status=1, MOMSN=25454, MT Status=0, MTMSN=0
2014-04-13T17:14:59.252Z,1397409299.252 [NAL9602](INFO): Sent 75 bytes from file Logs/20140413T163946/Courier0024.lzma
2014-04-13T17:14:59.252Z,1397409299.252 [NAL9602](INFO): Packets left to send: 0
2014-04-13T17:14:59.254Z,1397409299.254 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T163946/Courier0024.lzma.parts/0000.sbd
2014-04-13T17:14:59.254Z,1397409299.254 [NAL9602](INFO): Completed sending Logs/20140413T163946/Courier0024.lzma
2014-04-13T17:15:13.342Z,1397409313.342 [NAL9602](INFO): SBD MO Status=1, MOMSN=25455, MT Status=0, MTMSN=0
2014-04-13T17:15:13.390Z,1397409313.390 [NAL9602](INFO): Sent 209 bytes from file Logs/20140413T163946/Express0025.lzma
2014-04-13T17:15:13.391Z,1397409313.391 [NAL9602](INFO): Packets left to send: 0
2014-04-13T17:15:13.392Z,1397409313.392 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T163946/Express0025.lzma.parts/0000.sbd
2014-04-13T17:15:13.392Z,1397409313.392 [NAL9602](INFO): Completed sending Logs/20140413T163946/Express0025.lzma
2014-04-13T17:15:22.233Z,1397409322.233 [NAL9602](INFO): SBD MO Status=0, MOMSN=25456, MT Status=0, MTMSN=0
2014-04-13T17:15:22.366Z,1397409322.366 [Default:Iridium:Read_Iridium] Stopped
2014-04-13T17:15:22.367Z,1397409322.367 [Default:Iridium](INFO): Completed Default:Iridium
2014-04-13T17:15:22.367Z,1397409322.367 [Default:Iridium] Stopped
2014-04-13T17:15:22.367Z,1397409322.367 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-04-13T17:15:22.367Z,1397409322.367 [Default:Iridium:A.SetSpeed] Stopped
2014-04-13T17:15:22.367Z,1397409322.367 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-04-13T17:15:22.927Z,1397409322.927 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-04-13T17:15:22.927Z,1397409322.927 [Default:CallIridium:B] Stopped
2014-04-13T17:15:22.927Z,1397409322.927 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-04-13T17:15:22.928Z,1397409322.928 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-04-13T17:15:22.928Z,1397409322.928 [Default:CallIridium] Stopped
2014-04-13T17:15:22.928Z,1397409322.928 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-04-13T17:15:23.828Z,1397409323.828 [NAL9602](IMPORTANT): GPS fix at: 1397409286.00
2014-04-13T17:15:23.845Z,1397409323.845 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07
2014-04-13T17:15:23.850Z,1397409323.850 [Default:GPS:Read_GPS] Stopped
2014-04-13T17:15:23.850Z,1397409323.850 [Default:GPS:D] Running Loop=1
2014-04-13T17:15:24.256Z,1397409324.256 [Default:GPS:D] Stopped
2014-04-13T17:15:24.256Z,1397409324.256 [Default:GPS](INFO): Completed Default:GPS
2014-04-13T17:15:24.256Z,1397409324.256 [Default:GPS] Stopped
2014-04-13T17:15:24.257Z,1397409324.257 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-04-13T17:15:24.257Z,1397409324.257 [Default:GPS:A.SetSpeed] Stopped
2014-04-13T17:15:24.257Z,1397409324.257 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-04-13T17:15:44.785Z,1397409344.785 [NAL9602](INFO): Powering down
2014-04-13T17:17:59.854Z,1397409479.854 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T17:17:59.855Z,1397409479.855 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T17:17:59.855Z,1397409479.855 [DVL_micro](ERROR): Data Fault
2014-04-13T17:17:59.885Z,1397409479.885 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T17:18:04.821Z,1397409484.821 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T17:18:09.825Z,1397409489.825 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T17:18:09.825Z,1397409489.825 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T17:18:09.825Z,1397409489.825 [DVL_micro](ERROR): Hardware Fault
2014-04-13T17:18:14.865Z,1397409494.865 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T17:18:14.865Z,1397409494.865 [DVL_micro] No Fault, FailCount= 1
2014-04-13T17:18:19.846Z,1397409499.846 [DVL_micro](INFO): Initializing
2014-04-13T17:20:25.013Z,1397409625.013 [Default:CallIridium] Running Loop=1
2014-04-13T17:20:25.013Z,1397409625.013 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-04-13T17:20:25.013Z,1397409625.013 [Default:CallIridium:A] Running Loop=1
2014-04-13T17:20:25.013Z,1397409625.013 [Default:CallIridium:A] Stopped
2014-04-13T17:20:25.014Z,1397409625.014 [Default:CallIridium:B] Running Loop=1
2014-04-13T17:20:25.014Z,1397409625.014 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-04-13T17:20:29.883Z,1397409629.883 [Default:Iridium] Running Loop=1
2014-04-13T17:20:29.883Z,1397409629.883 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-04-13T17:20:29.883Z,1397409629.883 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-04-13T17:20:29.883Z,1397409629.883 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-04-13T17:20:29.883Z,1397409629.883 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-04-13T17:20:29.883Z,1397409629.883 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-13T17:20:29.908Z,1397409629.908 [Default:Iridium:B.GoToSurface] Stopped
2014-04-13T17:20:29.908Z,1397409629.908 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-13T17:20:29.908Z,1397409629.908 [Default:Iridium:Read_Iridium] Running Loop=1
2014-04-13T17:20:29.909Z,1397409629.909 [Default:GPS] Running Loop=1
2014-04-13T17:20:29.909Z,1397409629.909 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-04-13T17:20:29.909Z,1397409629.909 [Default:GPS:A.SetSpeed] Running Loop=1
2014-04-13T17:20:29.909Z,1397409629.909 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-04-13T17:20:29.909Z,1397409629.909 [Default:GPS:B.GoToSurface] Running Loop=1
2014-04-13T17:20:29.909Z,1397409629.909 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-13T17:20:29.910Z,1397409629.910 [Default:GPS:B.GoToSurface] Stopped
2014-04-13T17:20:29.910Z,1397409629.910 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-13T17:20:29.910Z,1397409629.910 [Default:GPS:Read_GPS] Running Loop=1
2014-04-13T17:20:31.509Z,1397409631.509 [NAL9602](INFO): Powering up
2014-04-13T17:20:42.304Z,1397409642.304 [NAL9602](INFO): NAL9602 initialized
2014-04-13T17:20:49.255Z,1397409649.255 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46
2014-04-13T17:20:49.255Z,1397409649.255 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 7 -1231 -1131 -948 2 2 2 2 2159.4 -377.7 -761.2 2 71.8 -2191.0 -761.2 2 2159 -377 -761 2 71 -2191 -761 2 -3.89 -7.00 281.8 -3.0 16.8 0.005 35.0 1489 109
2014-04-13T17:21:35.919Z,1397409695.919 [NAL9602](INFO): SBD MO Status=2, MOMSN=25457, MT Status=2, MTMSN=0
2014-04-13T17:21:35.919Z,1397409695.919 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-04-13T17:21:37.183Z,1397409697.183 [NAL9602](IMPORTANT): GPS fix at: 1397409659.00
2014-04-13T17:21:37.249Z,1397409697.249 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07
2014-04-13T17:21:37.253Z,1397409697.253 [Default:GPS:Read_GPS] Stopped
2014-04-13T17:21:37.254Z,1397409697.254 [Default:GPS:D] Running Loop=1
2014-04-13T17:21:37.658Z,1397409697.658 [Default:GPS:D] Stopped
2014-04-13T17:21:37.658Z,1397409697.658 [Default:GPS](INFO): Completed Default:GPS
2014-04-13T17:21:37.658Z,1397409697.658 [Default:GPS] Stopped
2014-04-13T17:21:37.658Z,1397409697.658 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-04-13T17:21:37.658Z,1397409697.658 [Default:GPS:A.SetSpeed] Stopped
2014-04-13T17:21:37.659Z,1397409697.659 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-04-13T17:21:40.214Z,1397409700.214 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T17:21:40.214Z,1397409700.214 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T17:21:40.214Z,1397409700.214 [DVL_micro](ERROR): Data Fault
2014-04-13T17:21:40.753Z,1397409700.753 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T17:21:41.125Z,1397409701.125 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T17:21:42.034Z,1397409702.034 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T17:21:42.034Z,1397409702.034 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T17:21:42.034Z,1397409702.034 [DVL_micro](ERROR): Hardware Fault
2014-04-13T17:21:44.663Z,1397409704.663 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T17:21:44.663Z,1397409704.663 [DVL_micro] No Fault, FailCount= 1
2014-04-13T17:21:45.038Z,1397409705.038 [DVL_micro](INFO): Initializing
2014-04-13T17:21:59.570Z,1397409719.570 [NAL9602](INFO): SBD MO Status=1, MOMSN=25457, MT Status=0, MTMSN=0
2014-04-13T17:21:59.620Z,1397409719.620 [NAL9602](INFO): Sent 74 bytes from file Logs/20140413T163946/Courier0028.lzma
2014-04-13T17:21:59.620Z,1397409719.620 [NAL9602](INFO): Packets left to send: 0
2014-04-13T17:21:59.622Z,1397409719.622 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T163946/Courier0028.lzma.parts/0000.sbd
2014-04-13T17:21:59.622Z,1397409719.622 [NAL9602](INFO): Completed sending Logs/20140413T163946/Courier0028.lzma
2014-04-13T17:22:17.463Z,1397409737.463 [NAL9602](INFO): SBD MO Status=2, MOMSN=25458, MT Status=2, MTMSN=0
2014-04-13T17:22:17.463Z,1397409737.463 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-04-13T17:22:37.282Z,1397409757.282 [NAL9602](INFO): SBD MO Status=1, MOMSN=25458, MT Status=0, MTMSN=0
2014-04-13T17:22:37.326Z,1397409757.326 [NAL9602](INFO): Sent 229 bytes from file Logs/20140413T163946/Express0029.lzma
2014-04-13T17:22:37.327Z,1397409757.327 [NAL9602](INFO): Packets left to send: 0
2014-04-13T17:22:37.328Z,1397409757.328 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T163946/Express0029.lzma.parts/0000.sbd
2014-04-13T17:22:37.329Z,1397409757.329 [NAL9602](INFO): Completed sending Logs/20140413T163946/Express0029.lzma
2014-04-13T17:22:46.404Z,1397409766.404 [NAL9602](INFO): SBD MO Status=0, MOMSN=25459, MT Status=0, MTMSN=0
2014-04-13T17:22:46.487Z,1397409766.487 [Default:Iridium:Read_Iridium] Stopped
2014-04-13T17:22:46.487Z,1397409766.487 [Default:Iridium](INFO): Completed Default:Iridium
2014-04-13T17:22:46.487Z,1397409766.487 [Default:Iridium] Stopped
2014-04-13T17:22:46.487Z,1397409766.487 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-04-13T17:22:46.487Z,1397409766.487 [Default:Iridium:A.SetSpeed] Stopped
2014-04-13T17:22:46.487Z,1397409766.487 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-04-13T17:22:46.962Z,1397409766.962 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-04-13T17:22:46.962Z,1397409766.962 [Default:CallIridium:B] Stopped
2014-04-13T17:22:46.962Z,1397409766.962 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-04-13T17:22:46.962Z,1397409766.962 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-04-13T17:22:46.962Z,1397409766.962 [Default:CallIridium] Stopped
2014-04-13T17:22:46.962Z,1397409766.962 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-04-13T17:22:57.084Z,1397409777.084 [NAL9602](INFO): Powering down
2014-04-13T17:24:52.106Z,1397409892.106 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T17:24:52.106Z,1397409892.106 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T17:24:52.106Z,1397409892.106 [DVL_micro](ERROR): Data Fault
2014-04-13T17:24:52.152Z,1397409892.152 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T17:24:57.058Z,1397409897.058 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T17:25:02.081Z,1397409902.081 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T17:25:02.081Z,1397409902.081 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T17:25:02.081Z,1397409902.081 [DVL_micro](ERROR): Hardware Fault
2014-04-13T17:25:07.108Z,1397409907.108 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T17:25:07.108Z,1397409907.108 [DVL_micro] No Fault, FailCount= 1
2014-04-13T17:25:12.115Z,1397409912.115 [DVL_micro](INFO): Initializing
2014-04-13T17:25:27.266Z,1397409927.266 [Depth_Keller](ERROR): Pressure reading out of range: 1830.442749 decibar
2014-04-13T17:26:42.142Z,1397410002.142 [Depth_Keller](ERROR): Pressure reading out of range: 1830.489014 decibar
2014-04-13T17:27:12.082Z,1397410032.082 [Depth_Keller](ERROR): Pressure reading out of range: 1354.910034 decibar
2014-04-13T17:27:22.105Z,1397410042.105 [Depth_Keller](ERROR): Pressure reading out of range: 1830.464478 decibar
2014-04-13T17:27:32.072Z,1397410052.072 [Depth_Keller](ERROR): Pressure reading out of range: 1830.464478 decibar
2014-04-13T17:27:42.060Z,1397410062.060 [Depth_Keller](ERROR): Pressure reading out of range: 1830.471558 decibar
2014-04-13T17:27:47.110Z,1397410067.110 [Default:CallIridium] Running Loop=1
2014-04-13T17:27:47.110Z,1397410067.110 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-04-13T17:27:47.110Z,1397410067.110 [Default:CallIridium:A] Running Loop=1
2014-04-13T17:27:47.115Z,1397410067.115 [Default:CallIridium:A] Stopped
2014-04-13T17:27:47.115Z,1397410067.115 [Default:CallIridium:B] Running Loop=1
2014-04-13T17:27:47.115Z,1397410067.115 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-04-13T17:27:52.071Z,1397410072.071 [Depth_Keller](ERROR): Pressure reading out of range: 1830.479370 decibar
2014-04-13T17:27:52.150Z,1397410072.150 [Default:Iridium] Running Loop=1
2014-04-13T17:27:52.150Z,1397410072.150 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-04-13T17:27:52.150Z,1397410072.150 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-04-13T17:27:52.151Z,1397410072.151 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-04-13T17:27:52.151Z,1397410072.151 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-04-13T17:27:52.151Z,1397410072.151 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-13T17:27:52.152Z,1397410072.152 [Default:Iridium:B.GoToSurface] Stopped
2014-04-13T17:27:52.152Z,1397410072.152 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-13T17:27:52.152Z,1397410072.152 [Default:Iridium:Read_Iridium] Running Loop=1
2014-04-13T17:27:52.152Z,1397410072.152 [Default:GPS] Running Loop=1
2014-04-13T17:27:52.152Z,1397410072.152 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-04-13T17:27:52.152Z,1397410072.152 [Default:GPS:A.SetSpeed] Running Loop=1
2014-04-13T17:27:52.152Z,1397410072.152 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-04-13T17:27:52.153Z,1397410072.153 [Default:GPS:B.GoToSurface] Running Loop=1
2014-04-13T17:27:52.153Z,1397410072.153 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-13T17:27:52.153Z,1397410072.153 [Default:GPS:B.GoToSurface] Stopped
2014-04-13T17:27:52.153Z,1397410072.153 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-13T17:27:52.154Z,1397410072.154 [Default:GPS:Read_GPS] Running Loop=1
2014-04-13T17:27:53.740Z,1397410073.740 [NAL9602](INFO): Powering up
2014-04-13T17:28:04.450Z,1397410084.450 [NAL9602](INFO): NAL9602 initialized
2014-04-13T17:28:32.434Z,1397410112.434 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T17:28:32.434Z,1397410112.434 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T17:28:32.434Z,1397410112.434 [DVL_micro](ERROR): Data Fault
2014-04-13T17:28:32.438Z,1397410112.438 [NAL9602](INFO): SBD MO Status=1, MOMSN=25460, MT Status=0, MTMSN=0
2014-04-13T17:28:32.489Z,1397410112.489 [NAL9602](INFO): Sent 75 bytes from file Logs/20140413T163946/Courier0032.lzma
2014-04-13T17:28:32.489Z,1397410112.489 [NAL9602](INFO): Packets left to send: 0
2014-04-13T17:28:32.491Z,1397410112.491 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T163946/Courier0032.lzma.parts/0000.sbd
2014-04-13T17:28:32.491Z,1397410112.491 [NAL9602](INFO): Completed sending Logs/20140413T163946/Courier0032.lzma
2014-04-13T17:28:32.562Z,1397410112.562 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T17:28:32.948Z,1397410112.948 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T17:28:34.169Z,1397410114.169 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T17:28:34.169Z,1397410114.169 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T17:28:34.170Z,1397410114.170 [DVL_micro](ERROR): Hardware Fault
2014-04-13T17:28:36.715Z,1397410116.715 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T17:28:36.715Z,1397410116.715 [DVL_micro] No Fault, FailCount= 1
2014-04-13T17:28:37.079Z,1397410117.079 [DVL_micro](INFO): Initializing
2014-04-13T17:28:46.431Z,1397410126.431 [NAL9602](INFO): SBD MO Status=1, MOMSN=25461, MT Status=0, MTMSN=0
2014-04-13T17:28:46.479Z,1397410126.479 [NAL9602](INFO): Sent 217 bytes from file Logs/20140413T163946/Express0033.lzma
2014-04-13T17:28:46.479Z,1397410126.479 [NAL9602](INFO): Packets left to send: 0
2014-04-13T17:28:46.480Z,1397410126.480 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T163946/Express0033.lzma.parts/0000.sbd
2014-04-13T17:28:46.481Z,1397410126.481 [NAL9602](INFO): Completed sending Logs/20140413T163946/Express0033.lzma
2014-04-13T17:28:57.403Z,1397410137.403 [NAL9602](INFO): SBD MO Status=0, MOMSN=25462, MT Status=0, MTMSN=0
2014-04-13T17:28:57.485Z,1397410137.485 [Default:Iridium:Read_Iridium] Stopped
2014-04-13T17:28:57.486Z,1397410137.486 [Default:Iridium](INFO): Completed Default:Iridium
2014-04-13T17:28:57.486Z,1397410137.486 [Default:Iridium] Stopped
2014-04-13T17:28:57.486Z,1397410137.486 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-04-13T17:28:57.486Z,1397410137.486 [Default:Iridium:A.SetSpeed] Stopped
2014-04-13T17:28:57.486Z,1397410137.486 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-04-13T17:28:57.949Z,1397410137.949 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-04-13T17:28:57.949Z,1397410137.949 [Default:CallIridium:B] Stopped
2014-04-13T17:28:57.949Z,1397410137.949 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-04-13T17:28:57.949Z,1397410137.949 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-04-13T17:28:57.949Z,1397410137.949 [Default:CallIridium] Stopped
2014-04-13T17:28:57.949Z,1397410137.949 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-04-13T17:28:58.777Z,1397410138.777 [NAL9602](IMPORTANT): GPS fix at: 1397410100.00
2014-04-13T17:28:58.810Z,1397410138.810 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07
2014-04-13T17:28:58.819Z,1397410138.819 [Default:GPS:Read_GPS] Stopped
2014-04-13T17:28:58.819Z,1397410138.819 [Default:GPS:D] Running Loop=1
2014-04-13T17:28:59.367Z,1397410139.367 [Default:GPS:D] Stopped
2014-04-13T17:28:59.367Z,1397410139.367 [Default:GPS](INFO): Completed Default:GPS
2014-04-13T17:28:59.367Z,1397410139.367 [Default:GPS] Stopped
2014-04-13T17:28:59.368Z,1397410139.368 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-04-13T17:28:59.368Z,1397410139.368 [Default:GPS:A.SetSpeed] Stopped
2014-04-13T17:28:59.368Z,1397410139.368 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-04-13T17:29:14.904Z,1397410154.904 [Depth_Keller](ERROR): Pressure reading out of range: 1830.490723 decibar
2014-04-13T17:29:19.925Z,1397410159.925 [NAL9602](INFO): Powering down
2014-04-13T17:29:34.938Z,1397410174.938 [Depth_Keller](ERROR): Pressure reading out of range: 1830.460205 decibar
2014-04-13T17:29:49.921Z,1397410189.921 [Depth_Keller](ERROR): Pressure reading out of range: 1830.468018 decibar
2014-04-13T17:29:59.933Z,1397410199.933 [Depth_Keller](ERROR): Pressure reading out of range: 1830.458374 decibar
2014-04-13T17:30:09.924Z,1397410209.924 [Depth_Keller](ERROR): Pressure reading out of range: 1830.461914 decibar
2014-04-13T17:30:19.885Z,1397410219.885 [Depth_Keller](ERROR): Pressure reading out of range: 1830.456665 decibar
2014-04-13T17:30:30.023Z,1397410230.023 [Radio_Freewave](INFO): Powering down
2014-04-13T17:30:34.960Z,1397410234.960 [Depth_Keller](ERROR): Pressure reading out of range: 1830.443604 decibar
2014-04-13T17:30:39.959Z,1397410239.959 [Radio_Freewave](INFO): Powering up
2014-04-13T17:30:45.042Z,1397410245.042 [Radio_Freewave](IMPORTANT): Starting PPPD with command:/sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0
2014-04-13T17:30:59.930Z,1397410259.930 [Depth_Keller](ERROR): Pressure reading out of range: 1354.880249 decibar
2014-04-13T17:31:44.942Z,1397410304.942 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T17:31:44.942Z,1397410304.942 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T17:31:44.942Z,1397410304.942 [DVL_micro](ERROR): Data Fault
2014-04-13T17:31:44.970Z,1397410304.970 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T17:31:49.942Z,1397410309.942 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T17:31:54.843Z,1397410314.843 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T17:31:54.843Z,1397410314.843 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T17:31:54.843Z,1397410314.843 [DVL_micro](ERROR): Hardware Fault
2014-04-13T17:31:59.979Z,1397410319.979 [Depth_Keller](ERROR): Pressure reading out of range: 1830.481934 decibar
2014-04-13T17:32:00.045Z,1397410320.045 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T17:32:00.045Z,1397410320.045 [DVL_micro] No Fault, FailCount= 1
2014-04-13T17:32:04.909Z,1397410324.909 [DVL_micro](INFO): Initializing
2014-04-13T17:32:24.955Z,1397410344.955 [Depth_Keller](ERROR): Pressure reading out of range: 1830.454956 decibar
2014-04-13T17:32:34.954Z,1397410354.954 [Depth_Keller](ERROR): Pressure reading out of range: 1830.447998 decibar
2014-04-13T17:32:44.970Z,1397410364.970 [Depth_Keller](ERROR): Pressure reading out of range: 1830.505615 decibar
2014-04-13T17:32:54.961Z,1397410374.961 [Depth_Keller](ERROR): Pressure reading out of range: 1830.500366 decibar
2014-04-13T17:33:04.940Z,1397410384.940 [Depth_Keller](ERROR): Pressure reading out of range: 1830.501221 decibar
2014-04-13T17:33:14.964Z,1397410394.964 [Depth_Keller](ERROR): Pressure reading out of range: 1830.478516 decibar
2014-04-13T17:33:24.940Z,1397410404.940 [Depth_Keller](ERROR): Pressure reading out of range: 1830.461914 decibar
2014-04-13T17:33:39.963Z,1397410419.963 [Depth_Keller](ERROR): Pressure reading out of range: 1830.482910 decibar
2014-04-13T17:33:59.980Z,1397410439.980 [Default:CallIridium] Running Loop=1
2014-04-13T17:33:59.980Z,1397410439.980 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-04-13T17:33:59.980Z,1397410439.980 [Default:CallIridium:A] Running Loop=1
2014-04-13T17:33:59.981Z,1397410439.981 [Default:CallIridium:A] Stopped
2014-04-13T17:33:59.981Z,1397410439.981 [Default:CallIridium:B] Running Loop=1
2014-04-13T17:33:59.981Z,1397410439.981 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-04-13T17:34:05.004Z,1397410445.004 [Default:Iridium] Running Loop=1
2014-04-13T17:34:05.004Z,1397410445.004 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-04-13T17:34:05.008Z,1397410445.008 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-04-13T17:34:05.008Z,1397410445.008 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-04-13T17:34:05.008Z,1397410445.008 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-04-13T17:34:05.009Z,1397410445.009 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-13T17:34:05.009Z,1397410445.009 [Default:Iridium:B.GoToSurface] Stopped
2014-04-13T17:34:05.009Z,1397410445.009 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-13T17:34:05.009Z,1397410445.009 [Default:Iridium:Read_Iridium] Running Loop=1
2014-04-13T17:34:05.010Z,1397410445.010 [Default:GPS] Running Loop=1
2014-04-13T17:34:05.010Z,1397410445.010 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-04-13T17:34:05.010Z,1397410445.010 [Default:GPS:A.SetSpeed] Running Loop=1
2014-04-13T17:34:05.010Z,1397410445.010 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-04-13T17:34:05.010Z,1397410445.010 [Default:GPS:B.GoToSurface] Running Loop=1
2014-04-13T17:34:05.010Z,1397410445.010 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-13T17:34:05.011Z,1397410445.011 [Default:GPS:B.GoToSurface] Stopped
2014-04-13T17:34:05.011Z,1397410445.011 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-13T17:34:05.011Z,1397410445.011 [Default:GPS:Read_GPS] Running Loop=1
2014-04-13T17:34:06.533Z,1397410446.533 [NAL9602](INFO): Powering up
2014-04-13T17:34:17.328Z,1397410457.328 [NAL9602](INFO): NAL9602 initialized
2014-04-13T17:34:36.809Z,1397410476.809 [NAL9602](INFO): SBD MO Status=1, MOMSN=25463, MT Status=0, MTMSN=0
2014-04-13T17:34:36.858Z,1397410476.858 [NAL9602](INFO): Sent 75 bytes from file Logs/20140413T163946/Courier0036.lzma
2014-04-13T17:34:36.858Z,1397410476.858 [NAL9602](INFO): Packets left to send: 0
2014-04-13T17:34:36.860Z,1397410476.860 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T163946/Courier0036.lzma.parts/0000.sbd
2014-04-13T17:34:36.860Z,1397410476.860 [NAL9602](INFO): Completed sending Logs/20140413T163946/Courier0036.lzma
2014-04-13T17:34:49.477Z,1397410489.477 [NAL9602](INFO): SBD MO Status=1, MOMSN=25464, MT Status=0, MTMSN=0
2014-04-13T17:34:49.538Z,1397410489.538 [NAL9602](INFO): Sent 321 bytes from file Logs/20140413T163946/Express0037.lzma
2014-04-13T17:34:49.538Z,1397410489.538 [NAL9602](INFO): Packets left to send: 0
2014-04-13T17:34:49.539Z,1397410489.539 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T163946/Express0037.lzma.parts/0000.sbd
2014-04-13T17:34:49.540Z,1397410489.540 [NAL9602](INFO): Completed sending Logs/20140413T163946/Express0037.lzma
2014-04-13T17:35:00.354Z,1397410500.354 [NAL9602](INFO): SBD MO Status=0, MOMSN=25465, MT Status=0, MTMSN=0
2014-04-13T17:35:00.454Z,1397410500.454 [Default:Iridium:Read_Iridium] Stopped
2014-04-13T17:35:00.455Z,1397410500.455 [Default:Iridium](INFO): Completed Default:Iridium
2014-04-13T17:35:00.455Z,1397410500.455 [Default:Iridium] Stopped
2014-04-13T17:35:00.455Z,1397410500.455 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-04-13T17:35:00.455Z,1397410500.455 [Default:Iridium:A.SetSpeed] Stopped
2014-04-13T17:35:00.455Z,1397410500.455 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-04-13T17:35:00.868Z,1397410500.868 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-04-13T17:35:00.868Z,1397410500.868 [Default:CallIridium:B] Stopped
2014-04-13T17:35:00.869Z,1397410500.869 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-04-13T17:35:00.869Z,1397410500.869 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-04-13T17:35:00.869Z,1397410500.869 [Default:CallIridium] Stopped
2014-04-13T17:35:00.869Z,1397410500.869 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-04-13T17:35:01.717Z,1397410501.717 [NAL9602](IMPORTANT): GPS fix at: 1397410463.00
2014-04-13T17:35:01.754Z,1397410501.754 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07
2014-04-13T17:35:01.758Z,1397410501.758 [Default:GPS:Read_GPS] Stopped
2014-04-13T17:35:01.758Z,1397410501.758 [Default:GPS:D] Running Loop=1
2014-04-13T17:35:02.202Z,1397410502.202 [Default:GPS:D] Stopped
2014-04-13T17:35:02.203Z,1397410502.203 [Default:GPS](INFO): Completed Default:GPS
2014-04-13T17:35:02.203Z,1397410502.203 [Default:GPS] Stopped
2014-04-13T17:35:02.203Z,1397410502.203 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-04-13T17:35:02.203Z,1397410502.203 [Default:GPS:A.SetSpeed] Stopped
2014-04-13T17:35:02.203Z,1397410502.203 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-04-13T17:35:07.763Z,1397410507.763 [Depth_Keller](ERROR): Pressure reading out of range: 1830.473267 decibar
2014-04-13T17:35:17.833Z,1397410517.833 [NAL9602](INFO): Powering down
2014-04-13T17:35:27.783Z,1397410527.783 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T17:35:27.783Z,1397410527.783 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T17:35:27.783Z,1397410527.783 [DVL_micro](ERROR): Data Fault
2014-04-13T17:35:27.859Z,1397410527.859 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T17:35:32.755Z,1397410532.755 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T17:35:37.782Z,1397410537.782 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T17:35:37.782Z,1397410537.782 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T17:35:37.782Z,1397410537.782 [DVL_micro](ERROR): Hardware Fault
2014-04-13T17:35:42.804Z,1397410542.804 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T17:35:42.804Z,1397410542.804 [DVL_micro] No Fault, FailCount= 1
2014-04-13T17:35:47.820Z,1397410547.820 [DVL_micro](INFO): Initializing
2014-04-13T17:36:02.756Z,1397410562.756 [Depth_Keller](ERROR): Pressure reading out of range: 1830.464478 decibar
2014-04-13T17:36:12.764Z,1397410572.764 [Depth_Keller](ERROR): Pressure reading out of range: 1830.477661 decibar
2014-04-13T17:36:22.774Z,1397410582.774 [Depth_Keller](ERROR): Pressure reading out of range: 1830.492432 decibar
2014-04-13T17:36:32.771Z,1397410592.771 [Depth_Keller](ERROR): Pressure reading out of range: 1830.476807 decibar
2014-04-13T17:36:52.741Z,1397410612.741 [Depth_Keller](ERROR): Pressure reading out of range: 1830.482910 decibar
2014-04-13T17:37:07.741Z,1397410627.741 [Depth_Keller](ERROR): Pressure reading out of range: 1830.497681 decibar
2014-04-13T17:37:17.761Z,1397410637.761 [Depth_Keller](ERROR): Pressure reading out of range: 1830.476807 decibar
2014-04-13T17:37:27.815Z,1397410647.815 [Depth_Keller](ERROR): Pressure reading out of range: 1830.465454 decibar
2014-04-13T17:37:42.763Z,1397410662.763 [Depth_Keller](ERROR): Pressure reading out of range: 1830.487183 decibar
2014-04-13T17:37:52.755Z,1397410672.755 [Depth_Keller](ERROR): Pressure reading out of range: 1830.467163 decibar
2014-04-13T17:38:02.759Z,1397410682.759 [Depth_Keller](ERROR): Pressure reading out of range: 1830.478516 decibar
2014-04-13T17:38:12.754Z,1397410692.754 [Depth_Keller](ERROR): Pressure reading out of range: 1830.508179 decibar
2014-04-13T17:38:22.757Z,1397410702.757 [Depth_Keller](ERROR): Pressure reading out of range: 1830.496826 decibar
2014-04-13T17:38:32.769Z,1397410712.769 [Depth_Keller](ERROR): Pressure reading out of range: 1830.495972 decibar
2014-04-13T17:38:42.756Z,1397410722.756 [Depth_Keller](ERROR): Pressure reading out of range: 1830.498535 decibar
2014-04-13T17:38:52.760Z,1397410732.760 [Depth_Keller](ERROR): Pressure reading out of range: 1830.509033 decibar
2014-04-13T17:39:17.760Z,1397410757.760 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T17:39:17.760Z,1397410757.760 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T17:39:17.760Z,1397410757.760 [DVL_micro](ERROR): Data Fault
2014-04-13T17:39:17.823Z,1397410757.823 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T17:39:22.780Z,1397410762.780 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T17:39:27.758Z,1397410767.758 [Depth_Keller](ERROR): Pressure reading out of range: 1830.501221 decibar
2014-04-13T17:39:27.760Z,1397410767.760 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T17:39:27.760Z,1397410767.760 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T17:39:27.760Z,1397410767.760 [DVL_micro](ERROR): Hardware Fault
2014-04-13T17:39:32.860Z,1397410772.860 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T17:39:32.860Z,1397410772.860 [DVL_micro] No Fault, FailCount= 1
2014-04-13T17:39:37.769Z,1397410777.769 [DVL_micro](INFO): Initializing
2014-04-13T17:39:42.762Z,1397410782.762 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#11 STATUS: 65535
2014-04-13T17:39:57.733Z,1397410797.733 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#11 STATUS: 65535
2014-04-13T17:40:02.733Z,1397410802.733 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#11 STATUS: 65535
2014-04-13T17:40:02.774Z,1397410802.774 [Default:CallIridium] Running Loop=1
2014-04-13T17:40:02.775Z,1397410802.775 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-04-13T17:40:02.775Z,1397410802.775 [Default:CallIridium:A] Running Loop=1
2014-04-13T17:40:02.775Z,1397410802.775 [Default:CallIridium:A] Stopped
2014-04-13T17:40:02.775Z,1397410802.775 [Default:CallIridium:B] Running Loop=1
2014-04-13T17:40:02.776Z,1397410802.776 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-04-13T17:40:07.807Z,1397410807.807 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#11 STATUS: 65535
2014-04-13T17:40:07.871Z,1397410807.871 [Default:Iridium] Running Loop=1
2014-04-13T17:40:07.871Z,1397410807.871 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-04-13T17:40:07.872Z,1397410807.872 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-04-13T17:40:07.872Z,1397410807.872 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-04-13T17:40:07.872Z,1397410807.872 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-04-13T17:40:07.872Z,1397410807.872 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-13T17:40:07.873Z,1397410807.873 [Default:Iridium:B.GoToSurface] Stopped
2014-04-13T17:40:07.873Z,1397410807.873 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-13T17:40:07.873Z,1397410807.873 [Default:Iridium:Read_Iridium] Running Loop=1
2014-04-13T17:40:07.873Z,1397410807.873 [Default:GPS] Running Loop=1
2014-04-13T17:40:07.873Z,1397410807.873 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-04-13T17:40:07.873Z,1397410807.873 [Default:GPS:A.SetSpeed] Running Loop=1
2014-04-13T17:40:07.873Z,1397410807.873 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-04-13T17:40:07.874Z,1397410807.874 [Default:GPS:B.GoToSurface] Running Loop=1
2014-04-13T17:40:07.874Z,1397410807.874 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-13T17:40:07.874Z,1397410807.874 [Default:GPS:B.GoToSurface] Stopped
2014-04-13T17:40:07.874Z,1397410807.874 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-13T17:40:07.877Z,1397410807.877 [Default:GPS:Read_GPS] Running Loop=1
2014-04-13T17:40:09.456Z,1397410809.456 [NAL9602](INFO): Powering up
2014-04-13T17:40:09.886Z,1397410809.886 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#11 STATUS: 65535
2014-04-13T17:40:11.962Z,1397410811.962 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#11 STATUS: 65535
2014-04-13T17:40:14.543Z,1397410814.543 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#11 STATUS: 65535
2014-04-13T17:40:17.039Z,1397410817.039 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#11 STATUS: 65535
2014-04-13T17:40:19.222Z,1397410819.222 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#11 STATUS: 65535
2014-04-13T17:40:20.198Z,1397410820.198 [NAL9602](INFO): NAL9602 initialized
2014-04-13T17:40:36.620Z,1397410836.620 [NAL9602](INFO): SBD MO Status=1, MOMSN=25466, MT Status=0, MTMSN=0
2014-04-13T17:40:36.668Z,1397410836.668 [NAL9602](INFO): Sent 74 bytes from file Logs/20140413T163946/Courier0040.lzma
2014-04-13T17:40:36.668Z,1397410836.668 [NAL9602](INFO): Packets left to send: 0
2014-04-13T17:40:36.670Z,1397410836.670 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T163946/Courier0040.lzma.parts/0000.sbd
2014-04-13T17:40:36.670Z,1397410836.670 [NAL9602](INFO): Completed sending Logs/20140413T163946/Courier0040.lzma
2014-04-13T17:40:45.973Z,1397410845.973 [NAL9602](INFO): SBD MO Status=1, MOMSN=25467, MT Status=0, MTMSN=0
2014-04-13T17:40:46.026Z,1397410846.026 [NAL9602](INFO): Sent 230 bytes from file Logs/20140413T163946/Express0041.lzma
2014-04-13T17:40:46.026Z,1397410846.026 [NAL9602](INFO): Packets left to send: 0
2014-04-13T17:40:46.028Z,1397410846.028 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T163946/Express0041.lzma.parts/0000.sbd
2014-04-13T17:40:46.028Z,1397410846.028 [NAL9602](INFO): Completed sending Logs/20140413T163946/Express0041.lzma
2014-04-13T17:40:54.611Z,1397410854.611 [NAL9602](INFO): SBD MO Status=0, MOMSN=25468, MT Status=0, MTMSN=0
2014-04-13T17:40:54.714Z,1397410854.714 [Default:Iridium:Read_Iridium] Stopped
2014-04-13T17:40:54.714Z,1397410854.714 [Default:Iridium](INFO): Completed Default:Iridium
2014-04-13T17:40:54.714Z,1397410854.714 [Default:Iridium] Stopped
2014-04-13T17:40:54.714Z,1397410854.714 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-04-13T17:40:54.714Z,1397410854.714 [Default:Iridium:A.SetSpeed] Stopped
2014-04-13T17:40:54.714Z,1397410854.714 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-04-13T17:40:55.315Z,1397410855.315 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-04-13T17:40:55.315Z,1397410855.315 [Default:CallIridium:B] Stopped
2014-04-13T17:40:55.315Z,1397410855.315 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-04-13T17:40:55.315Z,1397410855.315 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-04-13T17:40:55.316Z,1397410855.316 [Default:CallIridium] Stopped
2014-04-13T17:40:55.316Z,1397410855.316 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-04-13T17:40:56.151Z,1397410856.151 [NAL9602](IMPORTANT): GPS fix at: 1397410818.00
2014-04-13T17:40:56.165Z,1397410856.165 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07
2014-04-13T17:40:56.169Z,1397410856.169 [Default:GPS:Read_GPS] Stopped
2014-04-13T17:40:56.169Z,1397410856.169 [Default:GPS:D] Running Loop=1
2014-04-13T17:40:56.648Z,1397410856.648 [Default:GPS:D] Stopped
2014-04-13T17:40:56.648Z,1397410856.648 [Default:GPS](INFO): Completed Default:GPS
2014-04-13T17:40:56.648Z,1397410856.648 [Default:GPS] Stopped
2014-04-13T17:40:56.648Z,1397410856.648 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-04-13T17:40:56.649Z,1397410856.649 [Default:GPS:A.SetSpeed] Stopped
2014-04-13T17:40:56.649Z,1397410856.649 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-04-13T17:41:17.229Z,1397410877.229 [NAL9602](INFO): Powering down
2014-04-13T17:44:02.250Z,1397411042.250 [Radio_Freewave](INFO): Powering down
2014-04-13T17:44:12.262Z,1397411052.262 [Radio_Freewave](INFO): Powering up
2014-04-13T17:44:17.237Z,1397411057.237 [Radio_Freewave](IMPORTANT): Starting PPPD with command:/sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0
2014-04-13T17:45:57.236Z,1397411157.236 [Default:CallIridium] Running Loop=1
2014-04-13T17:45:57.236Z,1397411157.236 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-04-13T17:45:57.236Z,1397411157.236 [Default:CallIridium:A] Running Loop=1
2014-04-13T17:45:57.237Z,1397411157.237 [Default:CallIridium:A] Stopped
2014-04-13T17:45:57.237Z,1397411157.237 [Default:CallIridium:B] Running Loop=1
2014-04-13T17:45:57.237Z,1397411157.237 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-04-13T17:46:02.344Z,1397411162.344 [Default:Iridium] Running Loop=1
2014-04-13T17:46:02.345Z,1397411162.345 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-04-13T17:46:02.345Z,1397411162.345 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-04-13T17:46:02.345Z,1397411162.345 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-04-13T17:46:02.345Z,1397411162.345 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-04-13T17:46:02.345Z,1397411162.345 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-13T17:46:02.346Z,1397411162.346 [Default:Iridium:B.GoToSurface] Stopped
2014-04-13T17:46:02.346Z,1397411162.346 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-13T17:46:02.346Z,1397411162.346 [Default:Iridium:Read_Iridium] Running Loop=1
2014-04-13T17:46:02.346Z,1397411162.346 [Default:GPS] Running Loop=1
2014-04-13T17:46:02.347Z,1397411162.347 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-04-13T17:46:02.347Z,1397411162.347 [Default:GPS:A.SetSpeed] Running Loop=1
2014-04-13T17:46:02.347Z,1397411162.347 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-04-13T17:46:02.347Z,1397411162.347 [Default:GPS:B.GoToSurface] Running Loop=1
2014-04-13T17:46:02.347Z,1397411162.347 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-13T17:46:02.348Z,1397411162.348 [Default:GPS:B.GoToSurface] Stopped
2014-04-13T17:46:02.348Z,1397411162.348 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-13T17:46:02.348Z,1397411162.348 [Default:GPS:Read_GPS] Running Loop=1
2014-04-13T17:46:03.850Z,1397411163.850 [NAL9602](INFO): Powering up
2014-04-13T17:46:14.691Z,1397411174.691 [NAL9602](INFO): NAL9602 initialized
2014-04-13T17:46:38.905Z,1397411198.905 [NAL9602](INFO): SBD MO Status=1, MOMSN=25469, MT Status=0, MTMSN=0
2014-04-13T17:46:38.953Z,1397411198.953 [NAL9602](INFO): Sent 75 bytes from file Logs/20140413T163946/Courier0044.lzma
2014-04-13T17:46:38.954Z,1397411198.954 [NAL9602](INFO): Packets left to send: 0
2014-04-13T17:46:38.955Z,1397411198.955 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T163946/Courier0044.lzma.parts/0000.sbd
2014-04-13T17:46:38.956Z,1397411198.956 [NAL9602](INFO): Completed sending Logs/20140413T163946/Courier0044.lzma
2014-04-13T17:46:53.328Z,1397411213.328 [NAL9602](INFO): SBD MO Status=1, MOMSN=25470, MT Status=0, MTMSN=0
2014-04-13T17:46:53.376Z,1397411213.376 [NAL9602](INFO): Sent 332 bytes from file Logs/20140413T163946/Express0045.lzma
2014-04-13T17:46:53.376Z,1397411213.376 [NAL9602](INFO): Packets left to send: 1
2014-04-13T17:46:53.378Z,1397411213.378 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T163946/Express0045.lzma.parts/0001.sbd
2014-04-13T17:47:00.083Z,1397411220.083 [NAL9602](INFO): SBD MO Status=1, MOMSN=25471, MT Status=0, MTMSN=0
2014-04-13T17:47:00.130Z,1397411220.130 [NAL9602](INFO): Sent 20 bytes from file Logs/20140413T163946/Express0045.lzma
2014-04-13T17:47:00.131Z,1397411220.131 [NAL9602](INFO): Packets left to send: 0
2014-04-13T17:47:00.132Z,1397411220.132 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T163946/Express0045.lzma.parts/0000.sbd
2014-04-13T17:47:00.132Z,1397411220.132 [NAL9602](INFO): Completed sending Logs/20140413T163946/Express0045.lzma
2014-04-13T17:47:02.335Z,1397411222.335 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T17:47:02.335Z,1397411222.335 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T17:47:02.335Z,1397411222.335 [DVL_micro](ERROR): Data Fault
2014-04-13T17:47:02.369Z,1397411222.369 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T17:47:02.744Z,1397411222.744 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T17:47:03.215Z,1397411223.215 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T17:47:03.215Z,1397411223.215 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T17:47:03.215Z,1397411223.215 [DVL_micro](ERROR): Hardware Fault
2014-04-13T17:47:03.678Z,1397411223.678 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T17:47:03.678Z,1397411223.678 [DVL_micro] No Fault, FailCount= 1
2014-04-13T17:47:04.072Z,1397411224.072 [DVL_micro](INFO): Initializing
2014-04-13T17:47:17.144Z,1397411237.144 [NAL9602](INFO): SBD MO Status=0, MOMSN=25472, MT Status=0, MTMSN=0
2014-04-13T17:47:17.245Z,1397411237.245 [Default:Iridium:Read_Iridium] Stopped
2014-04-13T17:47:17.246Z,1397411237.246 [Default:Iridium](INFO): Completed Default:Iridium
2014-04-13T17:47:17.246Z,1397411237.246 [Default:Iridium] Stopped
2014-04-13T17:47:17.246Z,1397411237.246 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-04-13T17:47:17.246Z,1397411237.246 [Default:Iridium:A.SetSpeed] Stopped
2014-04-13T17:47:17.246Z,1397411237.246 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-04-13T17:47:17.654Z,1397411237.654 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-04-13T17:47:17.654Z,1397411237.654 [Default:CallIridium:B] Stopped
2014-04-13T17:47:17.654Z,1397411237.654 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-04-13T17:47:17.654Z,1397411237.654 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-04-13T17:47:17.654Z,1397411237.654 [Default:CallIridium] Stopped
2014-04-13T17:47:17.654Z,1397411237.654 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-04-13T17:47:18.445Z,1397411238.445 [NAL9602](IMPORTANT): GPS fix at: 1397411200.00
2014-04-13T17:47:18.459Z,1397411238.459 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07
2014-04-13T17:47:18.463Z,1397411238.463 [Default:GPS:Read_GPS] Stopped
2014-04-13T17:47:18.463Z,1397411238.463 [Default:GPS:D] Running Loop=1
2014-04-13T17:47:18.873Z,1397411238.873 [Default:GPS:D] Stopped
2014-04-13T17:47:18.873Z,1397411238.873 [Default:GPS](INFO): Completed Default:GPS
2014-04-13T17:47:18.874Z,1397411238.874 [Default:GPS] Stopped
2014-04-13T17:47:18.874Z,1397411238.874 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-04-13T17:47:18.874Z,1397411238.874 [Default:GPS:A.SetSpeed] Stopped
2014-04-13T17:47:18.874Z,1397411238.874 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-04-13T17:47:39.454Z,1397411259.454 [NAL9602](INFO): Powering down
2014-04-13T17:50:14.433Z,1397411414.433 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T17:50:14.433Z,1397411414.433 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T17:50:14.433Z,1397411414.433 [DVL_micro](ERROR): Data Fault
2014-04-13T17:50:14.466Z,1397411414.466 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T17:50:19.446Z,1397411419.446 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T17:50:24.436Z,1397411424.436 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T17:50:24.436Z,1397411424.436 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T17:50:24.436Z,1397411424.436 [DVL_micro](ERROR): Hardware Fault
2014-04-13T17:50:29.470Z,1397411429.470 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T17:50:29.470Z,1397411429.470 [DVL_micro] No Fault, FailCount= 1
2014-04-13T17:50:34.448Z,1397411434.448 [DVL_micro](INFO): Initializing
2014-04-13T17:52:19.449Z,1397411539.449 [Default:CallIridium] Running Loop=1
2014-04-13T17:52:19.450Z,1397411539.450 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-04-13T17:52:19.450Z,1397411539.450 [Default:CallIridium:A] Running Loop=1
2014-04-13T17:52:19.450Z,1397411539.450 [Default:CallIridium:A] Stopped
2014-04-13T17:52:19.450Z,1397411539.450 [Default:CallIridium:B] Running Loop=1
2014-04-13T17:52:19.450Z,1397411539.450 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-04-13T17:52:24.553Z,1397411544.553 [Default:Iridium] Running Loop=1
2014-04-13T17:52:24.553Z,1397411544.553 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-04-13T17:52:24.553Z,1397411544.553 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-04-13T17:52:24.553Z,1397411544.553 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-04-13T17:52:24.553Z,1397411544.553 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-04-13T17:52:24.553Z,1397411544.553 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-13T17:52:24.554Z,1397411544.554 [Default:Iridium:B.GoToSurface] Stopped
2014-04-13T17:52:24.554Z,1397411544.554 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-13T17:52:24.554Z,1397411544.554 [Default:Iridium:Read_Iridium] Running Loop=1
2014-04-13T17:52:24.555Z,1397411544.555 [Default:GPS] Running Loop=1
2014-04-13T17:52:24.555Z,1397411544.555 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-04-13T17:52:24.555Z,1397411544.555 [Default:GPS:A.SetSpeed] Running Loop=1
2014-04-13T17:52:24.555Z,1397411544.555 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-04-13T17:52:24.555Z,1397411544.555 [Default:GPS:B.GoToSurface] Running Loop=1
2014-04-13T17:52:24.555Z,1397411544.555 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-13T17:52:24.556Z,1397411544.556 [Default:GPS:B.GoToSurface] Stopped
2014-04-13T17:52:24.556Z,1397411544.556 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-13T17:52:24.556Z,1397411544.556 [Default:GPS:Read_GPS] Running Loop=1
2014-04-13T17:52:26.037Z,1397411546.037 [NAL9602](INFO): Powering up
2014-04-13T17:52:36.748Z,1397411556.748 [NAL9602](INFO): NAL9602 initialized
2014-04-13T17:52:55.934Z,1397411575.934 [NAL9602](INFO): SBD MO Status=1, MOMSN=25473, MT Status=0, MTMSN=0
2014-04-13T17:52:55.982Z,1397411575.982 [NAL9602](INFO): Sent 77 bytes from file Logs/20140413T163946/Courier0048.lzma
2014-04-13T17:52:55.982Z,1397411575.982 [NAL9602](INFO): Packets left to send: 0
2014-04-13T17:52:55.984Z,1397411575.984 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T163946/Courier0048.lzma.parts/0000.sbd
2014-04-13T17:52:55.984Z,1397411575.984 [NAL9602](INFO): Completed sending Logs/20140413T163946/Courier0048.lzma
2014-04-13T17:53:08.525Z,1397411588.525 [NAL9602](INFO): SBD MO Status=1, MOMSN=25474, MT Status=0, MTMSN=0
2014-04-13T17:53:08.574Z,1397411588.574 [NAL9602](INFO): Sent 200 bytes from file Logs/20140413T163946/Express0049.lzma
2014-04-13T17:53:08.574Z,1397411588.574 [NAL9602](INFO): Packets left to send: 0
2014-04-13T17:53:08.576Z,1397411588.576 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T163946/Express0049.lzma.parts/0000.sbd
2014-04-13T17:53:08.576Z,1397411588.576 [NAL9602](INFO): Completed sending Logs/20140413T163946/Express0049.lzma
2014-04-13T17:53:16.910Z,1397411596.910 [NAL9602](INFO): SBD MO Status=0, MOMSN=25475, MT Status=0, MTMSN=0
2014-04-13T17:53:17.027Z,1397411597.027 [Default:Iridium:Read_Iridium] Stopped
2014-04-13T17:53:17.027Z,1397411597.027 [Default:Iridium](INFO): Completed Default:Iridium
2014-04-13T17:53:17.027Z,1397411597.027 [Default:Iridium] Stopped
2014-04-13T17:53:17.027Z,1397411597.027 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-04-13T17:53:17.028Z,1397411597.028 [Default:Iridium:A.SetSpeed] Stopped
2014-04-13T17:53:17.028Z,1397411597.028 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-04-13T17:53:17.413Z,1397411597.413 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-04-13T17:53:17.413Z,1397411597.413 [Default:CallIridium:B] Stopped
2014-04-13T17:53:17.413Z,1397411597.413 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-04-13T17:53:17.413Z,1397411597.413 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-04-13T17:53:17.413Z,1397411597.413 [Default:CallIridium] Stopped
2014-04-13T17:53:17.413Z,1397411597.413 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-04-13T17:53:18.226Z,1397411598.226 [NAL9602](IMPORTANT): GPS fix at: 1397411560.00
2014-04-13T17:53:18.239Z,1397411598.239 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07
2014-04-13T17:53:18.244Z,1397411598.244 [Default:GPS:Read_GPS] Stopped
2014-04-13T17:53:18.244Z,1397411598.244 [Default:GPS:D] Running Loop=1
2014-04-13T17:53:18.711Z,1397411598.711 [Default:GPS:D] Stopped
2014-04-13T17:53:18.712Z,1397411598.712 [Default:GPS](INFO): Completed Default:GPS
2014-04-13T17:53:18.712Z,1397411598.712 [Default:GPS] Stopped
2014-04-13T17:53:18.712Z,1397411598.712 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-04-13T17:53:18.712Z,1397411598.712 [Default:GPS:A.SetSpeed] Stopped
2014-04-13T17:53:18.712Z,1397411598.712 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-04-13T17:53:39.309Z,1397411619.309 [NAL9602](INFO): Powering down
2014-04-13T17:53:59.270Z,1397411639.270 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T17:53:59.270Z,1397411639.270 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T17:53:59.271Z,1397411639.271 [DVL_micro](ERROR): Data Fault
2014-04-13T17:53:59.314Z,1397411639.314 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T17:54:04.286Z,1397411644.286 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T17:54:09.282Z,1397411649.282 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T17:54:09.282Z,1397411649.282 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T17:54:09.282Z,1397411649.282 [DVL_micro](ERROR): Hardware Fault
2014-04-13T17:54:14.363Z,1397411654.363 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T17:54:14.363Z,1397411654.363 [DVL_micro] No Fault, FailCount= 1
2014-04-13T17:54:19.280Z,1397411659.280 [DVL_micro](INFO): Initializing
2014-04-13T17:57:49.258Z,1397411869.258 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T17:57:49.258Z,1397411869.258 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T17:57:49.258Z,1397411869.258 [DVL_micro](ERROR): Data Fault
2014-04-13T17:57:49.302Z,1397411869.302 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T17:57:54.275Z,1397411874.275 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T17:57:59.274Z,1397411879.274 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T17:57:59.274Z,1397411879.274 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T17:57:59.274Z,1397411879.274 [DVL_micro](ERROR): Hardware Fault
2014-04-13T17:58:04.336Z,1397411884.336 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T17:58:04.337Z,1397411884.337 [DVL_micro] No Fault, FailCount= 1
2014-04-13T17:58:09.343Z,1397411889.343 [DVL_micro](INFO): Initializing
2014-04-13T17:58:19.351Z,1397411899.351 [Default:CallIridium] Running Loop=1
2014-04-13T17:58:19.351Z,1397411899.351 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-04-13T17:58:19.351Z,1397411899.351 [Default:CallIridium:A] Running Loop=1
2014-04-13T17:58:19.352Z,1397411899.352 [Default:CallIridium:A] Stopped
2014-04-13T17:58:19.352Z,1397411899.352 [Default:CallIridium:B] Running Loop=1
2014-04-13T17:58:19.352Z,1397411899.352 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-04-13T17:58:24.348Z,1397411904.348 [Default:Iridium] Running Loop=1
2014-04-13T17:58:24.348Z,1397411904.348 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-04-13T17:58:24.348Z,1397411904.348 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-04-13T17:58:24.348Z,1397411904.348 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-04-13T17:58:24.348Z,1397411904.348 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-04-13T17:58:24.348Z,1397411904.348 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-13T17:58:24.349Z,1397411904.349 [Default:Iridium:B.GoToSurface] Stopped
2014-04-13T17:58:24.349Z,1397411904.349 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-13T17:58:24.349Z,1397411904.349 [Default:Iridium:Read_Iridium] Running Loop=1
2014-04-13T17:58:24.350Z,1397411904.350 [Default:GPS] Running Loop=1
2014-04-13T17:58:24.350Z,1397411904.350 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-04-13T17:58:24.350Z,1397411904.350 [Default:GPS:A.SetSpeed] Running Loop=1
2014-04-13T17:58:24.350Z,1397411904.350 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-04-13T17:58:24.350Z,1397411904.350 [Default:GPS:B.GoToSurface] Running Loop=1
2014-04-13T17:58:24.350Z,1397411904.350 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-13T17:58:24.351Z,1397411904.351 [Default:GPS:B.GoToSurface] Stopped
2014-04-13T17:58:24.351Z,1397411904.351 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-13T17:58:24.351Z,1397411904.351 [Default:GPS:Read_GPS] Running Loop=1
2014-04-13T17:58:25.779Z,1397411905.779 [NAL9602](INFO): Powering up
2014-04-13T17:58:36.355Z,1397411916.355 [NAL9602](INFO): NAL9602 initialized
2014-04-13T17:59:49.772Z,1397411989.772 [NAL9602](IMPORTANT): GPS fix at: 1397411951.00
2014-04-13T17:59:49.785Z,1397411989.785 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07
2014-04-13T17:59:49.790Z,1397411989.790 [Default:GPS:Read_GPS] Stopped
2014-04-13T17:59:49.790Z,1397411989.790 [Default:GPS:D] Running Loop=1
2014-04-13T17:59:50.261Z,1397411990.261 [Default:GPS:D] Stopped
2014-04-13T17:59:50.262Z,1397411990.262 [Default:GPS](INFO): Completed Default:GPS
2014-04-13T17:59:50.262Z,1397411990.262 [Default:GPS] Stopped
2014-04-13T17:59:50.262Z,1397411990.262 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-04-13T17:59:50.262Z,1397411990.262 [Default:GPS:A.SetSpeed] Stopped
2014-04-13T17:59:50.262Z,1397411990.262 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-04-13T18:00:24.673Z,1397412024.673 [NAL9602](INFO): SBD MO Status=2, MOMSN=25476, MT Status=2, MTMSN=0
2014-04-13T18:00:24.674Z,1397412024.674 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-04-13T18:00:53.818Z,1397412053.818 [NAL9602](INFO): SBD MO Status=2, MOMSN=25476, MT Status=2, MTMSN=0
2014-04-13T18:00:53.823Z,1397412053.823 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-04-13T18:01:26.258Z,1397412086.258 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T18:01:26.258Z,1397412086.258 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T18:01:26.258Z,1397412086.258 [DVL_micro](ERROR): Data Fault
2014-04-13T18:01:28.339Z,1397412088.339 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T18:01:28.771Z,1397412088.771 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T18:01:29.220Z,1397412089.220 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T18:01:29.220Z,1397412089.220 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T18:01:29.220Z,1397412089.220 [DVL_micro](ERROR): Hardware Fault
2014-04-13T18:01:29.758Z,1397412089.758 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T18:01:29.758Z,1397412089.758 [DVL_micro] No Fault, FailCount= 1
2014-04-13T18:01:30.137Z,1397412090.137 [DVL_micro](INFO): Initializing
2014-04-13T18:01:49.426Z,1397412109.426 [NAL9602](INFO): SBD MO Status=2, MOMSN=25476, MT Status=2, MTMSN=0
2014-04-13T18:01:49.426Z,1397412109.426 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-04-13T18:02:16.159Z,1397412136.159 [NAL9602](INFO): SBD MO Status=2, MOMSN=25476, MT Status=2, MTMSN=0
2014-04-13T18:02:16.159Z,1397412136.159 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-04-13T18:02:38.324Z,1397412158.324 [NAL9602](INFO): SBD MO Status=1, MOMSN=25476, MT Status=0, MTMSN=0
2014-04-13T18:02:38.373Z,1397412158.373 [NAL9602](INFO): Sent 75 bytes from file Logs/20140413T163946/Courier0052.lzma
2014-04-13T18:02:38.373Z,1397412158.373 [NAL9602](INFO): Packets left to send: 0
2014-04-13T18:02:38.377Z,1397412158.377 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T163946/Courier0052.lzma.parts/0000.sbd
2014-04-13T18:02:38.377Z,1397412158.377 [NAL9602](INFO): Completed sending Logs/20140413T163946/Courier0052.lzma
2014-04-13T18:02:51.092Z,1397412171.092 [NAL9602](INFO): SBD MO Status=1, MOMSN=25477, MT Status=0, MTMSN=0
2014-04-13T18:02:51.161Z,1397412171.161 [NAL9602](INFO): Sent 192 bytes from file Logs/20140413T163946/Express0053.lzma
2014-04-13T18:02:51.161Z,1397412171.161 [NAL9602](INFO): Packets left to send: 0
2014-04-13T18:02:51.163Z,1397412171.163 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T163946/Express0053.lzma.parts/0000.sbd
2014-04-13T18:02:51.163Z,1397412171.163 [NAL9602](INFO): Completed sending Logs/20140413T163946/Express0053.lzma
2014-04-13T18:02:59.062Z,1397412179.062 [NAL9602](INFO): SBD MO Status=0, MOMSN=25478, MT Status=0, MTMSN=0
2014-04-13T18:02:59.162Z,1397412179.162 [Default:Iridium:Read_Iridium] Stopped
2014-04-13T18:02:59.163Z,1397412179.163 [Default:Iridium](INFO): Completed Default:Iridium
2014-04-13T18:02:59.163Z,1397412179.163 [Default:Iridium] Stopped
2014-04-13T18:02:59.163Z,1397412179.163 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-04-13T18:02:59.163Z,1397412179.163 [Default:Iridium:A.SetSpeed] Stopped
2014-04-13T18:02:59.163Z,1397412179.163 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-04-13T18:02:59.571Z,1397412179.571 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-04-13T18:02:59.571Z,1397412179.571 [Default:CallIridium:B] Stopped
2014-04-13T18:02:59.571Z,1397412179.571 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-04-13T18:02:59.571Z,1397412179.571 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-04-13T18:02:59.571Z,1397412179.571 [Default:CallIridium] Stopped
2014-04-13T18:02:59.571Z,1397412179.571 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-04-13T18:03:09.728Z,1397412189.728 [NAL9602](INFO): Powering down
2014-04-13T18:04:34.700Z,1397412274.700 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T18:04:34.700Z,1397412274.700 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T18:04:34.700Z,1397412274.700 [DVL_micro](ERROR): Data Fault
2014-04-13T18:04:34.779Z,1397412274.779 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T18:04:39.796Z,1397412279.796 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T18:04:44.726Z,1397412284.726 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T18:04:44.726Z,1397412284.726 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T18:04:44.726Z,1397412284.726 [DVL_micro](ERROR): Hardware Fault
2014-04-13T18:04:49.781Z,1397412289.781 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T18:04:49.781Z,1397412289.781 [DVL_micro] No Fault, FailCount= 1
2014-04-13T18:04:54.749Z,1397412294.749 [DVL_micro](INFO): Initializing
2014-04-13T18:07:59.756Z,1397412479.756 [Default:CallIridium] Running Loop=1
2014-04-13T18:07:59.756Z,1397412479.756 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-04-13T18:07:59.756Z,1397412479.756 [Default:CallIridium:A] Running Loop=1
2014-04-13T18:07:59.756Z,1397412479.756 [Default:CallIridium:A] Stopped
2014-04-13T18:07:59.757Z,1397412479.757 [Default:CallIridium:B] Running Loop=1
2014-04-13T18:07:59.757Z,1397412479.757 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-04-13T18:08:04.798Z,1397412484.798 [Default:Iridium] Running Loop=1
2014-04-13T18:08:04.798Z,1397412484.798 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-04-13T18:08:04.798Z,1397412484.798 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-04-13T18:08:04.798Z,1397412484.798 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-04-13T18:08:04.798Z,1397412484.798 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-04-13T18:08:04.798Z,1397412484.798 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-13T18:08:04.799Z,1397412484.799 [Default:Iridium:B.GoToSurface] Stopped
2014-04-13T18:08:04.799Z,1397412484.799 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-13T18:08:04.799Z,1397412484.799 [Default:Iridium:Read_Iridium] Running Loop=1
2014-04-13T18:08:04.799Z,1397412484.799 [Default:GPS] Running Loop=1
2014-04-13T18:08:04.800Z,1397412484.800 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-04-13T18:08:04.800Z,1397412484.800 [Default:GPS:A.SetSpeed] Running Loop=1
2014-04-13T18:08:04.800Z,1397412484.800 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-04-13T18:08:04.800Z,1397412484.800 [Default:GPS:B.GoToSurface] Running Loop=1
2014-04-13T18:08:04.800Z,1397412484.800 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-13T18:08:04.801Z,1397412484.801 [Default:GPS:B.GoToSurface] Stopped
2014-04-13T18:08:04.801Z,1397412484.801 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-13T18:08:04.801Z,1397412484.801 [Default:GPS:Read_GPS] Running Loop=1
2014-04-13T18:08:06.299Z,1397412486.299 [NAL9602](INFO): Powering up
2014-04-13T18:08:14.976Z,1397412494.976 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T18:08:14.976Z,1397412494.976 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T18:08:14.976Z,1397412494.976 [DVL_micro](ERROR): Data Fault
2014-04-13T18:08:15.038Z,1397412495.038 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T18:08:15.416Z,1397412495.416 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T18:08:15.848Z,1397412495.848 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T18:08:15.848Z,1397412495.848 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T18:08:15.848Z,1397412495.848 [DVL_micro](ERROR): Hardware Fault
2014-04-13T18:08:16.262Z,1397412496.262 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T18:08:16.262Z,1397412496.262 [DVL_micro] No Fault, FailCount= 1
2014-04-13T18:08:16.637Z,1397412496.637 [DVL_micro](INFO): Initializing
2014-04-13T18:08:17.230Z,1397412497.230 [NAL9602](INFO): NAL9602 initialized
2014-04-13T18:08:30.263Z,1397412510.263 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 43 of 46
2014-04-13T18:08:30.263Z,1397412510.263 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0799 -851 -677 -767 2 2 2 2 -162.8 -112.1 -834.3 2 -126.1 -152.2 -834.3 2 -162 -112 -834 2 -126 -152 -834 2 -1.83 -0.99 15.8 -3.0 18.4 0.005 35.0 1489 117
2014-04-13T18:08:35.733Z,1397412515.733 [NAL9602](INFO): SBD MO Status=2, MOMSN=25479, MT Status=2, MTMSN=0
2014-04-13T18:08:35.734Z,1397412515.734 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-04-13T18:09:08.141Z,1397412548.141 [NAL9602](INFO): SBD MO Status=1, MOMSN=25479, MT Status=0, MTMSN=0
2014-04-13T18:09:08.189Z,1397412548.189 [NAL9602](INFO): Sent 75 bytes from file Logs/20140413T163946/Courier0056.lzma
2014-04-13T18:09:08.190Z,1397412548.190 [NAL9602](INFO): Packets left to send: 0
2014-04-13T18:09:08.191Z,1397412548.191 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T163946/Courier0056.lzma.parts/0000.sbd
2014-04-13T18:09:08.192Z,1397412548.192 [NAL9602](INFO): Completed sending Logs/20140413T163946/Courier0056.lzma
2014-04-13T18:09:19.270Z,1397412559.270 [NAL9602](INFO): SBD MO Status=1, MOMSN=25480, MT Status=0, MTMSN=0
2014-04-13T18:09:19.319Z,1397412559.319 [NAL9602](INFO): Sent 223 bytes from file Logs/20140413T163946/Express0057.lzma
2014-04-13T18:09:19.319Z,1397412559.319 [NAL9602](INFO): Packets left to send: 0
2014-04-13T18:09:19.321Z,1397412559.321 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T163946/Express0057.lzma.parts/0000.sbd
2014-04-13T18:09:19.321Z,1397412559.321 [NAL9602](INFO): Completed sending Logs/20140413T163946/Express0057.lzma
2014-04-13T18:09:34.756Z,1397412574.756 [NAL9602](INFO): SBD MO Status=2, MOMSN=25481, MT Status=2, MTMSN=0
2014-04-13T18:09:34.756Z,1397412574.756 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-04-13T18:09:36.142Z,1397412576.142 [NAL9602](IMPORTANT): GPS fix at: 1397412538.00
2014-04-13T18:09:36.163Z,1397412576.163 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07
2014-04-13T18:09:36.168Z,1397412576.168 [Default:GPS:Read_GPS] Stopped
2014-04-13T18:09:36.168Z,1397412576.168 [Default:GPS:D] Running Loop=1
2014-04-13T18:09:36.572Z,1397412576.572 [Default:GPS:D] Stopped
2014-04-13T18:09:36.573Z,1397412576.573 [Default:GPS](INFO): Completed Default:GPS
2014-04-13T18:09:36.573Z,1397412576.573 [Default:GPS] Stopped
2014-04-13T18:09:36.573Z,1397412576.573 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-04-13T18:09:36.573Z,1397412576.573 [Default:GPS:A.SetSpeed] Stopped
2014-04-13T18:09:36.573Z,1397412576.573 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-04-13T18:09:54.766Z,1397412594.766 [NAL9602](INFO): SBD MO Status=0, MOMSN=25481, MT Status=0, MTMSN=0
2014-04-13T18:09:54.871Z,1397412594.871 [Default:Iridium:Read_Iridium] Stopped
2014-04-13T18:09:54.871Z,1397412594.871 [Default:Iridium](INFO): Completed Default:Iridium
2014-04-13T18:09:54.871Z,1397412594.871 [Default:Iridium] Stopped
2014-04-13T18:09:54.871Z,1397412594.871 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-04-13T18:09:54.872Z,1397412594.872 [Default:Iridium:A.SetSpeed] Stopped
2014-04-13T18:09:54.872Z,1397412594.872 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-04-13T18:09:55.273Z,1397412595.273 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-04-13T18:09:55.273Z,1397412595.273 [Default:CallIridium:B] Stopped
2014-04-13T18:09:55.274Z,1397412595.274 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-04-13T18:09:55.274Z,1397412595.274 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-04-13T18:09:55.274Z,1397412595.274 [Default:CallIridium] Stopped
2014-04-13T18:09:55.274Z,1397412595.274 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-04-13T18:10:05.461Z,1397412605.461 [NAL9602](INFO): Powering down
2014-04-13T18:11:30.472Z,1397412690.472 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T18:11:30.472Z,1397412690.472 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T18:11:30.472Z,1397412690.472 [DVL_micro](ERROR): Data Fault
2014-04-13T18:11:30.500Z,1397412690.500 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T18:11:35.412Z,1397412695.412 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T18:11:40.435Z,1397412700.435 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T18:11:40.435Z,1397412700.435 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T18:11:40.435Z,1397412700.435 [DVL_micro](ERROR): Hardware Fault
2014-04-13T18:11:45.514Z,1397412705.514 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T18:11:45.514Z,1397412705.514 [DVL_micro] No Fault, FailCount= 1
2014-04-13T18:11:50.421Z,1397412710.421 [DVL_micro](INFO): Initializing
2014-04-13T18:14:55.475Z,1397412895.475 [Default:CallIridium] Running Loop=1
2014-04-13T18:14:55.476Z,1397412895.476 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-04-13T18:14:55.476Z,1397412895.476 [Default:CallIridium:A] Running Loop=1
2014-04-13T18:14:55.476Z,1397412895.476 [Default:CallIridium:A] Stopped
2014-04-13T18:14:55.476Z,1397412895.476 [Default:CallIridium:B] Running Loop=1
2014-04-13T18:14:55.476Z,1397412895.476 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-04-13T18:15:00.498Z,1397412900.498 [Default:Iridium] Running Loop=1
2014-04-13T18:15:00.498Z,1397412900.498 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-04-13T18:15:00.498Z,1397412900.498 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-04-13T18:15:00.498Z,1397412900.498 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-04-13T18:15:00.498Z,1397412900.498 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-04-13T18:15:00.498Z,1397412900.498 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-13T18:15:00.499Z,1397412900.499 [Default:Iridium:B.GoToSurface] Stopped
2014-04-13T18:15:00.499Z,1397412900.499 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-13T18:15:00.499Z,1397412900.499 [Default:Iridium:Read_Iridium] Running Loop=1
2014-04-13T18:15:00.500Z,1397412900.500 [Default:GPS] Running Loop=1
2014-04-13T18:15:00.500Z,1397412900.500 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-04-13T18:15:00.500Z,1397412900.500 [Default:GPS:A.SetSpeed] Running Loop=1
2014-04-13T18:15:00.500Z,1397412900.500 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-04-13T18:15:00.500Z,1397412900.500 [Default:GPS:B.GoToSurface] Running Loop=1
2014-04-13T18:15:00.500Z,1397412900.500 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-13T18:15:00.501Z,1397412900.501 [Default:GPS:B.GoToSurface] Stopped
2014-04-13T18:15:00.501Z,1397412900.501 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-13T18:15:00.501Z,1397412900.501 [Default:GPS:Read_GPS] Running Loop=1
2014-04-13T18:15:02.003Z,1397412902.003 [NAL9602](INFO): Powering up
2014-04-13T18:15:10.569Z,1397412910.569 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T18:15:10.569Z,1397412910.569 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T18:15:10.569Z,1397412910.569 [DVL_micro](ERROR): Data Fault
2014-04-13T18:15:10.610Z,1397412910.610 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T18:15:10.986Z,1397412910.986 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T18:15:11.418Z,1397412911.418 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T18:15:11.418Z,1397412911.418 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T18:15:11.418Z,1397412911.418 [DVL_micro](ERROR): Hardware Fault
2014-04-13T18:15:11.912Z,1397412911.912 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T18:15:11.913Z,1397412911.913 [DVL_micro] No Fault, FailCount= 1
2014-04-13T18:15:12.288Z,1397412912.288 [DVL_micro](INFO): Initializing
2014-04-13T18:15:12.803Z,1397412912.803 [NAL9602](INFO): NAL9602 initialized
2014-04-13T18:15:45.409Z,1397412945.409 [NAL9602](INFO): SBD MO Status=1, MOMSN=25482, MT Status=0, MTMSN=0
2014-04-13T18:15:45.466Z,1397412945.466 [NAL9602](INFO): Sent 75 bytes from file Logs/20140413T163946/Courier0060.lzma
2014-04-13T18:15:45.466Z,1397412945.466 [NAL9602](INFO): Packets left to send: 0
2014-04-13T18:15:45.467Z,1397412945.467 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T163946/Courier0060.lzma.parts/0000.sbd
2014-04-13T18:15:45.468Z,1397412945.468 [NAL9602](INFO): Completed sending Logs/20140413T163946/Courier0060.lzma
2014-04-13T18:16:04.472Z,1397412964.472 [NAL9602](INFO): SBD MO Status=2, MOMSN=25483, MT Status=0, MTMSN=0
2014-04-13T18:16:04.472Z,1397412964.472 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-04-13T18:16:05.718Z,1397412965.718 [NAL9602](IMPORTANT): GPS fix at: 1397412927.00
2014-04-13T18:16:05.732Z,1397412965.732 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07
2014-04-13T18:16:05.737Z,1397412965.737 [Default:GPS:Read_GPS] Stopped
2014-04-13T18:16:05.737Z,1397412965.737 [Default:GPS:D] Running Loop=1
2014-04-13T18:16:06.206Z,1397412966.206 [Default:GPS:D] Stopped
2014-04-13T18:16:06.207Z,1397412966.207 [Default:GPS](INFO): Completed Default:GPS
2014-04-13T18:16:06.207Z,1397412966.207 [Default:GPS] Stopped
2014-04-13T18:16:06.207Z,1397412966.207 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-04-13T18:16:06.207Z,1397412966.207 [Default:GPS:A.SetSpeed] Stopped
2014-04-13T18:16:06.207Z,1397412966.207 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-04-13T18:16:18.961Z,1397412978.961 [NAL9602](INFO): SBD MO Status=1, MOMSN=25483, MT Status=0, MTMSN=0
2014-04-13T18:16:19.009Z,1397412979.009 [NAL9602](INFO): Sent 228 bytes from file Logs/20140413T163946/Express0061.lzma
2014-04-13T18:16:19.009Z,1397412979.009 [NAL9602](INFO): Packets left to send: 0
2014-04-13T18:16:19.011Z,1397412979.011 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T163946/Express0061.lzma.parts/0000.sbd
2014-04-13T18:16:19.011Z,1397412979.011 [NAL9602](INFO): Completed sending Logs/20140413T163946/Express0061.lzma
2014-04-13T18:16:30.787Z,1397412990.787 [NAL9602](INFO): SBD MO Status=2, MOMSN=25484, MT Status=2, MTMSN=0
2014-04-13T18:16:30.788Z,1397412990.788 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-04-13T18:16:41.890Z,1397413001.890 [NAL9602](INFO): SBD MO Status=0, MOMSN=25484, MT Status=0, MTMSN=0
2014-04-13T18:16:42.007Z,1397413002.007 [Default:Iridium:Read_Iridium] Stopped
2014-04-13T18:16:42.008Z,1397413002.008 [Default:Iridium](INFO): Completed Default:Iridium
2014-04-13T18:16:42.008Z,1397413002.008 [Default:Iridium] Stopped
2014-04-13T18:16:42.008Z,1397413002.008 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-04-13T18:16:42.008Z,1397413002.008 [Default:Iridium:A.SetSpeed] Stopped
2014-04-13T18:16:42.008Z,1397413002.008 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-04-13T18:16:42.388Z,1397413002.388 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-04-13T18:16:42.389Z,1397413002.389 [Default:CallIridium:B] Stopped
2014-04-13T18:16:42.389Z,1397413002.389 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-04-13T18:16:42.389Z,1397413002.389 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-04-13T18:16:42.389Z,1397413002.389 [Default:CallIridium] Stopped
2014-04-13T18:16:42.389Z,1397413002.389 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-04-13T18:16:52.562Z,1397413012.562 [NAL9602](INFO): Powering down
2014-04-13T18:18:12.495Z,1397413092.495 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#4 STATUS: 65535
2014-04-13T18:18:17.604Z,1397413097.604 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T18:18:17.604Z,1397413097.604 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T18:18:17.604Z,1397413097.604 [DVL_micro](ERROR): Data Fault
2014-04-13T18:18:17.631Z,1397413097.631 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T18:18:22.578Z,1397413102.578 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T18:18:27.582Z,1397413107.582 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T18:18:27.582Z,1397413107.582 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T18:18:27.582Z,1397413107.582 [DVL_micro](ERROR): Hardware Fault
2014-04-13T18:18:32.623Z,1397413112.623 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T18:18:32.623Z,1397413112.623 [DVL_micro] No Fault, FailCount= 1
2014-04-13T18:18:37.604Z,1397413117.604 [DVL_micro](INFO): Initializing
2014-04-13T18:21:42.666Z,1397413302.666 [Default:CallIridium] Running Loop=1
2014-04-13T18:21:42.666Z,1397413302.666 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-04-13T18:21:42.666Z,1397413302.666 [Default:CallIridium:A] Running Loop=1
2014-04-13T18:21:42.666Z,1397413302.666 [Default:CallIridium:A] Stopped
2014-04-13T18:21:42.666Z,1397413302.666 [Default:CallIridium:B] Running Loop=1
2014-04-13T18:21:42.671Z,1397413302.671 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-04-13T18:21:47.624Z,1397413307.624 [Default:Iridium] Running Loop=1
2014-04-13T18:21:47.624Z,1397413307.624 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-04-13T18:21:47.624Z,1397413307.624 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-04-13T18:21:47.625Z,1397413307.625 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-04-13T18:21:47.625Z,1397413307.625 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-04-13T18:21:47.625Z,1397413307.625 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-13T18:21:47.626Z,1397413307.626 [Default:Iridium:B.GoToSurface] Stopped
2014-04-13T18:21:47.626Z,1397413307.626 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-13T18:21:47.626Z,1397413307.626 [Default:Iridium:Read_Iridium] Running Loop=1
2014-04-13T18:21:47.626Z,1397413307.626 [Default:GPS] Running Loop=1
2014-04-13T18:21:47.626Z,1397413307.626 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-04-13T18:21:47.626Z,1397413307.626 [Default:GPS:A.SetSpeed] Running Loop=1
2014-04-13T18:21:47.626Z,1397413307.626 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-04-13T18:21:47.627Z,1397413307.627 [Default:GPS:B.GoToSurface] Running Loop=1
2014-04-13T18:21:47.627Z,1397413307.627 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-13T18:21:47.627Z,1397413307.627 [Default:GPS:B.GoToSurface] Stopped
2014-04-13T18:21:47.627Z,1397413307.627 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-13T18:21:47.628Z,1397413307.628 [Default:GPS:Read_GPS] Running Loop=1
2014-04-13T18:21:49.131Z,1397413309.131 [NAL9602](INFO): Powering up
2014-04-13T18:21:58.088Z,1397413318.088 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T18:21:58.089Z,1397413318.089 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T18:21:58.089Z,1397413318.089 [DVL_micro](ERROR): Data Fault
2014-04-13T18:21:58.122Z,1397413318.122 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T18:21:58.497Z,1397413318.497 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T18:21:58.957Z,1397413318.957 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T18:21:58.958Z,1397413318.958 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T18:21:58.958Z,1397413318.958 [DVL_micro](ERROR): Hardware Fault
2014-04-13T18:21:59.437Z,1397413319.437 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T18:21:59.437Z,1397413319.437 [DVL_micro] No Fault, FailCount= 1
2014-04-13T18:21:59.832Z,1397413319.832 [DVL_micro](INFO): Initializing
2014-04-13T18:22:00.010Z,1397413320.010 [NAL9602](INFO): NAL9602 initialized
2014-04-13T18:22:16.864Z,1397413336.864 [NAL9602](INFO): SBD MO Status=2, MOMSN=25485, MT Status=2, MTMSN=0
2014-04-13T18:22:16.864Z,1397413336.864 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-04-13T18:22:25.604Z,1397413345.604 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 43 of 46
2014-04-13T18:22:25.604Z,1397413345.604 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 -1218 -847 -660 -768 2 2 2 2 -744.7 -105.4 -941.8 2 -681.3 -318.5 -941.8 2 -744 -105 -941 2 -681 -318 -941 2 -1.68 -0.76 17.0 -3.0 18.7 0.005 35.0 1489 68
2014-04-13T18:25:04.020Z,1397413504.020 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T18:25:04.021Z,1397413504.021 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T18:25:04.021Z,1397413504.021 [DVL_micro](ERROR): Data Fault
2014-04-13T18:25:04.062Z,1397413504.062 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T18:25:04.456Z,1397413504.456 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T18:25:04.878Z,1397413504.878 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T18:25:04.878Z,1397413504.878 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T18:25:04.878Z,1397413504.878 [DVL_micro](ERROR): Hardware Fault
2014-04-13T18:25:05.336Z,1397413505.336 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T18:25:05.336Z,1397413505.336 [DVL_micro] No Fault, FailCount= 1
2014-04-13T18:25:05.726Z,1397413505.726 [DVL_micro](INFO): Initializing
2014-04-13T18:28:10.021Z,1397413690.021 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T18:28:10.021Z,1397413690.021 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T18:28:10.021Z,1397413690.021 [DVL_micro](ERROR): Data Fault
2014-04-13T18:28:10.060Z,1397413690.060 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T18:28:10.479Z,1397413690.479 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T18:28:10.921Z,1397413690.921 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T18:28:10.921Z,1397413690.921 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T18:28:10.921Z,1397413690.921 [DVL_micro](ERROR): Hardware Fault
2014-04-13T18:28:11.368Z,1397413691.368 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T18:28:11.369Z,1397413691.369 [DVL_micro] No Fault, FailCount= 1
2014-04-13T18:28:11.778Z,1397413691.778 [DVL_micro](INFO): Initializing
2014-04-13T18:31:16.250Z,1397413876.250 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T18:31:16.250Z,1397413876.250 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T18:31:16.250Z,1397413876.250 [DVL_micro](ERROR): Data Fault
2014-04-13T18:31:16.297Z,1397413876.297 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T18:31:16.720Z,1397413876.720 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T18:31:17.143Z,1397413877.143 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T18:31:17.143Z,1397413877.143 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T18:31:17.143Z,1397413877.143 [DVL_micro](ERROR): Hardware Fault
2014-04-13T18:31:17.571Z,1397413877.571 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T18:31:17.571Z,1397413877.571 [DVL_micro] No Fault, FailCount= 1
2014-04-13T18:31:17.961Z,1397413877.961 [DVL_micro](INFO): Initializing
2014-04-13T18:32:01.633Z,1397413921.633 [NAL9602](FAULT): GPS failed to acquire within timeout.
2014-04-13T18:32:01.633Z,1397413921.633 [NAL9602] Data Fault, FailCount= 1
2014-04-13T18:32:01.633Z,1397413921.633 [NAL9602](ERROR): Data Fault
2014-04-13T18:32:01.661Z,1397413921.661 [CBIT](ERROR): Data Fault in component: NAL9602
2014-04-13T18:32:02.043Z,1397413922.043 [NAL9602](INFO): Powering down
2014-04-13T18:32:02.903Z,1397413922.903 [CBIT](INFO): Clearing failed state for component NAL9602
2014-04-13T18:32:02.903Z,1397413922.903 [NAL9602] No Fault, FailCount= 1
2014-04-13T18:32:07.252Z,1397413927.252 [NAL9602](INFO): Powering up NAL9602
2014-04-13T18:32:17.984Z,1397413937.984 [NAL9602](INFO): NAL9602 initialized
2014-04-13T18:34:22.135Z,1397414062.135 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T18:34:22.135Z,1397414062.135 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T18:34:22.135Z,1397414062.135 [DVL_micro](ERROR): Data Fault
2014-04-13T18:34:22.180Z,1397414062.180 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T18:34:22.535Z,1397414062.535 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T18:34:23.443Z,1397414063.443 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T18:34:23.443Z,1397414063.443 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T18:34:23.443Z,1397414063.443 [DVL_micro](ERROR): Hardware Fault
2014-04-13T18:34:24.266Z,1397414064.266 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T18:34:24.267Z,1397414064.267 [DVL_micro] No Fault, FailCount= 1
2014-04-13T18:34:24.643Z,1397414064.643 [DVL_micro](INFO): Initializing
2014-04-13T18:37:29.737Z,1397414249.737 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T18:37:29.737Z,1397414249.737 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T18:37:29.737Z,1397414249.737 [DVL_micro](ERROR): Data Fault
2014-04-13T18:37:29.808Z,1397414249.808 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T18:37:30.165Z,1397414250.165 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T18:37:30.577Z,1397414250.577 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T18:37:30.577Z,1397414250.577 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T18:37:30.577Z,1397414250.577 [DVL_micro](ERROR): Hardware Fault
2014-04-13T18:37:30.997Z,1397414250.997 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T18:37:30.997Z,1397414250.997 [DVL_micro] No Fault, FailCount= 1
2014-04-13T18:37:31.442Z,1397414251.442 [DVL_micro](INFO): Initializing
2014-04-13T18:40:36.066Z,1397414436.066 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T18:40:36.066Z,1397414436.066 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T18:40:36.066Z,1397414436.066 [DVL_micro](ERROR): Data Fault
2014-04-13T18:40:36.094Z,1397414436.094 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T18:40:36.467Z,1397414436.467 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T18:40:36.891Z,1397414436.891 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T18:40:36.891Z,1397414436.891 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T18:40:36.891Z,1397414436.891 [DVL_micro](ERROR): Hardware Fault
2014-04-13T18:40:37.402Z,1397414437.402 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T18:40:37.402Z,1397414437.402 [DVL_micro] No Fault, FailCount= 1
2014-04-13T18:40:37.819Z,1397414437.819 [DVL_micro](INFO): Initializing
2014-04-13T18:42:21.490Z,1397414541.490 [NAL9602](FAULT): GPS failed to acquire within timeout.
2014-04-13T18:42:21.490Z,1397414541.490 [NAL9602] Data Fault, FailCount= 2
2014-04-13T18:42:21.490Z,1397414541.490 [NAL9602](ERROR): Data Fault
2014-04-13T18:42:21.517Z,1397414541.517 [CBIT](ERROR): Data Fault in component: NAL9602
2014-04-13T18:42:21.517Z,1397414541.517 [CBIT](CRITICAL): Data Fault in component: NAL9602
2014-04-13T18:42:21.926Z,1397414541.926 [NAL9602](INFO): Powering down
2014-04-13T18:42:21.972Z,1397414541.972 [CommandLine](FAULT): Scheduling is paused
2014-04-13T18:43:42.277Z,1397414622.277 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T18:43:42.277Z,1397414622.277 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T18:43:42.277Z,1397414622.277 [DVL_micro](ERROR): Data Fault
2014-04-13T18:43:42.304Z,1397414622.304 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T18:43:42.691Z,1397414622.691 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T18:43:43.127Z,1397414623.127 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T18:43:43.128Z,1397414623.128 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T18:43:43.128Z,1397414623.128 [DVL_micro](ERROR): Hardware Fault
2014-04-13T18:43:43.620Z,1397414623.620 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T18:43:43.620Z,1397414623.620 [DVL_micro] No Fault, FailCount= 1
2014-04-13T18:43:43.995Z,1397414623.995 [DVL_micro](INFO): Initializing
2014-04-13T18:44:21.745Z,1397414661.745 [CBIT](INFO): Clearing failed count for component NAL9602
2014-04-13T18:44:21.746Z,1397414661.746 [NAL9602] No Fault, FailCount= 2
2014-04-13T18:44:22.124Z,1397414662.124 [NAL9602](INFO): Powering up NAL9602
2014-04-13T18:44:32.992Z,1397414672.992 [NAL9602](INFO): NAL9602 initialized
2014-04-13T18:46:47.967Z,1397414807.967 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T18:46:47.967Z,1397414807.967 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T18:46:47.967Z,1397414807.967 [DVL_micro](ERROR): Data Fault
2014-04-13T18:46:48.012Z,1397414808.012 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T18:46:48.390Z,1397414808.390 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T18:46:49.436Z,1397414809.436 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T18:46:49.436Z,1397414809.436 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T18:46:49.437Z,1397414809.437 [DVL_micro](ERROR): Hardware Fault
2014-04-13T18:46:50.328Z,1397414810.328 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T18:46:50.329Z,1397414810.329 [DVL_micro] No Fault, FailCount= 1
2014-04-13T18:46:50.695Z,1397414810.695 [DVL_micro](INFO): Initializing
2014-04-13T18:49:55.806Z,1397414995.806 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T18:49:55.806Z,1397414995.806 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T18:49:55.806Z,1397414995.806 [DVL_micro](ERROR): Data Fault
2014-04-13T18:49:55.846Z,1397414995.846 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T18:49:56.225Z,1397414996.225 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T18:49:56.671Z,1397414996.671 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T18:49:56.671Z,1397414996.671 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T18:49:56.671Z,1397414996.671 [DVL_micro](ERROR): Hardware Fault
2014-04-13T18:49:57.108Z,1397414997.108 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T18:49:57.108Z,1397414997.108 [DVL_micro] No Fault, FailCount= 1
2014-04-13T18:49:57.587Z,1397414997.587 [DVL_micro](INFO): Initializing
2014-04-13T18:53:01.977Z,1397415181.977 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T18:53:01.977Z,1397415181.977 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T18:53:01.977Z,1397415181.977 [DVL_micro](ERROR): Data Fault
2014-04-13T18:53:02.005Z,1397415182.005 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T18:53:02.367Z,1397415182.367 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T18:53:02.802Z,1397415182.802 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T18:53:02.802Z,1397415182.802 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T18:53:02.802Z,1397415182.802 [DVL_micro](ERROR): Hardware Fault
2014-04-13T18:53:03.310Z,1397415183.310 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T18:53:03.310Z,1397415183.310 [DVL_micro] No Fault, FailCount= 1
2014-04-13T18:53:03.704Z,1397415183.704 [DVL_micro](INFO): Initializing
2014-04-13T18:54:37.478Z,1397415277.478 [NAL9602](FAULT): GPS failed to acquire within timeout.
2014-04-13T18:54:37.478Z,1397415277.478 [NAL9602] Data Fault, FailCount= 1
2014-04-13T18:54:37.478Z,1397415277.478 [NAL9602](ERROR): Data Fault
2014-04-13T18:54:37.505Z,1397415277.505 [CBIT](ERROR): Data Fault in component: NAL9602
2014-04-13T18:54:37.884Z,1397415277.884 [NAL9602](INFO): Powering down
2014-04-13T18:54:38.730Z,1397415278.730 [CBIT](INFO): Clearing failed state for component NAL9602
2014-04-13T18:54:38.730Z,1397415278.730 [NAL9602] No Fault, FailCount= 1
2014-04-13T18:54:42.961Z,1397415282.961 [NAL9602](INFO): Powering up NAL9602
2014-04-13T18:54:53.766Z,1397415293.766 [NAL9602](INFO): NAL9602 initialized
2014-04-13T18:56:08.235Z,1397415368.235 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T18:56:08.235Z,1397415368.235 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T18:56:08.235Z,1397415368.235 [DVL_micro](ERROR): Data Fault
2014-04-13T18:56:09.115Z,1397415369.115 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T18:56:09.730Z,1397415369.730 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T18:56:10.182Z,1397415370.182 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T18:56:10.182Z,1397415370.182 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T18:56:10.182Z,1397415370.182 [DVL_micro](ERROR): Hardware Fault
2014-04-13T18:56:10.643Z,1397415370.643 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T18:56:10.643Z,1397415370.643 [DVL_micro] No Fault, FailCount= 1
2014-04-13T18:56:11.037Z,1397415371.037 [DVL_micro](INFO): Initializing
2014-04-13T18:59:15.606Z,1397415555.606 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T18:59:15.606Z,1397415555.606 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T18:59:15.606Z,1397415555.606 [DVL_micro](ERROR): Data Fault
2014-04-13T18:59:15.673Z,1397415555.673 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T18:59:16.044Z,1397415556.044 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T18:59:16.477Z,1397415556.477 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T18:59:16.478Z,1397415556.478 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T18:59:16.478Z,1397415556.478 [DVL_micro](ERROR): Hardware Fault
2014-04-13T18:59:16.904Z,1397415556.904 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T18:59:16.904Z,1397415556.904 [DVL_micro] No Fault, FailCount= 1
2014-04-13T18:59:17.293Z,1397415557.293 [DVL_micro](INFO): Initializing
2014-04-13T19:02:21.506Z,1397415741.506 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-13T19:02:21.506Z,1397415741.506 [DVL_micro] Data Fault, FailCount= 1
2014-04-13T19:02:21.506Z,1397415741.506 [DVL_micro](ERROR): Data Fault
2014-04-13T19:02:21.557Z,1397415741.557 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-13T19:02:21.987Z,1397415741.987 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T19:02:22.427Z,1397415742.427 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-13T19:02:22.427Z,1397415742.427 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-13T19:02:22.427Z,1397415742.427 [DVL_micro](ERROR): Hardware Fault
2014-04-13T19:02:23.365Z,1397415743.365 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-13T19:02:23.366Z,1397415743.366 [DVL_micro] No Fault, FailCount= 1
2014-04-13T19:02:23.738Z,1397415743.738 [DVL_micro](INFO): Initializing
2014-04-13T19:02:35.434Z,1397415755.434 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=25485, MT Status=1, MTMSN=1760
2014-04-13T19:02:35.482Z,1397415755.482 [NAL9602](INFO): Sent 75 bytes from file Logs/20140413T163946/Courier0064.lzma
2014-04-13T19:02:35.482Z,1397415755.482 [NAL9602](INFO): Packets left to send: 0
2014-04-13T19:02:35.484Z,1397415755.484 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T163946/Courier0064.lzma.parts/0000.sbd
2014-04-13T19:02:35.484Z,1397415755.484 [NAL9602](INFO): Completed sending Logs/20140413T163946/Courier0064.lzma
2014-04-13T19:02:36.140Z,1397415756.140 [NAL9602](INFO): Received command:restart system
2014-04-13T19:02:36.207Z,1397415756.207 [CommandLine](IMPORTANT): got command restart system
2014-04-13T19:02:38.995Z,1397415758.995 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2014-04-13T19:02:39.012Z,1397415759.012 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2014-04-13T19:02:39.244Z,1397415759.244 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2014-04-13T19:02:39.252Z,1397415759.252 [WetLabsBB2FL](INFO): Powering down
2014-04-13T19:02:39.263Z,1397415759.263 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2014-04-13T19:02:39.480Z,1397415759.480 [CTD_NeilBrown](INFO): Powering down
2014-04-13T19:02:39.488Z,1397415759.488 [ComponentRegistry](INFO): Shutting down AsyncPiEstimator ThreadHandler
2014-04-13T19:02:39.540Z,1397415759.540 [AsyncPiEstimator](DEBUG): Uninitialize AsyncPiEstimator.
2014-04-13T19:02:39.549Z,1397415759.549 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2014-04-13T19:02:39.609Z,1397415759.609 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2014-04-13T19:02:39.609Z,1397415759.609 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2014-04-13T19:02:39.758Z,1397415759.758 [controlThread](DEBUG): Uninitializing ControlThread
2014-04-13T19:02:39.759Z,1397415759.759 [AHRS_sp3003D](INFO): Powering down
2014-04-13T19:02:39.760Z,1397415759.760 [DVL_micro](INFO): uninitialize:Powering down
2014-04-13T19:02:39.761Z,1397415759.761 [NAL9602](INFO): Powering down
2014-04-13T19:02:39.777Z,1397415759.777 [Radio_Freewave](INFO): Powering down
2014-04-13T19:02:39.779Z,1397415759.779 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2014-04-13T19:02:39.781Z,1397415759.781 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2014-04-13T19:02:39.781Z,1397415759.781 [Default] Stopped
2014-04-13T19:02:39.781Z,1397415759.781 [Default](INFO): Aggregate::uninitialize Default
2014-04-13T19:02:39.781Z,1397415759.781 [Default:GPS] Stopped
2014-04-13T19:02:39.781Z,1397415759.781 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-04-13T19:02:39.782Z,1397415759.782 [Default:GPS:A.SetSpeed] Stopped
2014-04-13T19:02:39.782Z,1397415759.782 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-04-13T19:02:39.782Z,1397415759.782 [Default:GPS:Read_GPS] Stopped
2014-04-13T19:02:39.782Z,1397415759.782 [Default:Iridium] Stopped
2014-04-13T19:02:39.782Z,1397415759.782 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-04-13T19:02:39.782Z,1397415759.782 [Default:Iridium:A.SetSpeed] Stopped
2014-04-13T19:02:39.782Z,1397415759.782 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-04-13T19:02:39.783Z,1397415759.783 [Default:Iridium:Read_Iridium] Stopped
2014-04-13T19:02:39.783Z,1397415759.783 [Default:CallIridium] Stopped
2014-04-13T19:02:39.783Z,1397415759.783 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-04-13T19:02:39.783Z,1397415759.783 [Default:CallIridium:B] Stopped
2014-04-13T19:02:39.783Z,1397415759.783 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-04-13T19:02:39.783Z,1397415759.783 [Default:WaitAtTheSurface] Stopped
2014-04-13T19:02:39.783Z,1397415759.783 [Default:WaitAtTheSurface](INFO): Aggregate::uninitialize Default:WaitAtTheSurface
2014-04-13T19:02:39.784Z,1397415759.784 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Stopped
2014-04-13T19:02:39.784Z,1397415759.784 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Uninitialize.
2014-04-13T19:02:39.784Z,1397415759.784 [Default:WaitAtTheSurface:B.GoToSurface] Stopped
2014-04-13T19:02:39.784Z,1397415759.784 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-13T19:02:39.798Z,1397415759.798 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2014-04-13T19:02:39.799Z,1397415759.799 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2014-04-13T19:02:39.799Z,1397415759.799 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2014-04-13T19:02:39.799Z,1397415759.799 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2014-04-13T19:02:39.800Z,1397415759.800 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2014-04-13T19:02:39.805Z,1397415759.805 [BuoyancyServo](INFO): Powering down
2014-04-13T19:02:39.817Z,1397415759.817 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2014-04-13T19:02:39.817Z,1397415759.817 [ElevatorServo](INFO): Powering down
2014-04-13T19:02:39.818Z,1397415759.818 [MassServo](DEBUG): Uninitialize Mass Servo.
2014-04-13T19:02:39.818Z,1397415759.818 [MassServo](INFO): Powering down
2014-04-13T19:02:39.819Z,1397415759.819 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2014-04-13T19:02:39.819Z,1397415759.819 [RudderServo](INFO): Powering down
2014-04-13T19:02:39.821Z,1397415759.821 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2014-04-13T19:02:39.821Z,1397415759.821 [ThrusterServo](INFO): Powering down
2014-04-13T19:02:39.822Z,1397415759.822 [SBIT](DEBUG): Uninitialize SBIT Component.
2014-04-13T19:02:39.822Z,1397415759.822 [IBIT](DEBUG): Uninitialize IBIT Component.
2014-04-13T19:02:39.823Z,1397415759.823 [CBIT](DEBUG): Uninitialize CBIT Component.