2014-04-18T22:26:01.199Z,1397859961.199 [Supervisor](DEBUG): Initializing supervisor.
2014-04-18T22:26:01.202Z,1397859961.202 [SyncHandler](DEBUG): Created PCaller Thread at 4033C4E0
2014-04-18T22:26:01.203Z,1397859961.203 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2014-04-18T22:26:01.204Z,1397859961.204 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036C4E0
2014-04-18T22:26:01.207Z,1397859961.207 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2014-04-18T22:26:01.218Z,1397859961.218 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2014-04-18T22:26:01.219Z,1397859961.219 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039C4E0
2014-04-18T22:26:01.220Z,1397859961.220 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2014-04-18T22:26:01.221Z,1397859961.221 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CC4E0
2014-04-18T22:26:01.223Z,1397859961.223 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2014-04-18T22:26:01.224Z,1397859961.224 [Supervisor](INFO): Looking for Config files in directory: Config/
2014-04-18T22:26:01.225Z,1397859961.225 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2014-04-18T22:26:01.585Z,1397859961.585 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2014-04-18T22:26:01.585Z,1397859961.585 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2014-04-18T22:26:01.856Z,1397859961.856 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2014-04-18T22:26:01.856Z,1397859961.856 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2014-04-18T22:26:01.943Z,1397859961.943 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2014-04-18T22:26:01.944Z,1397859961.944 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2014-04-18T22:26:02.140Z,1397859962.140 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2014-04-18T22:26:02.140Z,1397859962.140 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2014-04-18T22:26:02.299Z,1397859962.299 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2014-04-18T22:26:02.300Z,1397859962.300 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2014-04-18T22:26:02.592Z,1397859962.592 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2014-04-18T22:26:02.593Z,1397859962.593 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2014-04-18T22:26:02.774Z,1397859962.774 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2014-04-18T22:26:02.775Z,1397859962.775 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2014-04-18T22:26:03.110Z,1397859963.110 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2014-04-18T22:26:03.110Z,1397859963.110 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2014-04-18T22:26:03.220Z,1397859963.220 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2014-04-18T22:26:03.221Z,1397859963.221 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2014-04-18T22:26:03.709Z,1397859963.709 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2014-04-18T22:26:03.710Z,1397859963.710 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2014-04-18T22:26:03.819Z,1397859963.819 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2014-04-18T22:26:03.820Z,1397859963.820 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2014-04-18T22:26:03.906Z,1397859963.906 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2014-04-18T22:26:04.014Z,1397859964.014 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2014-04-18T22:26:04.015Z,1397859964.015 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2014-04-18T22:26:04.121Z,1397859964.121 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2014-04-18T22:26:04.121Z,1397859964.121 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2014-04-18T22:26:04.262Z,1397859964.262 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2014-04-18T22:26:04.264Z,1397859964.264 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2014-04-18T22:26:04.265Z,1397859964.265 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2014-04-18T22:26:04.372Z,1397859964.372 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2014-04-18T22:26:04.504Z,1397859964.504 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2014-04-18T22:26:04.600Z,1397859964.600 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2014-04-18T22:26:04.694Z,1397859964.694 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2014-04-18T22:26:04.849Z,1397859964.849 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2014-04-18T22:26:04.968Z,1397859964.968 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2014-04-18T22:26:05.062Z,1397859965.062 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2014-04-18T22:26:05.227Z,1397859965.227 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2014-04-18T22:26:05.329Z,1397859965.329 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2014-04-18T22:26:05.427Z,1397859965.427 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2014-04-18T22:26:05.517Z,1397859965.517 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Estimation.cfg
2014-04-18T22:26:05.616Z,1397859965.616 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/
2014-04-18T22:26:05.616Z,1397859965.616 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2014-04-18T22:26:05.618Z,1397859965.618 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2014-04-18T22:26:05.957Z,1397859965.957 [AHRS_sp3003D] Loaded
2014-04-18T22:26:05.957Z,1397859965.957 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2014-04-18T22:26:06.245Z,1397859966.245 [Batt_Ocean_Server] Loaded
2014-04-18T22:26:06.246Z,1397859966.246 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2014-04-18T22:26:06.259Z,1397859966.259 [Depth_Keller] Loaded
2014-04-18T22:26:06.259Z,1397859966.259 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2014-04-18T22:26:06.264Z,1397859966.264 [DropWeight] Loaded
2014-04-18T22:26:06.265Z,1397859966.265 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2014-04-18T22:26:06.403Z,1397859966.403 [DVL_micro] Loaded
2014-04-18T22:26:06.403Z,1397859966.403 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2014-04-18T22:26:06.502Z,1397859966.502 [NAL9602] Loaded
2014-04-18T22:26:06.503Z,1397859966.503 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2014-04-18T22:26:06.554Z,1397859966.554 [Onboard] Loaded
2014-04-18T22:26:06.554Z,1397859966.554 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2014-04-18T22:26:06.562Z,1397859966.562 [Radio_Freewave] Loaded
2014-04-18T22:26:06.562Z,1397859966.562 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread.
2014-04-18T22:26:06.569Z,1397859966.569 [SCPI] Loaded
2014-04-18T22:26:06.569Z,1397859966.569 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread.
2014-04-18T22:26:06.569Z,1397859966.569 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2014-04-18T22:26:06.570Z,1397859966.570 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2014-04-18T22:26:06.729Z,1397859966.729 [InternalSim] Loaded
2014-04-18T22:26:06.729Z,1397859966.729 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2014-04-18T22:26:06.730Z,1397859966.730 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2014-04-18T22:26:06.730Z,1397859966.730 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2014-04-18T22:26:06.968Z,1397859966.968 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2014-04-18T22:26:06.969Z,1397859966.969 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2014-04-18T22:26:06.974Z,1397859966.974 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator.
2014-04-18T22:26:06.979Z,1397859966.979 [AsyncPiEstimator] Loaded
2014-04-18T22:26:06.980Z,1397859966.980 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread.
2014-04-18T22:26:06.981Z,1397859966.981 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406A24E0
2014-04-18T22:26:06.981Z,1397859966.981 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2014-04-18T22:26:06.982Z,1397859966.982 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2014-04-18T22:26:07.062Z,1397859967.062 [DeadReckonUsingMultipleVelocitySources] Loaded
2014-04-18T22:26:07.063Z,1397859967.063 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2014-04-18T22:26:07.079Z,1397859967.079 [NavChart] Loaded
2014-04-18T22:26:07.079Z,1397859967.079 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2014-04-18T22:26:07.083Z,1397859967.083 [UniversalFixResidualReporter] Loaded
2014-04-18T22:26:07.084Z,1397859967.084 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2014-04-18T22:26:07.084Z,1397859967.084 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2014-04-18T22:26:07.085Z,1397859967.085 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2014-04-18T22:26:07.131Z,1397859967.131 [VerticalControl](DEBUG): Construct VerticalControl.
2014-04-18T22:26:07.242Z,1397859967.242 [VerticalControl] Loaded
2014-04-18T22:26:07.243Z,1397859967.243 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2014-04-18T22:26:07.244Z,1397859967.244 [HorizontalControl](DEBUG): Construct HorizontalControl.
2014-04-18T22:26:07.310Z,1397859967.310 [HorizontalControl] Loaded
2014-04-18T22:26:07.310Z,1397859967.310 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2014-04-18T22:26:07.311Z,1397859967.311 [SpeedControl](DEBUG): Construct SpeedControl.
2014-04-18T22:26:07.313Z,1397859967.313 [SpeedControl] Loaded
2014-04-18T22:26:07.313Z,1397859967.313 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2014-04-18T22:26:07.314Z,1397859967.314 [LoopControl](DEBUG): Construct LoopControl.
2014-04-18T22:26:07.315Z,1397859967.315 [LoopControl] Loaded
2014-04-18T22:26:07.315Z,1397859967.315 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2014-04-18T22:26:07.315Z,1397859967.315 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2014-04-18T22:26:07.316Z,1397859967.316 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2014-04-18T22:26:07.335Z,1397859967.335 [DepthRateCalculator] Loaded
2014-04-18T22:26:07.335Z,1397859967.335 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2014-04-18T22:26:07.341Z,1397859967.341 [PitchRateCalculator] Loaded
2014-04-18T22:26:07.341Z,1397859967.341 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2014-04-18T22:26:07.348Z,1397859967.348 [SpeedCalculator] Loaded
2014-04-18T22:26:07.348Z,1397859967.348 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2014-04-18T22:26:07.365Z,1397859967.365 [TempGradientCalculator] Loaded
2014-04-18T22:26:07.365Z,1397859967.365 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2014-04-18T22:26:07.370Z,1397859967.370 [YawRateCalculator] Loaded
2014-04-18T22:26:07.371Z,1397859967.371 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2014-04-18T22:26:07.371Z,1397859967.371 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2014-04-18T22:26:07.372Z,1397859967.372 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2014-04-18T22:26:07.473Z,1397859967.473 [CTD_NeilBrown] Loaded
2014-04-18T22:26:07.473Z,1397859967.473 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2014-04-18T22:26:07.475Z,1397859967.475 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 407444E0
2014-04-18T22:26:07.487Z,1397859967.487 [ISUS] Loaded
2014-04-18T22:26:07.488Z,1397859967.488 [ComponentRegistry](DEBUG): SyncComponent "ISUS" handled in the control thread.
2014-04-18T22:26:07.502Z,1397859967.502 [PAR_Licor] Loaded
2014-04-18T22:26:07.503Z,1397859967.503 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2014-04-18T22:26:07.539Z,1397859967.539 [WetLabsBB2FL] Loaded
2014-04-18T22:26:07.539Z,1397859967.539 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2014-04-18T22:26:07.540Z,1397859967.540 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407744E0
2014-04-18T22:26:07.541Z,1397859967.541 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2014-04-18T22:26:07.541Z,1397859967.541 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2014-04-18T22:26:07.631Z,1397859967.631 [SBIT](DEBUG): Construct Startup Built In Test.
2014-04-18T22:26:07.642Z,1397859967.642 [SBIT] Loaded
2014-04-18T22:26:07.643Z,1397859967.643 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2014-04-18T22:26:07.643Z,1397859967.643 [IBIT](DEBUG): Construct Initiated Built In Test.
2014-04-18T22:26:07.656Z,1397859967.656 [IBIT] Loaded
2014-04-18T22:26:07.656Z,1397859967.656 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2014-04-18T22:26:07.658Z,1397859967.658 [CBIT](DEBUG): Construct CBIT Built In Test.
2014-04-18T22:26:07.726Z,1397859967.726 [CBIT] Loaded
2014-04-18T22:26:07.727Z,1397859967.727 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2014-04-18T22:26:07.727Z,1397859967.727 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2014-04-18T22:26:07.728Z,1397859967.728 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2014-04-18T22:26:07.767Z,1397859967.767 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2014-04-18T22:26:07.768Z,1397859967.768 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2014-04-18T22:26:07.863Z,1397859967.863 [BuoyancyServo] Loaded
2014-04-18T22:26:07.863Z,1397859967.863 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2014-04-18T22:26:07.875Z,1397859967.875 [ElevatorServo] Loaded
2014-04-18T22:26:07.876Z,1397859967.876 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2014-04-18T22:26:07.887Z,1397859967.887 [MassServo] Loaded
2014-04-18T22:26:07.887Z,1397859967.887 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2014-04-18T22:26:07.899Z,1397859967.899 [RudderServo] Loaded
2014-04-18T22:26:07.899Z,1397859967.899 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2014-04-18T22:26:07.910Z,1397859967.910 [ThrusterServo] Loaded
2014-04-18T22:26:07.911Z,1397859967.911 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2014-04-18T22:26:07.911Z,1397859967.911 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2014-04-18T22:26:07.912Z,1397859967.912 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2014-04-18T22:26:07.934Z,1397859967.934 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2014-04-18T22:26:07.936Z,1397859967.936 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2014-04-18T22:26:07.937Z,1397859967.937 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2014-04-18T22:26:07.943Z,1397859967.943 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2014-04-18T22:26:07.944Z,1397859967.944 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 408424E0
2014-04-18T22:26:07.949Z,1397859967.949 [Supervisor](DEBUG): Running supervisor.
2014-04-18T22:26:07.950Z,1397859967.950 [CommandLine](INFO): Thread ID is 1030
2014-04-18T22:26:07.953Z,1397859967.953 [controlThread](INFO): Thread ID is 1029
2014-04-18T22:26:07.953Z,1397859967.953 [controlThread](DEBUG): Initializing ControlThread
2014-04-18T22:26:07.954Z,1397859967.954 [CycleStarter](INFO): Thread ID is 1028
2014-04-18T22:26:07.957Z,1397859967.957 [logger](INFO): Thread ID is 1031
2014-04-18T22:26:07.975Z,1397859967.975 [AsyncPiEstimator](INFO): Thread ID is 1114
2014-04-18T22:26:07.975Z,1397859967.975 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator.
2014-04-18T22:26:08.003Z,1397859968.003 [CTD_NeilBrown](INFO): Thread ID is 1115
2014-04-18T22:26:08.004Z,1397859968.004 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2014-04-18T22:26:08.007Z,1397859968.007 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2014-04-18T22:26:08.017Z,1397859968.017 [WetLabsBB2FL](INFO): Thread ID is 1116
2014-04-18T22:26:08.018Z,1397859968.018 [WetLabsBB2FL](INFO): Powering down
2014-04-18T22:26:08.045Z,1397859968.045 [NavChartDb](INFO): Thread ID is 1117
2014-04-18T22:26:08.048Z,1397859968.048 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2014-04-18T22:26:08.049Z,1397859968.049 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2014-04-18T22:26:08.049Z,1397859968.049 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2014-04-18T22:26:08.049Z,1397859968.049 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2014-04-18T22:26:08.049Z,1397859968.049 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2014-04-18T22:26:08.050Z,1397859968.050 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2014-04-18T22:26:08.050Z,1397859968.050 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2014-04-18T22:26:08.051Z,1397859968.051 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2014-04-18T22:26:08.051Z,1397859968.051 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2014-04-18T22:26:09.498Z,1397859969.498 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2014-04-18T22:26:09.528Z,1397859969.528 [InternalSim](DEBUG):  InternalSim initializing...
2014-04-18T22:26:09.637Z,1397859969.637 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2014-04-18T22:26:09.637Z,1397859969.637 [NavChart](DEBUG): Initialize NavChart Navigation.
2014-04-18T22:26:09.638Z,1397859969.638 [UniversalFixResidualReporter](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2014-04-18T22:26:09.638Z,1397859969.638 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2014-04-18T22:26:09.640Z,1397859969.640 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2014-04-18T22:26:09.641Z,1397859969.641 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2014-04-18T22:26:09.647Z,1397859969.647 [LoopControl](DEBUG): Initialize LoopControlComponent.
2014-04-18T22:26:09.648Z,1397859969.648 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2014-04-18T22:26:09.648Z,1397859969.648 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2014-04-18T22:26:09.649Z,1397859969.649 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2014-04-18T22:26:09.661Z,1397859969.661 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2014-04-18T22:26:09.662Z,1397859969.662 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2014-04-18T22:26:09.663Z,1397859969.663 [SBIT](INFO): Initialize SBIT Component.
2014-04-18T22:26:09.664Z,1397859969.664 [SBIT](IMPORTANT): Tethys CM Info: 
 $Rev:11231
2014-04-18T22:26:09.664Z,1397859969.664 [SBIT](IMPORTANT): Kernel Release:2.6.27.8
2014-04-18T22:26:09.664Z,1397859969.664 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2014-04-18T22:26:09.666Z,1397859969.666 [IBIT](INFO): Initialize IBIT Component.
2014-04-18T22:26:09.667Z,1397859969.667 [CBIT](DEBUG): Initialize CBIT Component.
2014-04-18T22:26:09.667Z,1397859969.667 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2014-04-18T22:26:09.695Z,1397859969.695 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2014-04-18T22:26:09.721Z,1397859969.721 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2014-04-18T22:26:09.746Z,1397859969.746 [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-18T22:26:09.747Z,1397859969.747 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2014-04-18T22:26:09.818Z,1397859969.818 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2014-04-18T22:26:09.821Z,1397859969.821 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2014-04-18T22:26:09.840Z,1397859969.840 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-04-18T22:26:09.864Z,1397859969.864 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2014-04-18T22:26:09.867Z,1397859969.867 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-04-18T22:26:09.898Z,1397859969.898 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2014-04-18T22:26:09.945Z,1397859969.945 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Construct.
2014-04-18T22:26:09.948Z,1397859969.948 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-04-18T22:26:09.972Z,1397859969.972 [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-18T22:26:09.977Z,1397859969.977 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,Radio_Freewave,SCPI,ISUS,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2014-04-18T22:26:10.033Z,1397859970.033 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2014-04-18T22:26:10.087Z,1397859970.087 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar
2014-04-18T22:26:10.149Z,1397859970.149 [DVL_micro](INFO): Initializing
2014-04-18T22:26:10.262Z,1397859970.262 [Radio_Freewave](INFO): Powering up
2014-04-18T22:26:10.663Z,1397859970.663 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2014-04-18T22:26:10.663Z,1397859970.663 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2014-04-18T22:26:10.674Z,1397859970.674 [ElevatorServo](DEBUG): Initializing EZServoServo.
2014-04-18T22:26:10.674Z,1397859970.674 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2014-04-18T22:26:10.699Z,1397859970.699 [MassServo](DEBUG): Initializing EZServoServo.
2014-04-18T22:26:10.699Z,1397859970.699 [MassServo](DEBUG): Initializing MassServo.
2014-04-18T22:26:10.709Z,1397859970.709 [RudderServo](DEBUG): Initializing EZServoServo.
2014-04-18T22:26:10.709Z,1397859970.709 [RudderServo](DEBUG): Initializing RudderServo.
2014-04-18T22:26:10.739Z,1397859970.739 [ThrusterServo](DEBUG): Initializing EZServoServo.
2014-04-18T22:26:10.739Z,1397859970.739 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2014-04-18T22:26:10.772Z,1397859970.772 [CommandLine](FAULT): Scheduling is paused
2014-04-18T22:26:11.315Z,1397859971.315 [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-18T22:26:12.056Z,1397859972.056 [NAL9602](INFO): Powering up NAL9602
2014-04-18T22:26:22.714Z,1397859982.714 [NAL9602](INFO): NAL9602 initialized
2014-04-18T22:26:25.291Z,1397859985.291 [SBIT](IMPORTANT): Beginning Startup BIT
2014-04-18T22:26:25.294Z,1397859985.294 [CBIT](IMPORTANT): Beginning GF scan
2014-04-18T22:26:38.601Z,1397859998.601 [SBIT](FAULT): Mass: EXPECTED:0.004000 ACTUAL:0.003453
2014-04-18T22:26:39.023Z,1397859999.023 [NAL9602](INFO): SBD MO Status=0, MOMSN=26717, MT Status=0, MTMSN=0
2014-04-18T22:26:39.023Z,1397859999.023 [NAL9602](INFO): No messages in MT queue
2014-04-18T22:26:40.784Z,1397860000.784 [NAL9602](IMPORTANT): GPS fix at: 1397859998.00
2014-04-18T22:26:49.234Z,1397860009.234 [NAL9602](INFO): Powering down
2014-04-18T22:26:51.887Z,1397860011.887 [CBIT](IMPORTANT): No ground fault detected
2014-04-18T22:27:19.584Z,1397860039.584 [SBIT](CRITICAL): SBIT FAILED
2014-04-18T22:27:20.024Z,1397860040.024 [MissionManager](IMPORTANT): Started mission Startup
2014-04-18T22:27:20.025Z,1397860040.025 [Startup] Running Loop=1
2014-04-18T22:27:20.025Z,1397860040.025 [Startup](INFO): Aggregate::initialize Startup
2014-04-18T22:27:20.025Z,1397860040.025 [Startup:A.GoToSurface] Running Loop=1
2014-04-18T22:27:20.025Z,1397860040.025 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-18T22:27:20.039Z,1397860040.039 [Startup:StartupSatComms] Running Loop=1
2014-04-18T22:27:20.039Z,1397860040.039 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2014-04-18T22:27:20.039Z,1397860040.039 [Startup:StartupSatComms:A] Running Loop=1
2014-04-18T22:27:20.451Z,1397860040.451 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2014-04-18T22:27:20.894Z,1397860040.894 [NAL9602](INFO): Powering up
2014-04-18T22:27:31.508Z,1397860051.508 [NAL9602](INFO): NAL9602 initialized
2014-04-18T22:27:53.075Z,1397860073.075 [NAL9602](INFO): SBD MO Status=0, MOMSN=26718, MT Status=0, MTMSN=0
2014-04-18T22:27:53.075Z,1397860073.075 [NAL9602](INFO): No messages in MT queue
2014-04-18T22:27:55.607Z,1397860075.607 [DVL_micro](ERROR): No DVL communication! Re-initializing
2014-04-18T22:27:55.607Z,1397860075.607 [DVL_micro] Communications Fault, FailCount= 1
2014-04-18T22:27:55.607Z,1397860075.607 [DVL_micro](ERROR): Communications Fault
2014-04-18T22:27:55.670Z,1397860075.670 [CBIT](ERROR): Communications Fault in component: DVL_micro
2014-04-18T22:27:56.036Z,1397860076.036 [DVL_micro](INFO): uninitialize:Powering down
2014-04-18T22:27:56.521Z,1397860076.521 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-18T22:27:56.521Z,1397860076.521 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-18T22:27:56.521Z,1397860076.521 [DVL_micro](ERROR): Hardware Fault
2014-04-18T22:27:57.030Z,1397860077.030 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-18T22:27:57.030Z,1397860077.030 [DVL_micro] No Fault, FailCount= 1
2014-04-18T22:27:57.410Z,1397860077.410 [DVL_micro](INFO): Initializing
2014-04-18T22:27:59.945Z,1397860079.945 [NAL9602](IMPORTANT): GPS fix at: 1397860077.00
2014-04-18T22:27:59.984Z,1397860079.984 [Startup:StartupSatComms:A] Stopped
2014-04-18T22:27:59.984Z,1397860079.984 [Startup:StartupSatComms:B] Running Loop=1
2014-04-18T22:28:00.435Z,1397860080.435 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2014-04-18T22:28:17.032Z,1397860097.032 [NAL9602](INFO): SBD MO Status=1, MOMSN=26719, MT Status=0, MTMSN=0
2014-04-18T22:28:17.088Z,1397860097.088 [NAL9602](INFO): Sent 75 bytes from file Logs/20140418T221104/Courier0008.lzma
2014-04-18T22:28:17.088Z,1397860097.088 [NAL9602](INFO): Packets left to send: 0
2014-04-18T22:28:17.090Z,1397860097.090 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T221104/Courier0008.lzma.parts/0000.sbd
2014-04-18T22:28:17.090Z,1397860097.090 [NAL9602](INFO): Completed sending Logs/20140418T221104/Courier0008.lzma
2014-04-18T22:28:32.175Z,1397860112.175 [NAL9602](INFO): SBD MO Status=2, MOMSN=26720, MT Status=2, MTMSN=0
2014-04-18T22:28:32.175Z,1397860112.175 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-04-18T22:28:58.011Z,1397860138.011 [NAL9602](INFO): SBD MO Status=2, MOMSN=26720, MT Status=2, MTMSN=0
2014-04-18T22:28:58.011Z,1397860138.011 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-04-18T22:29:00.116Z,1397860140.116 [Startup:StartupSatComms:B](INFO): Timed out from 2014-04-18T22:27:59.0Z
2014-04-18T22:29:00.117Z,1397860140.117 [Startup:StartupSatComms:B] Stopped
2014-04-18T22:29:00.117Z,1397860140.117 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2014-04-18T22:29:00.117Z,1397860140.117 [Startup:StartupSatComms] Stopped
2014-04-18T22:29:00.117Z,1397860140.117 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2014-04-18T22:29:00.118Z,1397860140.118 [Startup](INFO): Completed Startup
2014-04-18T22:29:00.118Z,1397860140.118 [Startup] Stopped
2014-04-18T22:29:00.118Z,1397860140.118 [Startup](INFO): Aggregate::uninitialize Startup
2014-04-18T22:29:00.118Z,1397860140.118 [Startup:A.GoToSurface] Stopped
2014-04-18T22:29:00.118Z,1397860140.118 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-18T22:29:00.636Z,1397860140.636 [MissionManager](IMPORTANT): Started mission Default
2014-04-18T22:29:00.636Z,1397860140.636 [Default] Running Loop=1
2014-04-18T22:29:00.636Z,1397860140.636 [Default](INFO): Aggregate::initialize Default
2014-04-18T22:29:00.636Z,1397860140.636 [Default:Iridium] Running Loop=1
2014-04-18T22:29:00.636Z,1397860140.636 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-04-18T22:29:00.636Z,1397860140.636 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-04-18T22:29:00.636Z,1397860140.636 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-04-18T22:29:00.637Z,1397860140.637 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-04-18T22:29:00.637Z,1397860140.637 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-18T22:29:00.637Z,1397860140.637 [Default:CallIridium] Running Loop=1
2014-04-18T22:29:00.637Z,1397860140.637 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-04-18T22:29:00.637Z,1397860140.637 [Default:CallIridium:A] Running Loop=1
2014-04-18T22:29:00.656Z,1397860140.656 [Default:CallIridium:A] Stopped
2014-04-18T22:29:00.656Z,1397860140.656 [Default:CallIridium:B] Running Loop=1
2014-04-18T22:29:00.656Z,1397860140.656 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-04-18T22:29:00.662Z,1397860140.662 [Default:Iridium:B.GoToSurface] Stopped
2014-04-18T22:29:00.662Z,1397860140.662 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-18T22:29:00.662Z,1397860140.662 [Default:Iridium:Read_Iridium] Running Loop=1
2014-04-18T22:29:00.662Z,1397860140.662 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-04-18T22:29:00.679Z,1397860140.679 [Default:GPS] Running Loop=1
2014-04-18T22:29:00.679Z,1397860140.679 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-04-18T22:29:00.679Z,1397860140.679 [Default:GPS:A.SetSpeed] Running Loop=1
2014-04-18T22:29:00.679Z,1397860140.679 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-04-18T22:29:00.679Z,1397860140.679 [Default:GPS:B.GoToSurface] Running Loop=1
2014-04-18T22:29:00.679Z,1397860140.679 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-18T22:29:00.691Z,1397860140.691 [Default:GPS:B.GoToSurface] Stopped
2014-04-18T22:29:00.691Z,1397860140.691 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-18T22:29:00.691Z,1397860140.691 [Default:GPS:Read_GPS] Running Loop=1
2014-04-18T22:29:00.692Z,1397860140.692 [Default:GPS:A.SetSpeed] Running Loop=1
2014-04-18T22:29:01.132Z,1397860141.132 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2014-04-18T22:29:01.141Z,1397860141.141 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2014-04-18T22:29:04.478Z,1397860144.478 [NAL9602](IMPORTANT): GPS fix at: 1397860142.00
2014-04-18T22:29:04.519Z,1397860144.519 [Default:GPS:Read_GPS] Stopped
2014-04-18T22:29:04.519Z,1397860144.519 [Default:GPS:D] Running Loop=1
2014-04-18T22:29:04.966Z,1397860144.966 [Default:GPS:D] Stopped
2014-04-18T22:29:04.966Z,1397860144.966 [Default:GPS](INFO): Completed Default:GPS
2014-04-18T22:29:04.966Z,1397860144.966 [Default:GPS] Stopped
2014-04-18T22:29:04.966Z,1397860144.966 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-04-18T22:29:04.966Z,1397860144.966 [Default:GPS:A.SetSpeed] Stopped
2014-04-18T22:29:04.966Z,1397860144.966 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-04-18T22:29:15.338Z,1397860155.338 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-18T22:29:15.339Z,1397860155.339 [DVL_micro] Data Fault, FailCount= 1
2014-04-18T22:29:15.339Z,1397860155.339 [DVL_micro](ERROR): Data Fault
2014-04-18T22:29:15.367Z,1397860155.367 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-18T22:29:15.755Z,1397860155.755 [DVL_micro](INFO): uninitialize:Powering down
2014-04-18T22:29:16.176Z,1397860156.176 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-18T22:29:16.176Z,1397860156.176 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-18T22:29:16.176Z,1397860156.176 [DVL_micro](ERROR): Hardware Fault
2014-04-18T22:29:16.659Z,1397860156.659 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-18T22:29:16.659Z,1397860156.659 [DVL_micro] No Fault, FailCount= 1
2014-04-18T22:29:17.064Z,1397860157.064 [DVL_micro](INFO): Initializing
2014-04-18T22:29:44.096Z,1397860184.096 [NAL9602](INFO): SBD MO Status=1, MOMSN=26720, MT Status=0, MTMSN=0
2014-04-18T22:29:44.158Z,1397860184.158 [NAL9602](INFO): Sent 18 bytes from file Logs/20140418T221104/Courier0012.lzma
2014-04-18T22:29:44.158Z,1397860184.158 [NAL9602](INFO): Packets left to send: 0
2014-04-18T22:29:44.160Z,1397860184.160 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T221104/Courier0012.lzma.parts/0000.sbd
2014-04-18T22:29:44.160Z,1397860184.160 [NAL9602](INFO): Completed sending Logs/20140418T221104/Courier0012.lzma
2014-04-18T22:29:59.282Z,1397860199.282 [NAL9602](INFO): SBD MO Status=1, MOMSN=26721, MT Status=0, MTMSN=0
2014-04-18T22:29:59.335Z,1397860199.335 [NAL9602](INFO): Sent 332 bytes from file Logs/20140418T222100/Courier0000.lzma
2014-04-18T22:29:59.335Z,1397860199.335 [NAL9602](INFO): Packets left to send: 1
2014-04-18T22:29:59.338Z,1397860199.338 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T222100/Courier0000.lzma.parts/0001.sbd
2014-04-18T22:30:08.833Z,1397860208.833 [NAL9602](INFO): SBD MO Status=1, MOMSN=26722, MT Status=0, MTMSN=0
2014-04-18T22:30:08.892Z,1397860208.892 [NAL9602](INFO): Sent 29 bytes from file Logs/20140418T222100/Courier0000.lzma
2014-04-18T22:30:08.892Z,1397860208.892 [NAL9602](INFO): Packets left to send: 0
2014-04-18T22:30:08.894Z,1397860208.894 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T222100/Courier0000.lzma.parts/0000.sbd
2014-04-18T22:30:08.894Z,1397860208.894 [NAL9602](INFO): Completed sending Logs/20140418T222100/Courier0000.lzma
2014-04-18T22:30:21.520Z,1397860221.520 [NAL9602](INFO): SBD MO Status=1, MOMSN=26723, MT Status=0, MTMSN=0
2014-04-18T22:30:21.574Z,1397860221.574 [NAL9602](INFO): Sent 332 bytes from file Logs/20140418T222254/Courier0000.lzma
2014-04-18T22:30:21.574Z,1397860221.574 [NAL9602](INFO): Packets left to send: 1
2014-04-18T22:30:21.576Z,1397860221.576 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T222254/Courier0000.lzma.parts/0001.sbd
2014-04-18T22:30:34.083Z,1397860234.083 [NAL9602](INFO): SBD MO Status=1, MOMSN=26724, MT Status=0, MTMSN=0
2014-04-18T22:30:34.131Z,1397860234.131 [NAL9602](INFO): Sent 29 bytes from file Logs/20140418T222254/Courier0000.lzma
2014-04-18T22:30:34.132Z,1397860234.132 [NAL9602](INFO): Packets left to send: 0
2014-04-18T22:30:34.133Z,1397860234.133 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T222254/Courier0000.lzma.parts/0000.sbd
2014-04-18T22:30:34.133Z,1397860234.133 [NAL9602](INFO): Completed sending Logs/20140418T222254/Courier0000.lzma
2014-04-18T22:30:53.425Z,1397860253.425 [NAL9602](INFO): SBD MO Status=1, MOMSN=26725, MT Status=0, MTMSN=0
2014-04-18T22:30:53.473Z,1397860253.473 [NAL9602](INFO): Sent 45 bytes from file Logs/20140418T222254/Courier0004.lzma
2014-04-18T22:30:53.474Z,1397860253.474 [NAL9602](INFO): Packets left to send: 0
2014-04-18T22:30:53.475Z,1397860253.475 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T222254/Courier0004.lzma.parts/0000.sbd
2014-04-18T22:30:53.475Z,1397860253.475 [NAL9602](INFO): Completed sending Logs/20140418T222254/Courier0004.lzma
2014-04-18T22:31:08.432Z,1397860268.432 [NAL9602](INFO): SBD MO Status=1, MOMSN=26726, MT Status=0, MTMSN=0
2014-04-18T22:31:08.485Z,1397860268.485 [NAL9602](INFO): Sent 332 bytes from file Logs/20140418T222601/Courier0000.lzma
2014-04-18T22:31:08.485Z,1397860268.485 [NAL9602](INFO): Packets left to send: 1
2014-04-18T22:31:08.486Z,1397860268.486 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T222601/Courier0000.lzma.parts/0001.sbd
2014-04-18T22:31:21.040Z,1397860281.040 [NAL9602](INFO): SBD MO Status=2, MOMSN=26727, MT Status=2, MTMSN=0
2014-04-18T22:31:21.040Z,1397860281.040 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-04-18T22:32:21.388Z,1397860341.388 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-18T22:32:21.389Z,1397860341.389 [DVL_micro] Data Fault, FailCount= 1
2014-04-18T22:32:21.389Z,1397860341.389 [DVL_micro](ERROR): Data Fault
2014-04-18T22:32:21.417Z,1397860341.417 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-18T22:32:21.853Z,1397860341.853 [DVL_micro](INFO): uninitialize:Powering down
2014-04-18T22:32:22.264Z,1397860342.264 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-18T22:32:22.264Z,1397860342.264 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-18T22:32:22.264Z,1397860342.264 [DVL_micro](ERROR): Hardware Fault
2014-04-18T22:32:23.266Z,1397860343.266 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-18T22:32:23.266Z,1397860343.266 [DVL_micro] No Fault, FailCount= 1
2014-04-18T22:32:23.647Z,1397860343.647 [DVL_micro](INFO): Initializing
2014-04-18T22:33:22.139Z,1397860402.139 [NAL9602](INFO): SBD MO Status=1, MOMSN=26727, MT Status=0, MTMSN=0
2014-04-18T22:33:22.208Z,1397860402.208 [NAL9602](INFO): Sent 48 bytes from file Logs/20140418T222601/Courier0000.lzma
2014-04-18T22:33:22.208Z,1397860402.208 [NAL9602](INFO): Packets left to send: 0
2014-04-18T22:33:22.209Z,1397860402.209 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T222601/Courier0000.lzma.parts/0000.sbd
2014-04-18T22:33:22.210Z,1397860402.210 [NAL9602](INFO): Completed sending Logs/20140418T222601/Courier0000.lzma
2014-04-18T22:33:30.997Z,1397860410.997 [NAL9602](INFO): SBD MO Status=1, MOMSN=26728, MT Status=0, MTMSN=0
2014-04-18T22:33:31.043Z,1397860411.043 [NAL9602](INFO): Sent 45 bytes from file Logs/20140418T222601/Courier0004.lzma
2014-04-18T22:33:31.044Z,1397860411.044 [NAL9602](INFO): Packets left to send: 0
2014-04-18T22:33:31.045Z,1397860411.045 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T222601/Courier0004.lzma.parts/0000.sbd
2014-04-18T22:33:31.045Z,1397860411.045 [NAL9602](INFO): Completed sending Logs/20140418T222601/Courier0004.lzma
2014-04-18T22:33:40.716Z,1397860420.716 [NAL9602](INFO): SBD MO Status=1, MOMSN=26729, MT Status=0, MTMSN=0
2014-04-18T22:33:40.773Z,1397860420.773 [NAL9602](INFO): Sent 332 bytes from file Logs/20140418T221104/Express0009.lzma
2014-04-18T22:33:40.773Z,1397860420.773 [NAL9602](INFO): Packets left to send: 2
2014-04-18T22:33:40.774Z,1397860420.774 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T221104/Express0009.lzma.parts/0002.sbd
2014-04-18T22:33:53.789Z,1397860433.789 [NAL9602](INFO): SBD MO Status=1, MOMSN=26730, MT Status=0, MTMSN=0
2014-04-18T22:33:53.837Z,1397860433.837 [NAL9602](INFO): Sent 332 bytes from file Logs/20140418T221104/Express0009.lzma
2014-04-18T22:33:53.837Z,1397860433.837 [NAL9602](INFO): Packets left to send: 1
2014-04-18T22:33:53.838Z,1397860433.838 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T221104/Express0009.lzma.parts/0001.sbd
2014-04-18T22:34:03.758Z,1397860443.758 [NAL9602](INFO): SBD MO Status=1, MOMSN=26731, MT Status=0, MTMSN=0
2014-04-18T22:34:03.809Z,1397860443.809 [NAL9602](INFO): Sent 192 bytes from file Logs/20140418T221104/Express0009.lzma
2014-04-18T22:34:03.809Z,1397860443.809 [NAL9602](INFO): Packets left to send: 0
2014-04-18T22:34:03.810Z,1397860443.810 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T221104/Express0009.lzma.parts/0000.sbd
2014-04-18T22:34:03.810Z,1397860443.810 [NAL9602](INFO): Completed sending Logs/20140418T221104/Express0009.lzma
2014-04-18T22:34:10.876Z,1397860450.876 [NAL9602](INFO): SBD MO Status=1, MOMSN=26732, MT Status=0, MTMSN=0
2014-04-18T22:34:10.924Z,1397860450.924 [NAL9602](INFO): Sent 18 bytes from file Logs/20140418T221104/Express0013.lzma
2014-04-18T22:34:10.924Z,1397860450.924 [NAL9602](INFO): Packets left to send: 0
2014-04-18T22:34:10.926Z,1397860450.926 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T221104/Express0013.lzma.parts/0000.sbd
2014-04-18T22:34:10.926Z,1397860450.926 [NAL9602](INFO): Completed sending Logs/20140418T221104/Express0013.lzma
2014-04-18T22:34:31.223Z,1397860471.223 [NAL9602](INFO): SBD MO Status=2, MOMSN=26733, MT Status=2, MTMSN=0
2014-04-18T22:34:31.224Z,1397860471.224 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-04-18T22:34:51.566Z,1397860491.566 [NAL9602](INFO): SBD MO Status=1, MOMSN=26733, MT Status=0, MTMSN=0
2014-04-18T22:34:51.615Z,1397860491.615 [NAL9602](INFO): Sent 332 bytes from file Logs/20140418T222100/Express0001.lzma
2014-04-18T22:34:51.615Z,1397860491.615 [NAL9602](INFO): Packets left to send: 2
2014-04-18T22:34:51.617Z,1397860491.617 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T222100/Express0001.lzma.parts/0002.sbd
2014-04-18T22:35:06.063Z,1397860506.063 [NAL9602](INFO): SBD MO Status=1, MOMSN=26734, MT Status=0, MTMSN=0
2014-04-18T22:35:06.117Z,1397860506.117 [NAL9602](INFO): Sent 332 bytes from file Logs/20140418T222100/Express0001.lzma
2014-04-18T22:35:06.117Z,1397860506.117 [NAL9602](INFO): Packets left to send: 1
2014-04-18T22:35:06.118Z,1397860506.118 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T222100/Express0001.lzma.parts/0001.sbd
2014-04-18T22:35:25.051Z,1397860525.051 [NAL9602](INFO): SBD MO Status=2, MOMSN=26735, MT Status=2, MTMSN=0
2014-04-18T22:35:25.051Z,1397860525.051 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-04-18T22:35:28.016Z,1397860528.016 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-18T22:35:28.016Z,1397860528.016 [DVL_micro] Data Fault, FailCount= 1
2014-04-18T22:35:28.016Z,1397860528.016 [DVL_micro](ERROR): Data Fault
2014-04-18T22:35:28.093Z,1397860528.093 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-18T22:35:28.504Z,1397860528.504 [DVL_micro](INFO): uninitialize:Powering down
2014-04-18T22:35:28.921Z,1397860528.921 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-18T22:35:28.922Z,1397860528.922 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-18T22:35:28.922Z,1397860528.922 [DVL_micro](ERROR): Hardware Fault
2014-04-18T22:35:29.916Z,1397860529.916 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-18T22:35:29.916Z,1397860529.916 [DVL_micro] No Fault, FailCount= 1
2014-04-18T22:35:30.391Z,1397860530.391 [DVL_micro](INFO): Initializing
2014-04-18T22:35:46.659Z,1397860546.659 [NAL9602](INFO): SBD MO Status=1, MOMSN=26735, MT Status=0, MTMSN=0
2014-04-18T22:35:46.708Z,1397860546.708 [NAL9602](INFO): Sent 93 bytes from file Logs/20140418T222100/Express0001.lzma
2014-04-18T22:35:46.708Z,1397860546.708 [NAL9602](INFO): Packets left to send: 0
2014-04-18T22:35:46.709Z,1397860546.709 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T222100/Express0001.lzma.parts/0000.sbd
2014-04-18T22:35:46.710Z,1397860546.710 [NAL9602](INFO): Completed sending Logs/20140418T222100/Express0001.lzma
2014-04-18T22:35:58.416Z,1397860558.416 [NAL9602](INFO): SBD MO Status=1, MOMSN=26736, MT Status=0, MTMSN=0
2014-04-18T22:35:58.466Z,1397860558.466 [NAL9602](INFO): Sent 332 bytes from file Logs/20140418T222254/Express0001.lzma
2014-04-18T22:35:58.467Z,1397860558.467 [NAL9602](INFO): Packets left to send: 2
2014-04-18T22:35:58.468Z,1397860558.468 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T222254/Express0001.lzma.parts/0002.sbd
2014-04-18T22:36:20.405Z,1397860580.405 [NAL9602](INFO): SBD MO Status=2, MOMSN=26737, MT Status=2, MTMSN=0
2014-04-18T22:36:20.405Z,1397860580.405 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-04-18T22:36:40.022Z,1397860600.022 [NAL9602](INFO): SBD MO Status=1, MOMSN=26737, MT Status=0, MTMSN=0
2014-04-18T22:36:40.071Z,1397860600.071 [NAL9602](INFO): Sent 332 bytes from file Logs/20140418T222254/Express0001.lzma
2014-04-18T22:36:40.071Z,1397860600.071 [NAL9602](INFO): Packets left to send: 1
2014-04-18T22:36:40.073Z,1397860600.073 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T222254/Express0001.lzma.parts/0001.sbd
2014-04-18T22:36:50.963Z,1397860610.963 [NAL9602](INFO): SBD MO Status=1, MOMSN=26738, MT Status=0, MTMSN=0
2014-04-18T22:36:51.017Z,1397860611.017 [NAL9602](INFO): Sent 35 bytes from file Logs/20140418T222254/Express0001.lzma
2014-04-18T22:36:51.017Z,1397860611.017 [NAL9602](INFO): Packets left to send: 0
2014-04-18T22:36:51.018Z,1397860611.018 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T222254/Express0001.lzma.parts/0000.sbd
2014-04-18T22:36:51.018Z,1397860611.018 [NAL9602](INFO): Completed sending Logs/20140418T222254/Express0001.lzma
2014-04-18T22:37:03.932Z,1397860623.932 [NAL9602](INFO): SBD MO Status=1, MOMSN=26739, MT Status=0, MTMSN=0
2014-04-18T22:37:03.984Z,1397860623.984 [NAL9602](INFO): Sent 145 bytes from file Logs/20140418T222254/Express0005.lzma
2014-04-18T22:37:03.984Z,1397860623.984 [NAL9602](INFO): Packets left to send: 0
2014-04-18T22:37:03.985Z,1397860623.985 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T222254/Express0005.lzma.parts/0000.sbd
2014-04-18T22:37:03.986Z,1397860623.986 [NAL9602](INFO): Completed sending Logs/20140418T222254/Express0005.lzma
2014-04-18T22:37:15.661Z,1397860635.661 [NAL9602](INFO): SBD MO Status=1, MOMSN=26740, MT Status=0, MTMSN=0
2014-04-18T22:37:15.730Z,1397860635.730 [NAL9602](INFO): Sent 332 bytes from file Logs/20140418T222601/Express0001.lzma
2014-04-18T22:37:15.730Z,1397860635.730 [NAL9602](INFO): Packets left to send: 2
2014-04-18T22:37:15.732Z,1397860635.732 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T222601/Express0001.lzma.parts/0002.sbd
2014-04-18T22:37:24.420Z,1397860644.420 [NAL9602](INFO): SBD MO Status=1, MOMSN=26741, MT Status=0, MTMSN=0
2014-04-18T22:37:24.477Z,1397860644.477 [NAL9602](INFO): Sent 332 bytes from file Logs/20140418T222601/Express0001.lzma
2014-04-18T22:37:24.477Z,1397860644.477 [NAL9602](INFO): Packets left to send: 1
2014-04-18T22:37:24.479Z,1397860644.479 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T222601/Express0001.lzma.parts/0001.sbd
2014-04-18T22:37:32.620Z,1397860652.620 [NAL9602](INFO): SBD MO Status=1, MOMSN=26742, MT Status=0, MTMSN=0
2014-04-18T22:37:32.672Z,1397860652.672 [NAL9602](INFO): Sent 118 bytes from file Logs/20140418T222601/Express0001.lzma
2014-04-18T22:37:32.672Z,1397860652.672 [NAL9602](INFO): Packets left to send: 0
2014-04-18T22:37:32.674Z,1397860652.674 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T222601/Express0001.lzma.parts/0000.sbd
2014-04-18T22:37:32.674Z,1397860652.674 [NAL9602](INFO): Completed sending Logs/20140418T222601/Express0001.lzma
2014-04-18T22:37:40.755Z,1397860660.755 [NAL9602](INFO): SBD MO Status=1, MOMSN=26743, MT Status=0, MTMSN=0
2014-04-18T22:37:40.805Z,1397860660.805 [NAL9602](INFO): Sent 94 bytes from file Logs/20140418T222601/Express0005.lzma
2014-04-18T22:37:40.805Z,1397860660.805 [NAL9602](INFO): Packets left to send: 0
2014-04-18T22:37:40.807Z,1397860660.807 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T222601/Express0005.lzma.parts/0000.sbd
2014-04-18T22:37:40.807Z,1397860660.807 [NAL9602](INFO): Completed sending Logs/20140418T222601/Express0005.lzma
2014-04-18T22:37:49.406Z,1397860669.406 [NAL9602](INFO): SBD MO Status=0, MOMSN=26744, MT Status=0, MTMSN=0
2014-04-18T22:37:49.500Z,1397860669.500 [Default:Iridium:Read_Iridium] Stopped
2014-04-18T22:37:49.500Z,1397860669.500 [Default:Iridium](INFO): Completed Default:Iridium
2014-04-18T22:37:49.501Z,1397860669.501 [Default:Iridium] Stopped
2014-04-18T22:37:49.501Z,1397860669.501 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-04-18T22:37:49.501Z,1397860669.501 [Default:Iridium:A.SetSpeed] Stopped
2014-04-18T22:37:49.501Z,1397860669.501 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-04-18T22:37:49.501Z,1397860669.501 [Default:WaitAtTheSurface] Running Loop=1
2014-04-18T22:37:49.501Z,1397860669.501 [Default:WaitAtTheSurface](INFO): Aggregate::initialize Default:WaitAtTheSurface
2014-04-18T22:37:49.501Z,1397860669.501 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Running Loop=1
2014-04-18T22:37:49.501Z,1397860669.501 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Initialize.
2014-04-18T22:37:49.501Z,1397860669.501 [Default:WaitAtTheSurface:B.GoToSurface] Running Loop=1
2014-04-18T22:37:49.501Z,1397860669.501 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-18T22:37:49.914Z,1397860669.914 [Default:WaitAtTheSurface:B.GoToSurface] Running Loop=1
2014-04-18T22:37:49.920Z,1397860669.920 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Running Loop=1
2014-04-18T22:37:49.941Z,1397860669.941 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-04-18T22:37:49.941Z,1397860669.941 [Default:CallIridium:B] Stopped
2014-04-18T22:37:49.941Z,1397860669.941 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-04-18T22:37:49.942Z,1397860669.942 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-04-18T22:37:49.942Z,1397860669.942 [Default:CallIridium] Stopped
2014-04-18T22:37:49.942Z,1397860669.942 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-04-18T22:38:00.065Z,1397860680.065 [NAL9602](INFO): Powering down
2014-04-18T22:38:45.067Z,1397860725.067 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-18T22:38:45.067Z,1397860725.067 [DVL_micro] Data Fault, FailCount= 1
2014-04-18T22:38:45.067Z,1397860725.067 [DVL_micro](ERROR): Data Fault
2014-04-18T22:38:45.154Z,1397860725.154 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-18T22:38:50.055Z,1397860730.055 [DVL_micro](INFO): uninitialize:Powering down
2014-04-18T22:38:55.058Z,1397860735.058 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-18T22:38:55.058Z,1397860735.058 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-18T22:38:55.058Z,1397860735.058 [DVL_micro](ERROR): Hardware Fault
2014-04-18T22:39:00.117Z,1397860740.117 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-18T22:39:00.117Z,1397860740.117 [DVL_micro] No Fault, FailCount= 1
2014-04-18T22:39:05.056Z,1397860745.056 [DVL_micro](INFO): Initializing
2014-04-18T22:42:25.064Z,1397860945.064 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-18T22:42:25.064Z,1397860945.064 [DVL_micro] Data Fault, FailCount= 1
2014-04-18T22:42:25.064Z,1397860945.064 [DVL_micro](ERROR): Data Fault
2014-04-18T22:42:25.189Z,1397860945.189 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-18T22:42:30.060Z,1397860950.060 [DVL_micro](INFO): uninitialize:Powering down
2014-04-18T22:42:35.055Z,1397860955.055 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-18T22:42:35.055Z,1397860955.055 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-18T22:42:35.055Z,1397860955.055 [DVL_micro](ERROR): Hardware Fault
2014-04-18T22:42:40.074Z,1397860960.074 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-18T22:42:40.074Z,1397860960.074 [DVL_micro] No Fault, FailCount= 1
2014-04-18T22:42:45.065Z,1397860965.065 [DVL_micro](INFO): Initializing
2014-04-18T22:42:50.073Z,1397860970.073 [Default:CallIridium] Running Loop=1
2014-04-18T22:42:50.073Z,1397860970.073 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-04-18T22:42:50.073Z,1397860970.073 [Default:CallIridium:A] Running Loop=1
2014-04-18T22:42:50.073Z,1397860970.073 [Default:CallIridium:A] Stopped
2014-04-18T22:42:50.074Z,1397860970.074 [Default:CallIridium:B] Running Loop=1
2014-04-18T22:42:50.074Z,1397860970.074 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-04-18T22:42:55.077Z,1397860975.077 [Default:Iridium] Running Loop=1
2014-04-18T22:42:55.077Z,1397860975.077 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-04-18T22:42:55.077Z,1397860975.077 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-04-18T22:42:55.077Z,1397860975.077 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-04-18T22:42:55.077Z,1397860975.077 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-04-18T22:42:55.077Z,1397860975.077 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-18T22:42:55.078Z,1397860975.078 [Default:Iridium:B.GoToSurface] Stopped
2014-04-18T22:42:55.078Z,1397860975.078 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-18T22:42:55.078Z,1397860975.078 [Default:Iridium:Read_Iridium] Running Loop=1
2014-04-18T22:42:55.078Z,1397860975.078 [Default:GPS] Running Loop=1
2014-04-18T22:42:55.079Z,1397860975.079 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-04-18T22:42:55.079Z,1397860975.079 [Default:GPS:A.SetSpeed] Running Loop=1
2014-04-18T22:42:55.079Z,1397860975.079 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-04-18T22:42:55.079Z,1397860975.079 [Default:GPS:B.GoToSurface] Running Loop=1
2014-04-18T22:42:55.079Z,1397860975.079 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-18T22:42:55.080Z,1397860975.080 [Default:GPS:B.GoToSurface] Stopped
2014-04-18T22:42:55.080Z,1397860975.080 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-18T22:42:55.080Z,1397860975.080 [Default:GPS:Read_GPS] Running Loop=1
2014-04-18T22:42:56.108Z,1397860976.108 [NAL9602](INFO): Powering up
2014-04-18T22:43:06.866Z,1397860986.866 [NAL9602](INFO): NAL9602 initialized
2014-04-18T22:43:23.524Z,1397861003.524 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=26745, MT Status=1, MTMSN=1778
2014-04-18T22:43:23.577Z,1397861003.577 [NAL9602](INFO): Sent 78 bytes from file Logs/20140418T222601/Courier0008.lzma
2014-04-18T22:43:23.578Z,1397861003.578 [NAL9602](INFO): Packets left to send: 0
2014-04-18T22:43:23.579Z,1397861003.579 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T222601/Courier0008.lzma.parts/0000.sbd
2014-04-18T22:43:23.579Z,1397861003.579 [NAL9602](INFO): Completed sending Logs/20140418T222601/Courier0008.lzma
2014-04-18T22:43:24.290Z,1397861004.290 [NAL9602](INFO): Received command:ibit
2014-04-18T22:43:24.315Z,1397861004.315 [CommandLine](IMPORTANT): got command ibit
2014-04-18T22:43:24.362Z,1397861004.362 [IBIT](IMPORTANT): Beginning Initiated BIT
2014-04-18T22:43:24.362Z,1397861004.362 [IBIT](IMPORTANT): Beginning control surface checks.
2014-04-18T22:43:24.364Z,1397861004.364 [CBIT](IMPORTANT): Beginning GF scan
2014-04-18T22:43:50.738Z,1397861030.738 [NAL9602](INFO): SBD MO Status=2, MOMSN=26746, MT Status=2, MTMSN=0
2014-04-18T22:43:50.738Z,1397861030.738 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-04-18T22:43:50.834Z,1397861030.834 [CBIT](IMPORTANT): No ground fault detected
2014-04-18T22:43:52.138Z,1397861032.138 [NAL9602](IMPORTANT): GPS fix at: 1397861030.00
2014-04-18T22:44:10.335Z,1397861050.335 [NAL9602](INFO): SBD MO Status=1, MOMSN=26746, MT Status=0, MTMSN=0
2014-04-18T22:44:10.393Z,1397861050.393 [NAL9602](INFO): Sent 332 bytes from file Logs/20140418T222601/Express0009.lzma
2014-04-18T22:44:10.393Z,1397861050.393 [NAL9602](INFO): Packets left to send: 1
2014-04-18T22:44:10.395Z,1397861050.395 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T222601/Express0009.lzma.parts/0001.sbd
2014-04-18T22:44:10.460Z,1397861050.460 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 3
Latitude: 33.616608 Longitude: -117.917732
2014-04-18T22:44:11.099Z,1397861051.099 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 230.500015
Voltage: 16.084312
2014-04-18T22:44:11.100Z,1397861051.100 [IBIT](IMPORTANT): batteryCapacityThreshold: 5.000000 Ah
2014-04-18T22:44:11.100Z,1397861051.100 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.500000 V
2014-04-18T22:44:13.569Z,1397861053.569 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2014-04-18T22:44:13.570Z,1397861053.570 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2014-04-18T22:44:13.570Z,1397861053.570 [IBIT](IMPORTANT): Pressure:11.265132 PSI
2014-04-18T22:44:13.570Z,1397861053.570 [IBIT](IMPORTANT): Humidity:8.622141 %
2014-04-18T22:44:14.140Z,1397861054.140 [IBIT](IMPORTANT): surfaceThreshold: 0.500000 m
2014-04-18T22:44:14.140Z,1397861054.140 [IBIT](IMPORTANT): buoyancyNeutral: 300.000000 cc
2014-04-18T22:44:14.141Z,1397861054.141 [IBIT](IMPORTANT): massDefault: 0.000000 cm
2014-04-18T22:44:14.141Z,1397861054.141 [IBIT](IMPORTANT): stopDepth: 112.000000 m
2014-04-18T22:44:14.141Z,1397861054.141 [IBIT](IMPORTANT): abortDepth: 130.000000 m
2014-04-18T22:44:14.141Z,1397861054.141 [IBIT](IMPORTANT): IBIT PASSED
2014-04-18T22:44:14.534Z,1397861054.534 [Default:GPS:Read_GPS] Stopped
2014-04-18T22:44:14.534Z,1397861054.534 [Default:GPS:D] Running Loop=1
2014-04-18T22:44:14.940Z,1397861054.940 [Default:GPS:D] Stopped
2014-04-18T22:44:14.941Z,1397861054.941 [Default:GPS](INFO): Completed Default:GPS
2014-04-18T22:44:14.941Z,1397861054.941 [Default:GPS] Stopped
2014-04-18T22:44:14.941Z,1397861054.941 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-04-18T22:44:14.941Z,1397861054.941 [Default:GPS:A.SetSpeed] Stopped
2014-04-18T22:44:14.941Z,1397861054.941 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-04-18T22:44:19.150Z,1397861059.150 [NAL9602](INFO): SBD MO Status=1, MOMSN=26747, MT Status=0, MTMSN=0
2014-04-18T22:44:19.203Z,1397861059.203 [NAL9602](INFO): Sent 14 bytes from file Logs/20140418T222601/Express0009.lzma
2014-04-18T22:44:19.203Z,1397861059.203 [NAL9602](INFO): Packets left to send: 0
2014-04-18T22:44:19.205Z,1397861059.205 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T222601/Express0009.lzma.parts/0000.sbd
2014-04-18T22:44:19.205Z,1397861059.205 [NAL9602](INFO): Completed sending Logs/20140418T222601/Express0009.lzma
2014-04-18T22:44:27.098Z,1397861067.098 [NAL9602](INFO): SBD MO Status=0, MOMSN=26748, MT Status=0, MTMSN=0
2014-04-18T22:44:43.808Z,1397861083.808 [NAL9602](INFO): SBD MO Status=1, MOMSN=26749, MT Status=0, MTMSN=0
2014-04-18T22:44:43.869Z,1397861083.869 [NAL9602](INFO): Sent 75 bytes from file Logs/20140418T222601/Courier0012.lzma
2014-04-18T22:44:43.869Z,1397861083.869 [NAL9602](INFO): Packets left to send: 0
2014-04-18T22:44:43.871Z,1397861083.871 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T222601/Courier0012.lzma.parts/0000.sbd
2014-04-18T22:44:43.871Z,1397861083.871 [NAL9602](INFO): Completed sending Logs/20140418T222601/Courier0012.lzma
2014-04-18T22:45:02.652Z,1397861102.652 [NAL9602](INFO): SBD MO Status=1, MOMSN=26750, MT Status=0, MTMSN=0
2014-04-18T22:45:02.706Z,1397861102.706 [NAL9602](INFO): Sent 332 bytes from file Logs/20140418T222601/Express0013.lzma
2014-04-18T22:45:02.706Z,1397861102.706 [NAL9602](INFO): Packets left to send: 1
2014-04-18T22:45:02.708Z,1397861102.708 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T222601/Express0013.lzma.parts/0001.sbd
2014-04-18T22:45:16.600Z,1397861116.600 [NAL9602](INFO): SBD MO Status=1, MOMSN=26751, MT Status=0, MTMSN=0
2014-04-18T22:45:16.656Z,1397861116.656 [NAL9602](INFO): Sent 278 bytes from file Logs/20140418T222601/Express0013.lzma
2014-04-18T22:45:16.656Z,1397861116.656 [NAL9602](INFO): Packets left to send: 0
2014-04-18T22:45:16.658Z,1397861116.658 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T222601/Express0013.lzma.parts/0000.sbd
2014-04-18T22:45:16.658Z,1397861116.658 [NAL9602](INFO): Completed sending Logs/20140418T222601/Express0013.lzma
2014-04-18T22:45:27.796Z,1397861127.796 [NAL9602](INFO): SBD MO Status=0, MOMSN=26752, MT Status=0, MTMSN=0
2014-04-18T22:45:27.898Z,1397861127.898 [Default:Iridium:Read_Iridium] Stopped
2014-04-18T22:45:27.899Z,1397861127.899 [Default:Iridium](INFO): Completed Default:Iridium
2014-04-18T22:45:27.899Z,1397861127.899 [Default:Iridium] Stopped
2014-04-18T22:45:27.899Z,1397861127.899 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-04-18T22:45:27.899Z,1397861127.899 [Default:Iridium:A.SetSpeed] Stopped
2014-04-18T22:45:27.899Z,1397861127.899 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-04-18T22:45:28.318Z,1397861128.318 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-04-18T22:45:28.318Z,1397861128.318 [Default:CallIridium:B] Stopped
2014-04-18T22:45:28.318Z,1397861128.318 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-04-18T22:45:28.319Z,1397861128.319 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-04-18T22:45:28.319Z,1397861128.319 [Default:CallIridium] Stopped
2014-04-18T22:45:28.319Z,1397861128.319 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-04-18T22:45:38.468Z,1397861138.468 [NAL9602](INFO): Powering down
2014-04-18T22:46:03.402Z,1397861163.402 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-18T22:46:03.402Z,1397861163.402 [DVL_micro] Data Fault, FailCount= 1
2014-04-18T22:46:03.402Z,1397861163.402 [DVL_micro](ERROR): Data Fault
2014-04-18T22:46:03.481Z,1397861163.481 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-18T22:46:08.486Z,1397861168.486 [DVL_micro](INFO): uninitialize:Powering down
2014-04-18T22:46:13.438Z,1397861173.438 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-18T22:46:13.438Z,1397861173.438 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-18T22:46:13.438Z,1397861173.438 [DVL_micro](ERROR): Hardware Fault
2014-04-18T22:46:18.541Z,1397861178.541 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-18T22:46:18.541Z,1397861178.541 [DVL_micro] No Fault, FailCount= 1
2014-04-18T22:46:23.440Z,1397861183.440 [DVL_micro](INFO): Initializing
2014-04-18T22:49:43.451Z,1397861383.451 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-18T22:49:43.452Z,1397861383.452 [DVL_micro] Data Fault, FailCount= 1
2014-04-18T22:49:43.452Z,1397861383.452 [DVL_micro](ERROR): Data Fault
2014-04-18T22:49:43.521Z,1397861383.521 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-18T22:49:48.467Z,1397861388.467 [DVL_micro](INFO): uninitialize:Powering down
2014-04-18T22:49:53.462Z,1397861393.462 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-18T22:49:53.463Z,1397861393.463 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-18T22:49:53.463Z,1397861393.463 [DVL_micro](ERROR): Hardware Fault
2014-04-18T22:49:58.517Z,1397861398.517 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-18T22:49:58.517Z,1397861398.517 [DVL_micro] No Fault, FailCount= 1
2014-04-18T22:50:03.464Z,1397861403.464 [DVL_micro](INFO): Initializing
2014-04-18T22:50:28.505Z,1397861428.505 [Default:CallIridium] Running Loop=1
2014-04-18T22:50:28.505Z,1397861428.505 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-04-18T22:50:28.505Z,1397861428.505 [Default:CallIridium:A] Running Loop=1
2014-04-18T22:50:28.506Z,1397861428.506 [Default:CallIridium:A] Stopped
2014-04-18T22:50:28.506Z,1397861428.506 [Default:CallIridium:B] Running Loop=1
2014-04-18T22:50:28.506Z,1397861428.506 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-04-18T22:50:33.532Z,1397861433.532 [Default:Iridium] Running Loop=1
2014-04-18T22:50:33.532Z,1397861433.532 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-04-18T22:50:33.532Z,1397861433.532 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-04-18T22:50:33.533Z,1397861433.533 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-04-18T22:50:33.533Z,1397861433.533 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-04-18T22:50:33.533Z,1397861433.533 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-18T22:50:33.533Z,1397861433.533 [Default:Iridium:B.GoToSurface] Stopped
2014-04-18T22:50:33.534Z,1397861433.534 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-18T22:50:33.534Z,1397861433.534 [Default:Iridium:Read_Iridium] Running Loop=1
2014-04-18T22:50:33.534Z,1397861433.534 [Default:GPS] Running Loop=1
2014-04-18T22:50:33.534Z,1397861433.534 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-04-18T22:50:33.534Z,1397861433.534 [Default:GPS:A.SetSpeed] Running Loop=1
2014-04-18T22:50:33.558Z,1397861433.558 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-04-18T22:50:33.559Z,1397861433.559 [Default:GPS:B.GoToSurface] Running Loop=1
2014-04-18T22:50:33.559Z,1397861433.559 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-18T22:50:33.560Z,1397861433.560 [Default:GPS:B.GoToSurface] Stopped
2014-04-18T22:50:33.560Z,1397861433.560 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-18T22:50:33.560Z,1397861433.560 [Default:GPS:Read_GPS] Running Loop=1
2014-04-18T22:50:34.618Z,1397861434.618 [NAL9602](INFO): Powering up
2014-04-18T22:50:45.349Z,1397861445.349 [NAL9602](INFO): NAL9602 initialized
2014-04-18T22:51:10.448Z,1397861470.448 [NAL9602](INFO): SBD MO Status=2, MOMSN=26753, MT Status=2, MTMSN=0
2014-04-18T22:51:10.448Z,1397861470.448 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-04-18T22:51:11.744Z,1397861471.744 [NAL9602](IMPORTANT): GPS fix at: 1397861470.00
2014-04-18T22:51:11.762Z,1397861471.762 [Default:GPS:Read_GPS] Stopped
2014-04-18T22:51:11.762Z,1397861471.762 [Default:GPS:D] Running Loop=1
2014-04-18T22:51:12.209Z,1397861472.209 [Default:GPS:D] Stopped
2014-04-18T22:51:12.209Z,1397861472.209 [Default:GPS](INFO): Completed Default:GPS
2014-04-18T22:51:12.209Z,1397861472.209 [Default:GPS] Stopped
2014-04-18T22:51:12.210Z,1397861472.210 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-04-18T22:51:12.210Z,1397861472.210 [Default:GPS:A.SetSpeed] Stopped
2014-04-18T22:51:12.210Z,1397861472.210 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-04-18T22:51:33.586Z,1397861493.586 [NAL9602](INFO): SBD MO Status=2, MOMSN=26753, MT Status=2, MTMSN=0
2014-04-18T22:51:33.586Z,1397861493.586 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-04-18T22:51:59.641Z,1397861519.641 [NAL9602](INFO): SBD MO Status=2, MOMSN=26753, MT Status=2, MTMSN=0
2014-04-18T22:51:59.641Z,1397861519.641 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-04-18T22:52:22.822Z,1397861542.822 [NAL9602](INFO): SBD MO Status=2, MOMSN=26753, MT Status=2, MTMSN=0
2014-04-18T22:52:22.822Z,1397861542.822 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-04-18T22:52:55.404Z,1397861575.404 [NAL9602](INFO): SBD MO Status=2, MOMSN=26753, MT Status=2, MTMSN=0
2014-04-18T22:52:55.404Z,1397861575.404 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-04-18T22:53:22.568Z,1397861602.568 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=26753, MT Status=1, MTMSN=1779
2014-04-18T22:53:22.621Z,1397861602.621 [NAL9602](INFO): Sent 45 bytes from file Logs/20140418T222601/Courier0016.lzma
2014-04-18T22:53:22.621Z,1397861602.621 [NAL9602](INFO): Packets left to send: 0
2014-04-18T22:53:22.623Z,1397861602.623 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T222601/Courier0016.lzma.parts/0000.sbd
2014-04-18T22:53:22.623Z,1397861602.623 [NAL9602](INFO): Completed sending Logs/20140418T222601/Courier0016.lzma
2014-04-18T22:53:23.334Z,1397861603.334 [NAL9602](INFO): Received command:failc
2014-04-18T22:53:23.386Z,1397861603.386 [CommandLine](IMPORTANT): got command failComponent
2014-04-18T22:53:23.386Z,1397861603.386 [CommandLine](IMPORTANT): Failed components:
2014-04-18T22:53:23.387Z,1397861603.387 [CommandLine](IMPORTANT): No failed Components.
2014-04-18T22:53:23.752Z,1397861603.752 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-18T22:53:23.752Z,1397861603.752 [DVL_micro] Data Fault, FailCount= 1
2014-04-18T22:53:23.752Z,1397861603.752 [DVL_micro](ERROR): Data Fault
2014-04-18T22:53:23.833Z,1397861603.833 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-18T22:53:24.205Z,1397861604.205 [DVL_micro](INFO): uninitialize:Powering down
2014-04-18T22:53:24.625Z,1397861604.625 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-18T22:53:24.625Z,1397861604.625 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-18T22:53:24.625Z,1397861604.625 [DVL_micro](ERROR): Hardware Fault
2014-04-18T22:53:25.116Z,1397861605.116 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-18T22:53:25.116Z,1397861605.116 [DVL_micro] No Fault, FailCount= 1
2014-04-18T22:53:25.504Z,1397861605.504 [DVL_micro](INFO): Initializing
2014-04-18T22:53:40.790Z,1397861620.790 [NAL9602](INFO): SBD MO Status=1, MOMSN=26754, MT Status=0, MTMSN=0
2014-04-18T22:53:40.833Z,1397861620.833 [NAL9602](INFO): Sent 163 bytes from file Logs/20140418T222601/Express0017.lzma
2014-04-18T22:53:40.834Z,1397861620.834 [NAL9602](INFO): Packets left to send: 0
2014-04-18T22:53:40.835Z,1397861620.835 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T222601/Express0017.lzma.parts/0000.sbd
2014-04-18T22:53:40.836Z,1397861620.836 [NAL9602](INFO): Completed sending Logs/20140418T222601/Express0017.lzma
2014-04-18T22:54:01.910Z,1397861641.910 [NAL9602](INFO): SBD MO Status=2, MOMSN=26755, MT Status=2, MTMSN=0
2014-04-18T22:54:01.910Z,1397861641.910 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-04-18T22:54:15.683Z,1397861655.683 [NAL9602](INFO): SBD MO Status=0, MOMSN=26755, MT Status=0, MTMSN=0
2014-04-18T22:54:37.041Z,1397861677.041 [NAL9602](INFO): SBD MO Status=1, MOMSN=26756, MT Status=0, MTMSN=0
2014-04-18T22:54:37.089Z,1397861677.089 [NAL9602](INFO): Sent 75 bytes from file Logs/20140418T222601/Courier0020.lzma
2014-04-18T22:54:37.089Z,1397861677.089 [NAL9602](INFO): Packets left to send: 0
2014-04-18T22:54:37.090Z,1397861677.090 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T222601/Courier0020.lzma.parts/0000.sbd
2014-04-18T22:54:37.091Z,1397861677.091 [NAL9602](INFO): Completed sending Logs/20140418T222601/Courier0020.lzma
2014-04-18T22:54:49.334Z,1397861689.334 [NAL9602](INFO): SBD MO Status=1, MOMSN=26757, MT Status=0, MTMSN=0
2014-04-18T22:54:49.384Z,1397861689.384 [NAL9602](INFO): Sent 284 bytes from file Logs/20140418T222601/Express0021.lzma
2014-04-18T22:54:49.384Z,1397861689.384 [NAL9602](INFO): Packets left to send: 0
2014-04-18T22:54:49.385Z,1397861689.385 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T222601/Express0021.lzma.parts/0000.sbd
2014-04-18T22:54:49.386Z,1397861689.386 [NAL9602](INFO): Completed sending Logs/20140418T222601/Express0021.lzma
2014-04-18T22:55:06.078Z,1397861706.078 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 40 of 46
2014-04-18T22:55:06.079Z,1397861706.079 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 08 1263.9 367.5 2 315.4 1229.2 367.5 2 114 1263 367 2 315 1229 367 2 1.42 1.81 350.8 -3.0 31.9 0.005 35.0 1489 113
2014-04-18T22:55:11.587Z,1397861711.587 [NAL9602](INFO): SBD MO Status=2, MOMSN=26758, MT Status=2, MTMSN=0
2014-04-18T22:55:11.587Z,1397861711.587 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-04-18T22:55:12.418Z,1397861712.418 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:126 Calculated:127
2014-04-18T22:55:12.423Z,1397861712.423 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -497 1547 -440 739 3 2 3 1078.4 363.7 2 123.6 1073.9 363.7 2 -76 1078 363 2 123 1073 363 2 0.08 2.33 349.4 -3.0 31.9 0.005 35.0 1489 126
2014-04-18T22:55:28.085Z,1397861728.085 [NAL9602](INFO): SBD MO Status=2, MOMSN=26758, MT Status=2, MTMSN=0
2014-04-18T22:55:28.086Z,1397861728.086 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-04-18T22:55:38.072Z,1397861738.072 [NAL9602](INFO): SBD MO Status=0, MOMSN=26758, MT Status=0, MTMSN=0
2014-04-18T22:55:38.158Z,1397861738.158 [Default:Iridium:Read_Iridium] Stopped
2014-04-18T22:55:38.159Z,1397861738.159 [Default:Iridium](INFO): Completed Default:Iridium
2014-04-18T22:55:38.160Z,1397861738.160 [Default:Iridium] Stopped
2014-04-18T22:55:38.160Z,1397861738.160 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-04-18T22:55:38.160Z,1397861738.160 [Default:Iridium:A.SetSpeed] Stopped
2014-04-18T22:55:38.160Z,1397861738.160 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-04-18T22:55:38.669Z,1397861738.669 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-04-18T22:55:38.669Z,1397861738.669 [Default:CallIridium:B] Stopped
2014-04-18T22:55:38.669Z,1397861738.669 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-04-18T22:55:38.669Z,1397861738.669 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-04-18T22:55:38.669Z,1397861738.669 [Default:CallIridium] Stopped
2014-04-18T22:55:38.669Z,1397861738.669 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-04-18T22:55:48.741Z,1397861748.741 [NAL9602](INFO): Powering down
2014-04-18T22:56:33.727Z,1397861793.727 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-18T22:56:33.728Z,1397861793.728 [DVL_micro] Data Fault, FailCount= 1
2014-04-18T22:56:33.728Z,1397861793.728 [DVL_micro](ERROR): Data Fault
2014-04-18T22:56:33.757Z,1397861793.757 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-18T22:56:38.699Z,1397861798.699 [DVL_micro](INFO): uninitialize:Powering down
2014-04-18T22:56:43.751Z,1397861803.751 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-18T22:56:43.751Z,1397861803.751 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-18T22:56:43.751Z,1397861803.751 [DVL_micro](ERROR): Hardware Fault
2014-04-18T22:56:48.760Z,1397861808.760 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-18T22:56:48.760Z,1397861808.760 [DVL_micro] No Fault, FailCount= 1
2014-04-18T22:56:53.761Z,1397861813.761 [DVL_micro](INFO): Initializing
2014-04-18T23:00:13.756Z,1397862013.756 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-04-18T23:00:13.756Z,1397862013.756 [DVL_micro] Data Fault, FailCount= 1
2014-04-18T23:00:13.756Z,1397862013.756 [DVL_micro](ERROR): Data Fault
2014-04-18T23:00:13.785Z,1397862013.785 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-04-18T23:00:18.746Z,1397862018.746 [DVL_micro](INFO): uninitialize:Powering down
2014-04-18T23:00:23.748Z,1397862023.748 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-04-18T23:00:23.748Z,1397862023.748 [DVL_micro] Hardware Fault, FailCount= 1
2014-04-18T23:00:23.748Z,1397862023.748 [DVL_micro](ERROR): Hardware Fault
2014-04-18T23:00:28.679Z,1397862028.679 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-04-18T23:00:28.679Z,1397862028.679 [DVL_micro] No Fault, FailCount= 1
2014-04-18T23:00:33.810Z,1397862033.810 [DVL_micro](INFO): Initializing
2014-04-18T23:00:38.712Z,1397862038.712 [Default:CallIridium] Running Loop=1
2014-04-18T23:00:38.712Z,1397862038.712 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-04-18T23:00:38.712Z,1397862038.712 [Default:CallIridium:A] Running Loop=1
2014-04-18T23:00:38.714Z,1397862038.714 [Default:CallIridium:A] Stopped
2014-04-18T23:00:38.714Z,1397862038.714 [Default:CallIridium:B] Running Loop=1
2014-04-18T23:00:38.714Z,1397862038.714 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-04-18T23:00:43.743Z,1397862043.743 [Default:Iridium] Running Loop=1
2014-04-18T23:00:43.743Z,1397862043.743 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-04-18T23:00:43.744Z,1397862043.744 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-04-18T23:00:43.744Z,1397862043.744 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-04-18T23:00:43.744Z,1397862043.744 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-04-18T23:00:43.744Z,1397862043.744 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-18T23:00:43.745Z,1397862043.745 [Default:Iridium:B.GoToSurface] Stopped
2014-04-18T23:00:43.745Z,1397862043.745 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-18T23:00:43.745Z,1397862043.745 [Default:Iridium:Read_Iridium] Running Loop=1
2014-04-18T23:00:43.745Z,1397862043.745 [Default:GPS] Running Loop=1
2014-04-18T23:00:43.745Z,1397862043.745 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-04-18T23:00:43.746Z,1397862043.746 [Default:GPS:A.SetSpeed] Running Loop=1
2014-04-18T23:00:43.746Z,1397862043.746 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-04-18T23:00:43.746Z,1397862043.746 [Default:GPS:B.GoToSurface] Running Loop=1
2014-04-18T23:00:43.746Z,1397862043.746 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-18T23:00:43.747Z,1397862043.747 [Default:GPS:B.GoToSurface] Stopped
2014-04-18T23:00:43.747Z,1397862043.747 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-18T23:00:43.747Z,1397862043.747 [Default:GPS:Read_GPS] Running Loop=1
2014-04-18T23:00:44.812Z,1397862044.812 [NAL9602](INFO): Powering up
2014-04-18T23:00:55.644Z,1397862055.644 [NAL9602](INFO): NAL9602 initialized
2014-04-18T23:01:19.924Z,1397862079.924 [NAL9602](INFO): SBD MO Status=1, MOMSN=26759, MT Status=0, MTMSN=0
2014-04-18T23:01:19.980Z,1397862079.980 [NAL9602](INFO): Sent 45 bytes from file Logs/20140418T222601/Courier0024.lzma
2014-04-18T23:01:19.980Z,1397862079.980 [NAL9602](INFO): Packets left to send: 0
2014-04-18T23:01:19.982Z,1397862079.982 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T222601/Courier0024.lzma.parts/0000.sbd
2014-04-18T23:01:19.982Z,1397862079.982 [NAL9602](INFO): Completed sending Logs/20140418T222601/Courier0024.lzma
2014-04-18T23:01:27.482Z,1397862087.482 [NAL9602](INFO): SBD MO Status=1, MOMSN=26760, MT Status=0, MTMSN=0
2014-04-18T23:01:27.529Z,1397862087.529 [NAL9602](INFO): Sent 315 bytes from file Logs/20140418T222601/Express0025.lzma
2014-04-18T23:01:27.529Z,1397862087.529 [NAL9602](INFO): Packets left to send: 0
2014-04-18T23:01:27.531Z,1397862087.531 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T222601/Express0025.lzma.parts/0000.sbd
2014-04-18T23:01:27.531Z,1397862087.531 [NAL9602](INFO): Completed sending Logs/20140418T222601/Express0025.lzma
2014-04-18T23:01:35.117Z,1397862095.117 [Radio_Freewave](INFO): Powering down
2014-04-18T23:01:39.233Z,1397862099.233 [NAL9602](INFO): SBD MO Status=2, MOMSN=26761, MT Status=2, MTMSN=0
2014-04-18T23:01:39.234Z,1397862099.234 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-04-18T23:01:40.663Z,1397862100.663 [NAL9602](IMPORTANT): GPS fix at: 1397862098.00
2014-04-18T23:01:40.711Z,1397862100.711 [Default:GPS:Read_GPS] Stopped
2014-04-18T23:01:40.711Z,1397862100.711 [Default:GPS:D] Running Loop=1
2014-04-18T23:01:41.214Z,1397862101.214 [Default:GPS:D] Stopped
2014-04-18T23:01:41.215Z,1397862101.215 [Default:GPS](INFO): Completed Default:GPS
2014-04-18T23:01:41.215Z,1397862101.215 [Default:GPS] Stopped
2014-04-18T23:01:41.215Z,1397862101.215 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-04-18T23:01:41.215Z,1397862101.215 [Default:GPS:A.SetSpeed] Stopped
2014-04-18T23:01:41.215Z,1397862101.215 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-04-18T23:01:44.582Z,1397862104.582 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2014-04-18T23:01:47.685Z,1397862107.685 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2014-04-18T23:01:48.694Z,1397862108.694 [Radio_Freewave](INFO): Powering up
2014-04-18T23:01:49.766Z,1397862109.766 [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-18T23:01:51.792Z,1397862111.792 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2014-04-18T23:01:55.328Z,1397862115.328 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2014-04-18T23:02:06.312Z,1397862126.312 [NAL9602](INFO): SBD MO Status=0, MOMSN=26761, MT Status=0, MTMSN=0
2014-04-18T23:02:06.402Z,1397862126.402 [Default:Iridium:Read_Iridium] Stopped
2014-04-18T23:02:06.403Z,1397862126.403 [Default:Iridium](INFO): Completed Default:Iridium
2014-04-18T23:02:06.403Z,1397862126.403 [Default:Iridium] Stopped
2014-04-18T23:02:06.403Z,1397862126.403 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-04-18T23:02:06.403Z,1397862126.403 [Default:Iridium:A.SetSpeed] Stopped
2014-04-18T23:02:06.403Z,1397862126.403 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-04-18T23:02:06.773Z,1397862126.773 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-04-18T23:02:06.774Z,1397862126.774 [Default:CallIridium:B] Stopped
2014-04-18T23:02:06.774Z,1397862126.774 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-04-18T23:02:06.774Z,1397862126.774 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-04-18T23:02:06.774Z,1397862126.774 [Default:CallIridium] Stopped
2014-04-18T23:02:06.774Z,1397862126.774 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-04-18T23:02:16.940Z,1397862136.940 [NAL9602](INFO): Powering down
2014-04-18T23:07:06.968Z,1397862426.968 [Default:CallIridium] Running Loop=1
2014-04-18T23:07:06.968Z,1397862426.968 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-04-18T23:07:06.968Z,1397862426.968 [Default:CallIridium:A] Running Loop=1
2014-04-18T23:07:06.968Z,1397862426.968 [Default:CallIridium:A] Stopped
2014-04-18T23:07:06.968Z,1397862426.968 [Default:CallIridium:B] Running Loop=1
2014-04-18T23:07:06.969Z,1397862426.969 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-04-18T23:07:12.059Z,1397862432.059 [Default:Iridium] Running Loop=1
2014-04-18T23:07:12.059Z,1397862432.059 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-04-18T23:07:12.059Z,1397862432.059 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-04-18T23:07:12.059Z,1397862432.059 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-04-18T23:07:12.060Z,1397862432.060 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-04-18T23:07:12.060Z,1397862432.060 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-18T23:07:12.060Z,1397862432.060 [Default:Iridium:B.GoToSurface] Stopped
2014-04-18T23:07:12.061Z,1397862432.061 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-18T23:07:12.061Z,1397862432.061 [Default:Iridium:Read_Iridium] Running Loop=1
2014-04-18T23:07:12.061Z,1397862432.061 [Default:GPS] Running Loop=1
2014-04-18T23:07:12.061Z,1397862432.061 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-04-18T23:07:12.061Z,1397862432.061 [Default:GPS:A.SetSpeed] Running Loop=1
2014-04-18T23:07:12.061Z,1397862432.061 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-04-18T23:07:12.061Z,1397862432.061 [Default:GPS:B.GoToSurface] Running Loop=1
2014-04-18T23:07:12.061Z,1397862432.061 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-18T23:07:12.062Z,1397862432.062 [Default:GPS:B.GoToSurface] Stopped
2014-04-18T23:07:12.062Z,1397862432.062 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-18T23:07:12.062Z,1397862432.062 [Default:GPS:Read_GPS] Running Loop=1
2014-04-18T23:07:13.078Z,1397862433.078 [NAL9602](INFO): Powering up
2014-04-18T23:07:23.849Z,1397862443.849 [NAL9602](INFO): NAL9602 initialized
2014-04-18T23:07:42.616Z,1397862462.616 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=26762, MT Status=1, MTMSN=1780
2014-04-18T23:07:42.667Z,1397862462.667 [NAL9602](INFO): Sent 76 bytes from file Logs/20140418T222601/Courier0028.lzma
2014-04-18T23:07:42.667Z,1397862462.667 [NAL9602](INFO): Packets left to send: 0
2014-04-18T23:07:42.668Z,1397862462.668 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T222601/Courier0028.lzma.parts/0000.sbd
2014-04-18T23:07:42.669Z,1397862462.669 [NAL9602](INFO): Completed sending Logs/20140418T222601/Courier0028.lzma
2014-04-18T23:07:43.328Z,1397862463.328 [NAL9602](INFO): Received command:Restart app
2014-04-18T23:07:43.372Z,1397862463.372 [CommandLine](IMPORTANT): got command restart application
2014-04-18T23:07:44.417Z,1397862464.417 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2014-04-18T23:07:44.418Z,1397862464.418 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2014-04-18T23:07:44.700Z,1397862464.700 [NAL9602](IMPORTANT): GPS fix at: 1397862098.00
2014-04-18T23:07:44.738Z,1397862464.738 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2014-04-18T23:07:44.748Z,1397862464.748 [Default:GPS:Read_GPS] Stopped
2014-04-18T23:07:44.748Z,1397862464.748 [Default:GPS:D] Running Loop=1
2014-04-18T23:07:45.038Z,1397862465.038 [WetLabsBB2FL](INFO): Powering down
2014-04-18T23:07:45.050Z,1397862465.050 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2014-04-18T23:07:45.188Z,1397862465.188 [Default:GPS:D] Stopped
2014-04-18T23:07:45.189Z,1397862465.189 [Default:GPS](INFO): Completed Default:GPS
2014-04-18T23:07:45.189Z,1397862465.189 [Default:GPS] Stopped
2014-04-18T23:07:45.189Z,1397862465.189 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-04-18T23:07:45.189Z,1397862465.189 [Default:GPS:A.SetSpeed] Stopped
2014-04-18T23:07:45.189Z,1397862465.189 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-04-18T23:07:45.443Z,1397862465.443 [CTD_NeilBrown](INFO): Powering down
2014-04-18T23:07:45.455Z,1397862465.455 [ComponentRegistry](INFO): Shutting down AsyncPiEstimator ThreadHandler
2014-04-18T23:07:45.643Z,1397862465.643 [AsyncPiEstimator](DEBUG): Uninitialize AsyncPiEstimator.
2014-04-18T23:07:45.656Z,1397862465.656 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2014-04-18T23:07:45.692Z,1397862465.692 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2014-04-18T23:07:45.692Z,1397862465.692 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2014-04-18T23:07:46.035Z,1397862466.035 [controlThread](DEBUG): Uninitializing ControlThread
2014-04-18T23:07:46.035Z,1397862466.035 [AHRS_sp3003D](INFO): Powering down
2014-04-18T23:07:46.036Z,1397862466.036 [DVL_micro](INFO): uninitialize:Powering down
2014-04-18T23:07:46.037Z,1397862466.037 [NAL9602](INFO): Powering down
2014-04-18T23:07:46.052Z,1397862466.052 [Radio_Freewave](INFO): Powering down
2014-04-18T23:07:46.056Z,1397862466.056 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2014-04-18T23:07:46.057Z,1397862466.057 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2014-04-18T23:07:46.058Z,1397862466.058 [Default] Stopped
2014-04-18T23:07:46.058Z,1397862466.058 [Default](INFO): Aggregate::uninitialize Default
2014-04-18T23:07:46.058Z,1397862466.058 [Default:Iridium] Stopped
2014-04-18T23:07:46.058Z,1397862466.058 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-04-18T23:07:46.058Z,1397862466.058 [Default:Iridium:A.SetSpeed] Stopped
2014-04-18T23:07:46.058Z,1397862466.058 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-04-18T23:07:46.058Z,1397862466.058 [Default:Iridium:Read_Iridium] Stopped
2014-04-18T23:07:46.059Z,1397862466.059 [Default:CallIridium] Stopped
2014-04-18T23:07:46.059Z,1397862466.059 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-04-18T23:07:46.059Z,1397862466.059 [Default:CallIridium:B] Stopped
2014-04-18T23:07:46.059Z,1397862466.059 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-04-18T23:07:46.059Z,1397862466.059 [Default:WaitAtTheSurface] Stopped
2014-04-18T23:07:46.059Z,1397862466.059 [Default:WaitAtTheSurface](INFO): Aggregate::uninitialize Default:WaitAtTheSurface
2014-04-18T23:07:46.059Z,1397862466.059 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Stopped
2014-04-18T23:07:46.060Z,1397862466.060 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Uninitialize.
2014-04-18T23:07:46.060Z,1397862466.060 [Default:WaitAtTheSurface:B.GoToSurface] Stopped
2014-04-18T23:07:46.060Z,1397862466.060 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-18T23:07:46.071Z,1397862466.071 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2014-04-18T23:07:46.071Z,1397862466.071 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2014-04-18T23:07:46.076Z,1397862466.076 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2014-04-18T23:07:46.076Z,1397862466.076 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2014-04-18T23:07:46.076Z,1397862466.076 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2014-04-18T23:07:46.077Z,1397862466.077 [BuoyancyServo](INFO): Powering down
2014-04-18T23:07:46.092Z,1397862466.092 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2014-04-18T23:07:46.092Z,1397862466.092 [ElevatorServo](INFO): Powering down
2014-04-18T23:07:46.093Z,1397862466.093 [MassServo](DEBUG): Uninitialize Mass Servo.
2014-04-18T23:07:46.093Z,1397862466.093 [MassServo](INFO): Powering down
2014-04-18T23:07:46.094Z,1397862466.094 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2014-04-18T23:07:46.094Z,1397862466.094 [RudderServo](INFO): Powering down
2014-04-18T23:07:46.096Z,1397862466.096 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2014-04-18T23:07:46.096Z,1397862466.096 [ThrusterServo](INFO): Powering down
2014-04-18T23:07:46.097Z,1397862466.097 [SBIT](DEBUG): Uninitialize SBIT Component.
2014-04-18T23:07:46.097Z,1397862466.097 [IBIT](DEBUG): Uninitialize IBIT Component.
2014-04-18T23:07:46.097Z,1397862466.097 [CBIT](DEBUG): Uninitialize CBIT Component.