2013-05-22T15:12:58.144Z,1369235578.144 [Supervisor](DEBUG): Initializing supervisor.
2013-05-22T15:12:58.148Z,1369235578.148 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0
2013-05-22T15:12:58.149Z,1369235578.149 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2013-05-22T15:12:58.153Z,1369235578.153 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0
2013-05-22T15:12:58.157Z,1369235578.157 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2013-05-22T15:12:58.167Z,1369235578.167 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2013-05-22T15:12:58.169Z,1369235578.169 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0
2013-05-22T15:12:58.170Z,1369235578.170 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2013-05-22T15:12:58.173Z,1369235578.173 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0
2013-05-22T15:12:58.174Z,1369235578.174 [Supervisor](INFO): Looking for Config files in directory: Config/
2013-05-22T15:12:58.178Z,1369235578.178 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2013-05-22T15:12:58.494Z,1369235578.494 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2013-05-22T15:12:58.495Z,1369235578.495 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2013-05-22T15:12:58.705Z,1369235578.705 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2013-05-22T15:12:58.705Z,1369235578.705 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2013-05-22T15:12:58.801Z,1369235578.801 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2013-05-22T15:12:58.803Z,1369235578.803 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2013-05-22T15:12:59.030Z,1369235579.030 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2013-05-22T15:12:59.031Z,1369235579.031 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2013-05-22T15:12:59.186Z,1369235579.186 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2013-05-22T15:12:59.188Z,1369235579.188 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2013-05-22T15:12:59.454Z,1369235579.454 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2013-05-22T15:12:59.455Z,1369235579.455 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2013-05-22T15:12:59.646Z,1369235579.646 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2013-05-22T15:12:59.648Z,1369235579.648 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2013-05-22T15:12:59.935Z,1369235579.935 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2013-05-22T15:12:59.937Z,1369235579.937 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2013-05-22T15:13:00.050Z,1369235580.050 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2013-05-22T15:13:00.051Z,1369235580.050 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2013-05-22T15:13:00.503Z,1369235580.503 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2013-05-22T15:13:00.503Z,1369235580.503 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2013-05-22T15:13:00.634Z,1369235580.634 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2013-05-22T15:13:00.635Z,1369235580.635 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2013-05-22T15:13:00.730Z,1369235580.730 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2013-05-22T15:13:00.734Z,1369235580.734 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2013-05-22T15:13:00.852Z,1369235580.852 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2013-05-22T15:13:00.999Z,1369235580.999 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2013-05-22T15:13:01.170Z,1369235581.170 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2013-05-22T15:13:01.286Z,1369235581.286 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2013-05-22T15:13:01.397Z,1369235581.397 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2013-05-22T15:13:01.531Z,1369235581.531 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2013-05-22T15:13:01.687Z,1369235581.687 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2013-05-22T15:13:01.873Z,1369235581.873 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2013-05-22T15:13:01.906Z,1369235581.906 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2013-05-22T15:13:02.109Z,1369235582.109 [InternalSim] Loaded
2013-05-22T15:13:02.109Z,1369235582.109 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2013-05-22T15:13:02.110Z,1369235582.110 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2013-05-22T15:13:02.111Z,1369235582.111 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2013-05-22T15:13:02.195Z,1369235582.195 [SBIT](DEBUG): Construct Startup Built In Test.
2013-05-22T15:13:02.228Z,1369235582.228 [SBIT] Loaded
2013-05-22T15:13:02.229Z,1369235582.229 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2013-05-22T15:13:02.234Z,1369235582.234 [IBIT](DEBUG): Construct Initiated Built In Test.
2013-05-22T15:13:02.263Z,1369235582.263 [IBIT] Loaded
2013-05-22T15:13:02.263Z,1369235582.263 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2013-05-22T15:13:02.266Z,1369235582.266 [CBIT](DEBUG): Construct CBIT Built In Test.
2013-05-22T15:13:02.396Z,1369235582.396 [CBIT] Loaded
2013-05-22T15:13:02.396Z,1369235582.396 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2013-05-22T15:13:02.397Z,1369235582.397 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2013-05-22T15:13:02.398Z,1369235582.398 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2013-05-22T15:13:02.575Z,1369235582.575 [BuoyancyServo] Loaded
2013-05-22T15:13:02.576Z,1369235582.576 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2013-05-22T15:13:02.588Z,1369235582.588 [ElevatorServo] Loaded
2013-05-22T15:13:02.588Z,1369235582.588 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2013-05-22T15:13:02.604Z,1369235582.604 [MassServo] Loaded
2013-05-22T15:13:02.604Z,1369235582.604 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2013-05-22T15:13:02.617Z,1369235582.616 [RudderServo] Loaded
2013-05-22T15:13:02.617Z,1369235582.617 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2013-05-22T15:13:02.629Z,1369235582.629 [ThrusterServo] Loaded
2013-05-22T15:13:02.629Z,1369235582.629 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2013-05-22T15:13:02.629Z,1369235582.629 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2013-05-22T15:13:02.630Z,1369235582.630 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2013-05-22T15:13:02.666Z,1369235582.666 [DepthRateCalculator] Loaded
2013-05-22T15:13:02.667Z,1369235582.667 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2013-05-22T15:13:06.007Z,1369235586.007 [HFRadarModelCalc] Loaded
2013-05-22T15:13:06.007Z,1369235586.007 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2013-05-22T15:13:06.023Z,1369235586.023 [NavChart] Loaded
2013-05-22T15:13:06.024Z,1369235586.024 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2013-05-22T15:13:06.030Z,1369235586.030 [PitchRateCalculator] Loaded
2013-05-22T15:13:06.030Z,1369235586.030 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2013-05-22T15:13:06.041Z,1369235586.041 [SpeedCalculator] Loaded
2013-05-22T15:13:06.045Z,1369235586.045 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2013-05-22T15:13:06.060Z,1369235586.060 [TempGradientCalculator] Loaded
2013-05-22T15:13:06.061Z,1369235586.061 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2013-05-22T15:13:06.067Z,1369235586.067 [YawRateCalculator] Loaded
2013-05-22T15:13:06.067Z,1369235586.067 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2013-05-22T15:13:06.118Z,1369235586.118 [Navigation] Loaded
2013-05-22T15:13:06.118Z,1369235586.118 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread.
2013-05-22T15:13:06.118Z,1369235586.118 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2013-05-22T15:13:06.119Z,1369235586.119 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2013-05-22T15:13:06.392Z,1369235586.392 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2013-05-22T15:13:06.393Z,1369235586.393 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2013-05-22T15:13:06.438Z,1369235586.438 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2013-05-22T15:13:06.439Z,1369235586.439 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2013-05-22T15:13:06.503Z,1369235586.503 [VerticalControl](DEBUG): Construct VerticalControl.
2013-05-22T15:13:06.612Z,1369235586.612 [VerticalControl] Loaded
2013-05-22T15:13:06.612Z,1369235586.612 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2013-05-22T15:13:06.613Z,1369235586.613 [HorizontalControl](DEBUG): Construct HorizontalControl.
2013-05-22T15:13:06.675Z,1369235586.675 [HorizontalControl] Loaded
2013-05-22T15:13:06.676Z,1369235586.676 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2013-05-22T15:13:06.677Z,1369235586.677 [SpeedControl](DEBUG): Construct SpeedControl.
2013-05-22T15:13:06.678Z,1369235586.678 [SpeedControl] Loaded
2013-05-22T15:13:06.679Z,1369235586.679 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2013-05-22T15:13:06.679Z,1369235586.680 [LoopControl](DEBUG): Construct LoopControl.
2013-05-22T15:13:06.680Z,1369235586.680 [LoopControl] Loaded
2013-05-22T15:13:06.680Z,1369235586.680 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2013-05-22T15:13:06.681Z,1369235586.681 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2013-05-22T15:13:06.682Z,1369235586.681 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2013-05-22T15:13:06.690Z,1369235586.690 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator.
2013-05-22T15:13:06.695Z,1369235586.695 [AsyncPiEstimator] Loaded
2013-05-22T15:13:06.696Z,1369235586.696 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread.
2013-05-22T15:13:06.697Z,1369235586.697 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 4063B4E0
2013-05-22T15:13:06.698Z,1369235586.698 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2013-05-22T15:13:06.699Z,1369235586.699 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2013-05-22T15:13:06.885Z,1369235586.885 [AHRS_sp3003D] Loaded
2013-05-22T15:13:06.885Z,1369235586.885 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2013-05-22T15:13:07.173Z,1369235587.173 [Batt_Ocean_Server] Loaded
2013-05-22T15:13:07.173Z,1369235587.173 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2013-05-22T15:13:07.191Z,1369235587.191 [Depth_Keller] Loaded
2013-05-22T15:13:07.192Z,1369235587.192 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2013-05-22T15:13:07.197Z,1369235587.197 [DropWeight] Loaded
2013-05-22T15:13:07.198Z,1369235587.197 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2013-05-22T15:13:07.390Z,1369235587.390 [DVL_micro] Loaded
2013-05-22T15:13:07.390Z,1369235587.390 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread.
2013-05-22T15:13:07.393Z,1369235587.393 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 406B64E0
2013-05-22T15:13:07.485Z,1369235587.485 [NAL9602] Loaded
2013-05-22T15:13:07.485Z,1369235587.485 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2013-05-22T15:13:07.540Z,1369235587.540 [Onboard] Loaded
2013-05-22T15:13:07.541Z,1369235587.541 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2013-05-22T15:13:07.552Z,1369235587.552 [Radio_Freewave] Loaded
2013-05-22T15:13:07.552Z,1369235587.552 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread.
2013-05-22T15:13:07.728Z,1369235587.727 [DAT] Loaded
2013-05-22T15:13:07.728Z,1369235587.728 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2013-05-22T15:13:07.728Z,1369235587.728 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2013-05-22T15:13:07.729Z,1369235587.729 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2013-05-22T15:13:07.835Z,1369235587.835 [CTD_NeilBrown] Loaded
2013-05-22T15:13:07.835Z,1369235587.835 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2013-05-22T15:13:07.837Z,1369235587.837 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 407084E0
2013-05-22T15:13:07.873Z,1369235587.873 [WetLabsBB2FL] Loaded
2013-05-22T15:13:07.873Z,1369235587.873 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2013-05-22T15:13:07.877Z,1369235587.877 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407384E0
2013-05-22T15:13:07.878Z,1369235587.878 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2013-05-22T15:13:07.880Z,1369235587.880 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2013-05-22T15:13:07.881Z,1369235587.881 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2013-05-22T15:13:07.892Z,1369235587.892 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2013-05-22T15:13:07.893Z,1369235587.893 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 407684E0
2013-05-22T15:13:07.897Z,1369235587.897 [Supervisor](DEBUG): Running supervisor.
2013-05-22T15:13:07.899Z,1369235587.898 [CommandLine](INFO): Thread ID is 747
2013-05-22T15:13:07.902Z,1369235587.902 [controlThread](INFO): Thread ID is 746
2013-05-22T15:13:07.902Z,1369235587.902 [controlThread](DEBUG): Initializing ControlThread
2013-05-22T15:13:07.903Z,1369235587.903 [CycleStarter](INFO): Thread ID is 745
2013-05-22T15:13:07.903Z,1369235587.903 [InternalSim](DEBUG):  InternalSim initializing...
2013-05-22T15:13:08.010Z,1369235588.010 [logger](INFO): Thread ID is 748
2013-05-22T15:13:08.102Z,1369235588.102 [AsyncPiEstimator](INFO): Thread ID is 809
2013-05-22T15:13:08.103Z,1369235588.103 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator.
2013-05-22T15:13:08.206Z,1369235588.207 [DVL_micro](INFO): Thread ID is 810
2013-05-22T15:13:08.226Z,1369235588.226 [DVL_micro](INFO): Initializing
2013-05-22T15:13:08.226Z,1369235588.226 [DVL_micro](INFO): start:Powering up
2013-05-22T15:13:08.227Z,1369235588.227 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-05-22T15:13:08.228Z,1369235588.228 [DVL_micro](INFO): Cycling power to configure device.
2013-05-22T15:13:08.238Z,1369235588.238 [CTD_NeilBrown](INFO): Thread ID is 811
2013-05-22T15:13:08.239Z,1369235588.239 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2013-05-22T15:13:08.242Z,1369235588.242 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2013-05-22T15:13:08.266Z,1369235588.266 [WetLabsBB2FL](INFO): Thread ID is 812
2013-05-22T15:13:08.267Z,1369235588.267 [WetLabsBB2FL](INFO): Powering down
2013-05-22T15:13:08.328Z,1369235588.328 [SBIT](INFO): Initialize SBIT Component.
2013-05-22T15:13:08.329Z,1369235588.329 [SBIT](IMPORTANT): Tethys CM Info:
$Rev:10376
2013-05-22T15:13:08.329Z,1369235588.329 [SBIT](IMPORTANT): Kernel Release:2.6.27.8
2013-05-22T15:13:08.330Z,1369235588.330 [NavChartDb](INFO): Thread ID is 813
2013-05-22T15:13:08.331Z,1369235588.331 [SBIT](IMPORTANT): Kernel Version:#634 PREEMPT Wed Feb 13 10:21:48 PST 2013
2013-05-22T15:13:08.331Z,1369235588.332 [IBIT](INFO): Initialize IBIT Component.
2013-05-22T15:13:08.349Z,1369235588.349 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2013-05-22T15:13:08.350Z,1369235588.350 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2013-05-22T15:13:08.350Z,1369235588.350 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2013-05-22T15:13:08.350Z,1369235588.350 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2013-05-22T15:13:08.350Z,1369235588.351 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2013-05-22T15:13:08.351Z,1369235588.351 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2013-05-22T15:13:08.351Z,1369235588.351 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2013-05-22T15:13:08.351Z,1369235588.351 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2013-05-22T15:13:08.351Z,1369235588.351 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2013-05-22T15:13:08.354Z,1369235588.354 [CBIT](DEBUG): Initialize CBIT Component.
2013-05-22T15:13:08.354Z,1369235588.354 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2013-05-22T15:13:08.355Z,1369235588.355 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2013-05-22T15:13:08.387Z,1369235588.386 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2013-05-22T15:13:08.387Z,1369235588.387 [NavChart](DEBUG): Initialize NavChart Derivation.
2013-05-22T15:13:08.387Z,1369235588.388 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2013-05-22T15:13:08.388Z,1369235588.388 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2013-05-22T15:13:08.388Z,1369235588.388 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2013-05-22T15:13:08.394Z,1369235588.394 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2013-05-22T15:13:08.394Z,1369235588.394 [Navigation](DEBUG): Initializing Navigation.
2013-05-22T15:13:08.394Z,1369235588.394 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2013-05-22T15:13:08.396Z,1369235588.396 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2013-05-22T15:13:08.397Z,1369235588.397 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2013-05-22T15:13:08.410Z,1369235588.410 [LoopControl](DEBUG): Initialize LoopControlComponent.
2013-05-22T15:13:10.342Z,1369235590.342 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-05-22T15:13:10.342Z,1369235590.342 [DVL_micro](INFO): Querying output modes
2013-05-22T15:13:10.343Z,1369235590.342 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-05-22T15:13:10.353Z,1369235590.353 [DVL_micro](DEBUG): cmdResponse: 01
2013-05-22T15:13:10.354Z,1369235590.354 [DVL_micro](INFO): NQ1 output enabled
2013-05-22T15:13:10.354Z,1369235590.354 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-05-22T15:13:10.366Z,1369235590.366 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 
2013-05-22T15:13:10.371Z,1369235590.371 [DVL_micro](INFO): pause:Powering down
2013-05-22T15:13:10.396Z,1369235590.396 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2013-05-22T15:13:10.428Z,1369235590.428 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2013-05-22T15:13:10.484Z,1369235590.484 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2013-05-22T15:13:10.498Z,1369235590.498 [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 RunIn="Progression"/>

    <Aggregate Id="StartupSatComms" >

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

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

    </Aggregate>

</Mission>


2013-05-22T15:13:10.499Z,1369235590.499 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2013-05-22T15:13:10.591Z,1369235590.591 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2013-05-22T15:13:10.593Z,1369235590.593 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2013-05-22T15:13:10.596Z,1369235590.596 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-05-22T15:13:10.616Z,1369235590.616 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2013-05-22T15:13:10.619Z,1369235590.619 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-05-22T15:13:10.662Z,1369235590.662 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2013-05-22T15:13:10.686Z,1369235590.686 [Default:D.SetSpeed](DEBUG): Construct.
2013-05-22T15:13:10.697Z,1369235590.697 [Default:E.GoToSurface](DEBUG): Construct GoToSurface.
2013-05-22T15:13:10.702Z,1369235590.702 [Default:F.Wait](DEBUG): Construct Wait.
2013-05-22T15:13:10.714Z,1369235590.714 [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 RunIn="Parallel">
            <Setting><Guidance:SetSpeed.period/><Units:millisecond/><Value>400</Value></Setting>
        </Guidance:SetSpeed>

<!-- Get to the surface -->

        <Guidance:GoToSurface RunIn="Sequence"/>

<!-- Get GPS fix -->

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

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

    </Aggregate>

    <Aggregate Id="Iridium" >

<!-- Run at high speed -->

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

<!-- Get to the surface -->

        <Guidance:GoToSurface RunIn="Sequence"/>

<!-- Do data comms -->

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P2H">
                <Guidance:Execute RunIn="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><Arg Name="NeedGPS"/><True/></Assign>

        <Call RefId="Iridium"/>

    </Aggregate>

<!-- Wait forever at the surface-->

<!-- Run at low speed -->

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

    <Guidance:GoToSurface RunIn="Parallel"/>

    <Guidance:Wait RunIn="Sequence"></Guidance:Wait>

</Mission>


2013-05-22T15:13:10.719Z,1369235590.719 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,NAL9602,Onboard,Radio_Freewave,DAT,Depth_Keller,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,
2013-05-22T15:13:10.776Z,1369235590.776 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-05-22T15:13:11.006Z,1369235591.006 [Radio_Freewave](INFO): Powering up
2013-05-22T15:13:11.015Z,1369235591.015 [DAT](INFO): Powering up
2013-05-22T15:13:11.015Z,1369235591.015 [DAT](DEBUG): Initializing DAT.
2013-05-22T15:13:11.226Z,1369235591.226 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2013-05-22T15:13:11.250Z,1369235591.250 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2013-05-22T15:13:11.256Z,1369235591.256 [ElevatorServo](DEBUG): Initializing EZServoServo.
2013-05-22T15:13:11.262Z,1369235591.262 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2013-05-22T15:13:11.287Z,1369235591.287 [MassServo](DEBUG): Initializing EZServoServo.
2013-05-22T15:13:11.294Z,1369235591.294 [MassServo](DEBUG): Initializing MassServo.
2013-05-22T15:13:11.299Z,1369235591.299 [RudderServo](DEBUG): Initializing EZServoServo.
2013-05-22T15:13:11.306Z,1369235591.306 [RudderServo](DEBUG): Initializing RudderServo.
2013-05-22T15:13:11.315Z,1369235591.315 [ThrusterServo](DEBUG): Initializing EZServoServo.
2013-05-22T15:13:11.322Z,1369235591.322 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2013-05-22T15:13:12.576Z,1369235592.576 [NAL9602](INFO): Powering up NAL9602
2013-05-22T15:13:23.330Z,1369235603.330 [NAL9602](INFO): NAL9602 initialized
2013-05-22T15:13:23.720Z,1369235603.720 [SBIT](IMPORTANT): Beginning Startup BIT
2013-05-22T15:13:23.727Z,1369235603.727 [CBIT](IMPORTANT): Beginning GF scan
2013-05-22T15:13:31.202Z,1369235611.202 [DAT](INFO): Powering down
2013-05-22T15:13:50.432Z,1369235630.432 [CBIT](FAULT): Chan 4 High side GF detected
mA:
CHAN 5 (24V): 0.036730
CHAN 4 (Batt): 0.013583
CHAN 2 (12V): 0.005165
CHAN 1 (5V): 0.000670
CHAN 0 (3.3V): 0.000765
OPEN: 0.000574
Full Scale Calc: 0.392
2013-05-22T15:14:16.950Z,1369235656.950 [SBIT](IMPORTANT): SBIT PASSED
2013-05-22T15:14:17.344Z,1369235657.344 [MissionManager](IMPORTANT): Started mission Startup
2013-05-22T15:14:17.344Z,1369235657.344 [Startup] Running Loop=1
2013-05-22T15:14:17.344Z,1369235657.344 [Startup](INFO): Aggregate::initialize Startup
2013-05-22T15:14:17.344Z,1369235657.344 [Startup:A.GoToSurface] Running Loop=1
2013-05-22T15:14:17.344Z,1369235657.344 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-22T15:14:17.350Z,1369235657.350 [Startup:StartupSatComms] Running Loop=1
2013-05-22T15:14:17.350Z,1369235657.350 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2013-05-22T15:14:17.350Z,1369235657.351 [Startup:StartupSatComms:A] Running Loop=1
2013-05-22T15:14:17.744Z,1369235657.744 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2013-05-22T15:14:37.186Z,1369235677.186 [CommandLine](IMPORTANT): got command failComponent
2013-05-22T15:14:37.186Z,1369235677.186 [CommandLine](IMPORTANT): Failed components:
2013-05-22T15:14:37.186Z,1369235677.186 [CommandLine](IMPORTANT): No failed Components.
2013-05-22T15:14:52.038Z,1369235692.038 [CommandLine](IMPORTANT): got command ibit
2013-05-22T15:14:52.217Z,1369235692.217 [IBIT](IMPORTANT): Beginning Initiated BIT
2013-05-22T15:14:52.217Z,1369235692.217 [IBIT](IMPORTANT): Beginning control surface checks.

2013-05-22T15:14:52.219Z,1369235692.219 [CBIT](IMPORTANT): Beginning GF scan
2013-05-22T15:14:52.928Z,1369235692.928 [Radio_Freewave](INFO): Powering down
2013-05-22T15:14:53.728Z,1369235693.728 [Radio_Freewave](INFO): Powering up
2013-05-22T15:15:18.656Z,1369235718.656 [CBIT](FAULT): Chan 4 High side GF detected
mA:
CHAN 5 (24V): 0.031852
CHAN 4 (Batt): 0.011478
CHAN 2 (12V): 0.003826
CHAN 1 (5V): 0.000574
CHAN 0 (3.3V): 0.000765
OPEN: 0.014826
Full Scale Calc: 0.392
2013-05-22T15:15:18.987Z,1369235718.987 [NAL9602](IMPORTANT): GPS fix at: 1369235715.00
2013-05-22T15:15:22.226Z,1369235722.226 [NAL9602](IMPORTANT): GPS fix at: 1369235718.00
2013-05-22T15:15:24.982Z,1369235724.982 [NAL9602](IMPORTANT): GPS fix at: 1369235721.00
2013-05-22T15:15:28.310Z,1369235728.310 [NAL9602](IMPORTANT): GPS fix at: 1369235724.00
2013-05-22T15:15:31.112Z,1369235731.112 [NAL9602](IMPORTANT): GPS fix at: 1369235727.00
2013-05-22T15:15:33.910Z,1369235733.909 [NAL9602](IMPORTANT): GPS fix at: 1369235730.00
2013-05-22T15:15:37.112Z,1369235737.112 [NAL9602](IMPORTANT): GPS fix at: 1369235733.00
2013-05-22T15:15:39.910Z,1369235739.910 [NAL9602](IMPORTANT): GPS fix at: 1369235736.00
2013-05-22T15:15:43.112Z,1369235743.112 [NAL9602](IMPORTANT): GPS fix at: 1369235739.00
2013-05-22T15:15:45.910Z,1369235745.909 [NAL9602](IMPORTANT): GPS fix at: 1369235742.00
2013-05-22T15:15:49.112Z,1369235749.112 [NAL9602](IMPORTANT): GPS fix at: 1369235745.00
2013-05-22T15:15:51.910Z,1369235751.909 [NAL9602](IMPORTANT): GPS fix at: 1369235748.00
2013-05-22T15:15:55.112Z,1369235755.112 [NAL9602](IMPORTANT): GPS fix at: 1369235751.00
2013-05-22T15:15:57.995Z,1369235757.995 [NAL9602](IMPORTANT): GPS fix at: 1369235754.00
2013-05-22T15:16:01.113Z,1369235761.113 [NAL9602](IMPORTANT): GPS fix at: 1369235757.00
2013-05-22T15:16:03.910Z,1369235763.910 [NAL9602](IMPORTANT): GPS fix at: 1369235760.00
2013-05-22T15:16:07.112Z,1369235767.112 [NAL9602](IMPORTANT): GPS fix at: 1369235763.00
2013-05-22T15:16:09.910Z,1369235769.910 [NAL9602](IMPORTANT): GPS fix at: 1369235766.00
2013-05-22T15:16:13.163Z,1369235773.163 [NAL9602](IMPORTANT): GPS fix at: 1369235769.00
2013-05-22T15:16:15.910Z,1369235775.910 [NAL9602](IMPORTANT): GPS fix at: 1369235772.00
2013-05-22T15:16:19.112Z,1369235779.112 [NAL9602](IMPORTANT): GPS fix at: 1369235775.00
2013-05-22T15:16:21.904Z,1369235781.904 [NAL9602](IMPORTANT): GPS fix at: 1369235778.00
2013-05-22T15:16:25.112Z,1369235785.112 [NAL9602](IMPORTANT): GPS fix at: 1369235781.00
2013-05-22T15:16:27.946Z,1369235787.946 [NAL9602](IMPORTANT): GPS fix at: 1369235784.00
2013-05-22T15:16:31.144Z,1369235791.144 [NAL9602](IMPORTANT): GPS fix at: 1369235787.00
2013-05-22T15:16:33.958Z,1369235793.958 [NAL9602](IMPORTANT): GPS fix at: 1369235790.00
2013-05-22T15:16:37.112Z,1369235797.112 [NAL9602](IMPORTANT): GPS fix at: 1369235793.00
2013-05-22T15:16:39.910Z,1369235799.909 [NAL9602](IMPORTANT): GPS fix at: 1369235796.00
2013-05-22T15:16:43.112Z,1369235803.112 [NAL9602](IMPORTANT): GPS fix at: 1369235799.00
2013-05-22T15:16:43.150Z,1369235803.150 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired.
2013-05-22T15:16:43.554Z,1369235803.554 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 238.649994
Voltage: 16.280750
2013-05-22T15:16:43.554Z,1369235803.555 [IBIT](IMPORTANT): batteryCapacityThreshold: 5.000000 Ah
2013-05-22T15:16:43.555Z,1369235803.555 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.500000 V
2013-05-22T15:16:43.977Z,1369235803.977 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2013-05-22T15:16:43.978Z,1369235803.978 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2013-05-22T15:16:43.978Z,1369235803.978 [IBIT](IMPORTANT): Pressure:18.168247 PSI
2013-05-22T15:16:43.978Z,1369235803.978 [IBIT](IMPORTANT): Humidity:26.332771 %
2013-05-22T15:16:44.364Z,1369235804.364 [IBIT](IMPORTANT): surfaceThreshold: 0.500000 m
2013-05-22T15:16:44.365Z,1369235804.365 [IBIT](IMPORTANT): buoyancyNeutral: 450.000000 cc
2013-05-22T15:16:44.365Z,1369235804.365 [IBIT](IMPORTANT): massDefault: 0.000000 cm
2013-05-22T15:16:44.366Z,1369235804.366 [IBIT](IMPORTANT): stopDepth: 60.000000 m
2013-05-22T15:16:44.366Z,1369235804.366 [IBIT](IMPORTANT): abortDepth: 70.000000 m
2013-05-22T15:16:44.366Z,1369235804.366 [IBIT](IMPORTANT): IBIT FAILED
2013-05-22T15:16:44.724Z,1369235804.724 [Startup:StartupSatComms:A](INFO): Timed out from 2013-05-22T15:14:17.4Z
2013-05-22T15:16:44.724Z,1369235804.724 [Startup:StartupSatComms:A:A_Timeout] Running Loop=1
2013-05-22T15:16:44.724Z,1369235804.724 [Startup:StartupSatComms:A:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:A:A_Timeout
2013-05-22T15:16:44.724Z,1369235804.724 [Startup:StartupSatComms:A:A_Timeout](INFO): Completed Startup:StartupSatComms:A:A_Timeout
2013-05-22T15:16:44.725Z,1369235804.724 [Startup:StartupSatComms:A] Stopped
2013-05-22T15:16:44.725Z,1369235804.725 [Startup:StartupSatComms:B] Running Loop=1
2013-05-22T15:16:45.124Z,1369235805.124 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2013-05-22T15:17:09.345Z,1369235829.345 [NAL9602](INFO): SBD MO Status=2, MOMSN=12246, MT Status=2, MTMSN=0
2013-05-22T15:17:09.346Z,1369235829.346 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:17:24.992Z,1369235844.992 [NAL9602](INFO): SBD MO Status=2, MOMSN=12246, MT Status=2, MTMSN=0
2013-05-22T15:17:24.992Z,1369235844.992 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:17:39.148Z,1369235859.148 [NAL9602](INFO): SBD MO Status=2, MOMSN=12246, MT Status=2, MTMSN=0
2013-05-22T15:17:39.148Z,1369235859.148 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:17:44.855Z,1369235864.855 [Startup:StartupSatComms:B](INFO): Timed out from 2013-05-22T15:16:44.7Z
2013-05-22T15:17:44.855Z,1369235864.855 [Startup:StartupSatComms:B:A_Timeout] Running Loop=1
2013-05-22T15:17:44.855Z,1369235864.855 [Startup:StartupSatComms:B:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:B:A_Timeout
2013-05-22T15:17:44.855Z,1369235864.855 [Startup:StartupSatComms:B:A_Timeout](INFO): Completed Startup:StartupSatComms:B:A_Timeout
2013-05-22T15:17:44.855Z,1369235864.855 [Startup:StartupSatComms:B] Stopped
2013-05-22T15:17:44.855Z,1369235864.855 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2013-05-22T15:17:44.856Z,1369235864.856 [Startup:StartupSatComms] Stopped
2013-05-22T15:17:44.856Z,1369235864.856 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2013-05-22T15:17:44.857Z,1369235864.857 [Startup](INFO): Completed Startup
2013-05-22T15:17:44.857Z,1369235864.857 [Startup] Stopped
2013-05-22T15:17:44.857Z,1369235864.857 [Startup](INFO): Aggregate::uninitialize Startup
2013-05-22T15:17:44.857Z,1369235864.857 [Startup:A.GoToSurface] Stopped
2013-05-22T15:17:44.857Z,1369235864.857 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-05-22T15:17:47.206Z,1369235867.206 [MissionManager](IMPORTANT): Started mission Default
2013-05-22T15:17:47.206Z,1369235867.206 [Default] Running Loop=1
2013-05-22T15:17:47.206Z,1369235867.206 [Default](INFO): Aggregate::initialize Default
2013-05-22T15:17:47.206Z,1369235867.206 [Default:D.SetSpeed] Running Loop=1
2013-05-22T15:17:47.206Z,1369235867.206 [Default:D.SetSpeed](DEBUG): Initialize.
2013-05-22T15:17:47.206Z,1369235867.206 [Default:E.GoToSurface] Running Loop=1
2013-05-22T15:17:47.206Z,1369235867.206 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-22T15:17:47.206Z,1369235867.207 [Default:Iridium] Running Loop=1
2013-05-22T15:17:47.207Z,1369235867.207 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-05-22T15:17:47.207Z,1369235867.207 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-05-22T15:17:47.207Z,1369235867.207 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-05-22T15:17:47.207Z,1369235867.207 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-05-22T15:17:47.207Z,1369235867.207 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-22T15:17:47.208Z,1369235867.208 [Default:E.GoToSurface] Running Loop=1
2013-05-22T15:17:47.213Z,1369235867.213 [Default:D.SetSpeed] Running Loop=1
2013-05-22T15:17:47.219Z,1369235867.219 [Default:CallIridium] Running Loop=1
2013-05-22T15:17:47.219Z,1369235867.219 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-05-22T15:17:47.219Z,1369235867.219 [Default:CallIridium:A] Running Loop=1
2013-05-22T15:17:47.221Z,1369235867.221 [Default:CallIridium:A] Stopped
2013-05-22T15:17:47.221Z,1369235867.221 [Default:CallIridium:B] Running Loop=1
2013-05-22T15:17:47.221Z,1369235867.221 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-05-22T15:17:47.227Z,1369235867.227 [Default:Iridium:B.GoToSurface] Stopped
2013-05-22T15:17:47.227Z,1369235867.227 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-05-22T15:17:47.227Z,1369235867.227 [Default:Iridium:Read_Iridium] Running Loop=1
2013-05-22T15:17:47.227Z,1369235867.227 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-05-22T15:17:47.232Z,1369235867.232 [Default:GPS] Running Loop=1
2013-05-22T15:17:47.232Z,1369235867.232 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-05-22T15:17:47.232Z,1369235867.232 [Default:GPS:A.SetSpeed] Running Loop=1
2013-05-22T15:17:47.232Z,1369235867.232 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-05-22T15:17:47.233Z,1369235867.233 [Default:GPS:B.GoToSurface] Running Loop=1
2013-05-22T15:17:47.233Z,1369235867.233 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-22T15:17:47.263Z,1369235867.263 [Default:GPS:B.GoToSurface] Stopped
2013-05-22T15:17:47.263Z,1369235867.263 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-05-22T15:17:47.263Z,1369235867.263 [Default:GPS:Read_GPS] Running Loop=1
2013-05-22T15:17:47.263Z,1369235867.263 [Default:GPS:A.SetSpeed] Running Loop=1
2013-05-22T15:17:47.587Z,1369235867.587 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2013-05-22T15:17:47.590Z,1369235867.590 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2013-05-22T15:17:54.284Z,1369235874.284 [NAL9602](INFO): SBD MO Status=2, MOMSN=12246, MT Status=2, MTMSN=0
2013-05-22T15:17:54.284Z,1369235874.284 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:17:55.481Z,1369235875.481 [NAL9602](IMPORTANT): GPS fix at: 1369235871.00
2013-05-22T15:17:55.498Z,1369235875.498 [Default:GPS:Read_GPS] Stopped
2013-05-22T15:17:55.498Z,1369235875.498 [Default:GPS:D] Running Loop=1
2013-05-22T15:17:55.920Z,1369235875.920 [Default:GPS:D] Stopped
2013-05-22T15:17:55.920Z,1369235875.920 [Default:GPS](INFO): Completed Default:GPS
2013-05-22T15:17:55.920Z,1369235875.920 [Default:GPS] Stopped
2013-05-22T15:17:55.920Z,1369235875.921 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-05-22T15:17:55.921Z,1369235875.921 [Default:GPS:A.SetSpeed] Stopped
2013-05-22T15:17:55.921Z,1369235875.921 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-05-22T15:18:20.538Z,1369235900.538 [NAL9602](INFO): SBD MO Status=2, MOMSN=12246, MT Status=2, MTMSN=0
2013-05-22T15:18:20.539Z,1369235900.539 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:18:44.027Z,1369235924.027 [NAL9602](INFO): SBD MO Status=2, MOMSN=12246, MT Status=2, MTMSN=0
2013-05-22T15:18:44.027Z,1369235924.027 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:19:13.356Z,1369235953.356 [NAL9602](INFO): SBD MO Status=2, MOMSN=12246, MT Status=2, MTMSN=0
2013-05-22T15:19:13.356Z,1369235953.356 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:19:35.557Z,1369235975.556 [NAL9602](INFO): SBD MO Status=2, MOMSN=12246, MT Status=2, MTMSN=0
2013-05-22T15:19:35.557Z,1369235975.557 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:19:56.888Z,1369235996.888 [NAL9602](INFO): SBD MO Status=2, MOMSN=12246, MT Status=2, MTMSN=0
2013-05-22T15:19:56.889Z,1369235996.889 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:20:18.704Z,1369236018.704 [NAL9602](INFO): SBD MO Status=2, MOMSN=12246, MT Status=2, MTMSN=0
2013-05-22T15:20:18.704Z,1369236018.704 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:20:35.376Z,1369236035.376 [NAL9602](INFO): SBD MO Status=2, MOMSN=12246, MT Status=2, MTMSN=0
2013-05-22T15:20:35.376Z,1369236035.376 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:20:43.972Z,1369236043.972 [NAL9602](INFO): SBD MO Status=2, MOMSN=12246, MT Status=2, MTMSN=0
2013-05-22T15:20:43.972Z,1369236043.972 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:20:52.993Z,1369236052.993 [NAL9602](INFO): SBD MO Status=2, MOMSN=12246, MT Status=2, MTMSN=0
2013-05-22T15:20:52.993Z,1369236052.993 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:21:01.200Z,1369236061.200 [NAL9602](INFO): SBD MO Status=2, MOMSN=12246, MT Status=2, MTMSN=0
2013-05-22T15:21:01.200Z,1369236061.200 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:21:10.172Z,1369236070.172 [NAL9602](INFO): SBD MO Status=2, MOMSN=12246, MT Status=2, MTMSN=0
2013-05-22T15:21:10.172Z,1369236070.172 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:21:18.448Z,1369236078.448 [NAL9602](INFO): SBD MO Status=2, MOMSN=12246, MT Status=2, MTMSN=0
2013-05-22T15:21:18.448Z,1369236078.448 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:21:27.280Z,1369236087.280 [NAL9602](INFO): SBD MO Status=2, MOMSN=12246, MT Status=2, MTMSN=0
2013-05-22T15:21:27.280Z,1369236087.280 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:21:36.284Z,1369236096.284 [NAL9602](INFO): SBD MO Status=2, MOMSN=12246, MT Status=2, MTMSN=0
2013-05-22T15:21:36.285Z,1369236096.284 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:21:53.252Z,1369236113.252 [NAL9602](INFO): SBD MO Status=2, MOMSN=12246, MT Status=2, MTMSN=0
2013-05-22T15:21:53.252Z,1369236113.252 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:22:18.956Z,1369236138.956 [NAL9602](INFO): SBD MO Status=2, MOMSN=12246, MT Status=2, MTMSN=0
2013-05-22T15:22:18.956Z,1369236138.956 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:22:27.947Z,1369236147.947 [NAL9602](INFO): SBD MO Status=2, MOMSN=12246, MT Status=2, MTMSN=0
2013-05-22T15:22:27.947Z,1369236147.947 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:22:36.585Z,1369236156.585 [NAL9602](INFO): SBD MO Status=2, MOMSN=12246, MT Status=2, MTMSN=0
2013-05-22T15:22:36.585Z,1369236156.585 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:23:00.684Z,1369236180.684 [NAL9602](INFO): SBD MO Status=2, MOMSN=12246, MT Status=2, MTMSN=0
2013-05-22T15:23:00.684Z,1369236180.684 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:23:24.020Z,1369236204.020 [NAL9602](INFO): SBD MO Status=2, MOMSN=12246, MT Status=2, MTMSN=0
2013-05-22T15:23:24.020Z,1369236204.020 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:23:38.584Z,1369236218.584 [NAL9602](INFO): SBD MO Status=2, MOMSN=12246, MT Status=2, MTMSN=0
2013-05-22T15:23:38.584Z,1369236218.584 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:23:47.264Z,1369236227.264 [NAL9602](INFO): SBD MO Status=2, MOMSN=12246, MT Status=2, MTMSN=0
2013-05-22T15:23:47.264Z,1369236227.264 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:24:13.240Z,1369236253.240 [NAL9602](INFO): SBD MO Status=2, MOMSN=12246, MT Status=2, MTMSN=0
2013-05-22T15:24:13.240Z,1369236253.240 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:24:30.343Z,1369236270.342 [NAL9602](INFO): SBD MO Status=2, MOMSN=12246, MT Status=2, MTMSN=0
2013-05-22T15:24:30.343Z,1369236270.343 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:24:38.996Z,1369236278.996 [NAL9602](INFO): SBD MO Status=2, MOMSN=12246, MT Status=2, MTMSN=0
2013-05-22T15:24:38.996Z,1369236278.996 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:24:48.084Z,1369236288.084 [NAL9602](INFO): SBD MO Status=2, MOMSN=12246, MT Status=2, MTMSN=0
2013-05-22T15:24:48.084Z,1369236288.084 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:25:05.404Z,1369236305.404 [NAL9602](INFO): SBD MO Status=2, MOMSN=12246, MT Status=2, MTMSN=0
2013-05-22T15:25:05.404Z,1369236305.404 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:25:19.192Z,1369236319.192 [NAL9602](INFO): SBD MO Status=2, MOMSN=12246, MT Status=2, MTMSN=0
2013-05-22T15:25:19.192Z,1369236319.192 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:25:27.839Z,1369236327.839 [NAL9602](INFO): SBD MO Status=2, MOMSN=12246, MT Status=2, MTMSN=0
2013-05-22T15:25:27.839Z,1369236327.839 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:25:45.656Z,1369236345.656 [NAL9602](INFO): SBD MO Status=2, MOMSN=12246, MT Status=2, MTMSN=0
2013-05-22T15:25:45.656Z,1369236345.656 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:26:07.148Z,1369236367.148 [NAL9602](INFO): SBD MO Status=1, MOMSN=12246, MT Status=0, MTMSN=0
2013-05-22T15:26:07.198Z,1369236367.198 [NAL9602](INFO): Sent 332 bytes from file Logs/20130522T011141/shore0000.lzma
2013-05-22T15:26:07.198Z,1369236367.198 [NAL9602](INFO): Packets left to send: 1
2013-05-22T15:26:07.200Z,1369236367.200 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T011141/shore0000.lzma.parts/0001.sbd
2013-05-22T15:26:13.092Z,1369236373.092 [NAL9602](INFO): SBD MO Status=2, MOMSN=12247, MT Status=2, MTMSN=0
2013-05-22T15:26:13.093Z,1369236373.092 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:26:26.080Z,1369236386.080 [NAL9602](INFO): SBD MO Status=1, MOMSN=12247, MT Status=0, MTMSN=0
2013-05-22T15:26:26.130Z,1369236386.130 [NAL9602](INFO): Sent 312 bytes from file Logs/20130522T011141/shore0000.lzma
2013-05-22T15:26:26.130Z,1369236386.130 [NAL9602](INFO): Packets left to send: 0
2013-05-22T15:26:26.132Z,1369236386.132 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T011141/shore0000.lzma.parts/0000.sbd
2013-05-22T15:26:29.973Z,1369236389.973 [NAL9602](INFO): SBD MO Status=2, MOMSN=12248, MT Status=2, MTMSN=0
2013-05-22T15:26:29.973Z,1369236389.973 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:27:06.892Z,1369236426.892 [NAL9602](INFO): SBD MO Status=2, MOMSN=12248, MT Status=0, MTMSN=0
2013-05-22T15:27:06.892Z,1369236426.892 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:27:15.984Z,1369236435.984 [NAL9602](INFO): SBD MO Status=2, MOMSN=12248, MT Status=2, MTMSN=0
2013-05-22T15:27:15.985Z,1369236435.985 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:27:24.548Z,1369236444.548 [NAL9602](INFO): SBD MO Status=2, MOMSN=12248, MT Status=2, MTMSN=0
2013-05-22T15:27:24.548Z,1369236444.548 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:27:45.679Z,1369236465.679 [NAL9602](INFO): SBD MO Status=1, MOMSN=12248, MT Status=0, MTMSN=0
2013-05-22T15:27:45.730Z,1369236465.730 [NAL9602](INFO): Sent 268 bytes from file Logs/20130522T011141/shore0001.lzma
2013-05-22T15:27:45.730Z,1369236465.730 [NAL9602](INFO): Packets left to send: 0
2013-05-22T15:27:45.731Z,1369236465.731 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T011141/shore0001.lzma.parts/0000.sbd
2013-05-22T15:27:54.425Z,1369236474.425 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#5 STATUS: 65535
2013-05-22T15:27:58.396Z,1369236478.396 [NAL9602](INFO): SBD MO Status=1, MOMSN=12249, MT Status=0, MTMSN=0
2013-05-22T15:27:58.454Z,1369236478.454 [NAL9602](INFO): Sent 332 bytes from file Logs/20130522T011816/shore0000.lzma
2013-05-22T15:27:58.454Z,1369236478.454 [NAL9602](INFO): Packets left to send: 1
2013-05-22T15:27:58.455Z,1369236478.455 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T011816/shore0000.lzma.parts/0001.sbd
2013-05-22T15:28:09.872Z,1369236489.872 [NAL9602](INFO): SBD MO Status=1, MOMSN=12250, MT Status=0, MTMSN=0
2013-05-22T15:28:09.922Z,1369236489.922 [NAL9602](INFO): Sent 94 bytes from file Logs/20130522T011816/shore0000.lzma
2013-05-22T15:28:09.922Z,1369236489.922 [NAL9602](INFO): Packets left to send: 0
2013-05-22T15:28:09.923Z,1369236489.923 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T011816/shore0000.lzma.parts/0000.sbd
2013-05-22T15:28:21.339Z,1369236501.339 [NAL9602](INFO): SBD MO Status=1, MOMSN=12251, MT Status=0, MTMSN=0
2013-05-22T15:28:21.386Z,1369236501.386 [NAL9602](INFO): Sent 332 bytes from file Logs/20130522T012026/shore0000.lzma
2013-05-22T15:28:21.386Z,1369236501.386 [NAL9602](INFO): Packets left to send: 1
2013-05-22T15:28:21.387Z,1369236501.388 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T012026/shore0000.lzma.parts/0001.sbd
2013-05-22T15:28:27.572Z,1369236507.572 [NAL9602](INFO): SBD MO Status=1, MOMSN=12252, MT Status=0, MTMSN=0
2013-05-22T15:28:27.622Z,1369236507.622 [NAL9602](INFO): Sent 157 bytes from file Logs/20130522T012026/shore0000.lzma
2013-05-22T15:28:27.622Z,1369236507.622 [NAL9602](INFO): Packets left to send: 0
2013-05-22T15:28:27.623Z,1369236507.623 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T012026/shore0000.lzma.parts/0000.sbd
2013-05-22T15:28:35.820Z,1369236515.820 [NAL9602](INFO): SBD MO Status=1, MOMSN=12253, MT Status=0, MTMSN=0
2013-05-22T15:28:35.878Z,1369236515.878 [NAL9602](INFO): Sent 332 bytes from file Logs/20130522T012249/shore0000.lzma
2013-05-22T15:28:35.878Z,1369236515.878 [NAL9602](INFO): Packets left to send: 1
2013-05-22T15:28:35.879Z,1369236515.879 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T012249/shore0000.lzma.parts/0001.sbd
2013-05-22T15:28:42.464Z,1369236522.464 [NAL9602](INFO): SBD MO Status=1, MOMSN=12254, MT Status=0, MTMSN=0
2013-05-22T15:28:42.514Z,1369236522.514 [NAL9602](INFO): Sent 181 bytes from file Logs/20130522T012249/shore0000.lzma
2013-05-22T15:28:42.514Z,1369236522.514 [NAL9602](INFO): Packets left to send: 0
2013-05-22T15:28:42.515Z,1369236522.515 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T012249/shore0000.lzma.parts/0000.sbd
2013-05-22T15:28:52.339Z,1369236532.339 [NAL9602](INFO): SBD MO Status=1, MOMSN=12255, MT Status=0, MTMSN=0
2013-05-22T15:28:52.390Z,1369236532.390 [NAL9602](INFO): Sent 332 bytes from file Logs/20130522T013000/shore0000.lzma
2013-05-22T15:28:52.390Z,1369236532.390 [NAL9602](INFO): Packets left to send: 1
2013-05-22T15:28:52.391Z,1369236532.391 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T013000/shore0000.lzma.parts/0001.sbd
2013-05-22T15:29:03.024Z,1369236543.024 [NAL9602](INFO): SBD MO Status=1, MOMSN=12256, MT Status=0, MTMSN=0
2013-05-22T15:29:03.078Z,1369236543.078 [NAL9602](INFO): Sent 212 bytes from file Logs/20130522T013000/shore0000.lzma
2013-05-22T15:29:03.078Z,1369236543.078 [NAL9602](INFO): Packets left to send: 0
2013-05-22T15:29:03.089Z,1369236543.089 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T013000/shore0000.lzma.parts/0000.sbd
2013-05-22T15:29:11.380Z,1369236551.380 [NAL9602](INFO): SBD MO Status=1, MOMSN=12257, MT Status=0, MTMSN=0
2013-05-22T15:29:11.430Z,1369236551.430 [NAL9602](INFO): Sent 332 bytes from file Logs/20130522T013151/shore0000.lzma
2013-05-22T15:29:11.430Z,1369236551.430 [NAL9602](INFO): Packets left to send: 1
2013-05-22T15:29:11.431Z,1369236551.431 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T013151/shore0000.lzma.parts/0001.sbd
2013-05-22T15:29:21.292Z,1369236561.292 [NAL9602](INFO): SBD MO Status=1, MOMSN=12258, MT Status=0, MTMSN=0
2013-05-22T15:29:21.342Z,1369236561.342 [NAL9602](INFO): Sent 311 bytes from file Logs/20130522T013151/shore0000.lzma
2013-05-22T15:29:21.342Z,1369236561.342 [NAL9602](INFO): Packets left to send: 0
2013-05-22T15:29:21.343Z,1369236561.343 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T013151/shore0000.lzma.parts/0000.sbd
2013-05-22T15:29:48.332Z,1369236588.332 [NAL9602](INFO): SBD MO Status=2, MOMSN=12259, MT Status=2, MTMSN=0
2013-05-22T15:29:48.332Z,1369236588.332 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T15:30:08.118Z,1369236608.118 [NAL9602](INFO): SBD MO Status=1, MOMSN=12259, MT Status=0, MTMSN=0
2013-05-22T15:30:08.166Z,1369236608.166 [NAL9602](INFO): Sent 332 bytes from file Logs/20130522T013151/shore0001.lzma
2013-05-22T15:30:08.166Z,1369236608.166 [NAL9602](INFO): Packets left to send: 1
2013-05-22T15:30:08.167Z,1369236608.167 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T013151/shore0001.lzma.parts/0001.sbd
2013-05-22T15:30:21.992Z,1369236621.992 [NAL9602](INFO): SBD MO Status=1, MOMSN=12260, MT Status=0, MTMSN=0
2013-05-22T15:30:22.042Z,1369236622.042 [NAL9602](INFO): Sent 235 bytes from file Logs/20130522T013151/shore0001.lzma
2013-05-22T15:30:22.042Z,1369236622.042 [NAL9602](INFO): Packets left to send: 0
2013-05-22T15:30:22.043Z,1369236622.043 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T013151/shore0001.lzma.parts/0000.sbd
2013-05-22T15:30:34.312Z,1369236634.312 [NAL9602](INFO): SBD MO Status=1, MOMSN=12261, MT Status=0, MTMSN=0
2013-05-22T15:30:34.366Z,1369236634.366 [NAL9602](INFO): Sent 332 bytes from file Logs/20130522T144302/shore0000.lzma
2013-05-22T15:30:34.366Z,1369236634.366 [NAL9602](INFO): Packets left to send: 2
2013-05-22T15:30:34.367Z,1369236634.367 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T144302/shore0000.lzma.parts/0002.sbd
2013-05-22T15:30:44.943Z,1369236644.943 [NAL9602](INFO): SBD MO Status=1, MOMSN=12262, MT Status=0, MTMSN=0
2013-05-22T15:30:44.994Z,1369236644.994 [NAL9602](INFO): Sent 332 bytes from file Logs/20130522T144302/shore0000.lzma
2013-05-22T15:30:44.994Z,1369236644.994 [NAL9602](INFO): Packets left to send: 1
2013-05-22T15:30:44.995Z,1369236644.995 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T144302/shore0000.lzma.parts/0001.sbd
2013-05-22T15:30:52.813Z,1369236652.813 [NAL9602](INFO): SBD MO Status=1, MOMSN=12263, MT Status=0, MTMSN=0
2013-05-22T15:30:52.858Z,1369236652.858 [NAL9602](INFO): Sent 159 bytes from file Logs/20130522T144302/shore0000.lzma
2013-05-22T15:30:52.858Z,1369236652.858 [NAL9602](INFO): Packets left to send: 0
2013-05-22T15:30:52.859Z,1369236652.859 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T144302/shore0000.lzma.parts/0000.sbd
2013-05-22T15:31:11.908Z,1369236671.908 [NAL9602](INFO): SBD MO Status=1, MOMSN=12264, MT Status=0, MTMSN=0
2013-05-22T15:31:11.966Z,1369236671.966 [NAL9602](INFO): Sent 332 bytes from file Logs/20130522T144907/shore0000.lzma
2013-05-22T15:31:11.966Z,1369236671.966 [NAL9602](INFO): Packets left to send: 2
2013-05-22T15:31:11.967Z,1369236671.967 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T144907/shore0000.lzma.parts/0002.sbd
2013-05-22T15:31:24.663Z,1369236684.663 [NAL9602](INFO): SBD MO Status=1, MOMSN=12265, MT Status=0, MTMSN=0
2013-05-22T15:31:24.710Z,1369236684.710 [NAL9602](INFO): Sent 332 bytes from file Logs/20130522T144907/shore0000.lzma
2013-05-22T15:31:24.710Z,1369236684.710 [NAL9602](INFO): Packets left to send: 1
2013-05-22T15:31:24.711Z,1369236684.711 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T144907/shore0000.lzma.parts/0001.sbd
2013-05-22T15:31:32.173Z,1369236692.173 [NAL9602](INFO): SBD MO Status=1, MOMSN=12266, MT Status=0, MTMSN=0
2013-05-22T15:31:32.222Z,1369236692.222 [NAL9602](INFO): Sent 118 bytes from file Logs/20130522T144907/shore0000.lzma
2013-05-22T15:31:32.222Z,1369236692.222 [NAL9602](INFO): Packets left to send: 0
2013-05-22T15:31:32.223Z,1369236692.223 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T144907/shore0000.lzma.parts/0000.sbd
2013-05-22T15:31:44.841Z,1369236704.841 [NAL9602](INFO): SBD MO Status=1, MOMSN=12267, MT Status=0, MTMSN=0
2013-05-22T15:31:44.890Z,1369236704.890 [NAL9602](INFO): Sent 332 bytes from file Logs/20130522T145043/shore0000.lzma
2013-05-22T15:31:44.890Z,1369236704.890 [NAL9602](INFO): Packets left to send: 2
2013-05-22T15:31:44.891Z,1369236704.891 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T145043/shore0000.lzma.parts/0002.sbd
2013-05-22T15:32:03.496Z,1369236723.496 [NAL9602](INFO): SBD MO Status=1, MOMSN=12268, MT Status=0, MTMSN=0
2013-05-22T15:32:03.554Z,1369236723.554 [NAL9602](INFO): Sent 332 bytes from file Logs/20130522T145043/shore0000.lzma
2013-05-22T15:32:03.554Z,1369236723.554 [NAL9602](INFO): Packets left to send: 1
2013-05-22T15:32:03.555Z,1369236723.555 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T145043/shore0000.lzma.parts/0001.sbd
2013-05-22T15:32:09.344Z,1369236729.344 [NAL9602](INFO): SBD MO Status=1, MOMSN=12269, MT Status=0, MTMSN=0
2013-05-22T15:32:09.394Z,1369236729.394 [NAL9602](INFO): Sent 35 bytes from file Logs/20130522T145043/shore0000.lzma
2013-05-22T15:32:09.394Z,1369236729.394 [NAL9602](INFO): Packets left to send: 0
2013-05-22T15:32:09.395Z,1369236729.395 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T145043/shore0000.lzma.parts/0000.sbd
2013-05-22T15:32:19.180Z,1369236739.180 [NAL9602](INFO): SBD MO Status=1, MOMSN=12270, MT Status=0, MTMSN=0
2013-05-22T15:32:19.230Z,1369236739.230 [NAL9602](INFO): Sent 193 bytes from file Logs/20130522T145043/shore0001.lzma
2013-05-22T15:32:19.230Z,1369236739.230 [NAL9602](INFO): Packets left to send: 0
2013-05-22T15:32:19.231Z,1369236739.231 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T145043/shore0001.lzma.parts/0000.sbd
2013-05-22T15:32:28.676Z,1369236748.676 [NAL9602](INFO): SBD MO Status=1, MOMSN=12271, MT Status=0, MTMSN=0
2013-05-22T15:32:28.726Z,1369236748.726 [NAL9602](INFO): Sent 332 bytes from file Logs/20130522T150009/shore0000.lzma
2013-05-22T15:32:28.726Z,1369236748.726 [NAL9602](INFO): Packets left to send: 1
2013-05-22T15:32:28.728Z,1369236748.728 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T150009/shore0000.lzma.parts/0001.sbd
2013-05-22T15:32:43.380Z,1369236763.380 [NAL9602](INFO): SBD MO Status=1, MOMSN=12272, MT Status=0, MTMSN=0
2013-05-22T15:32:43.430Z,1369236763.430 [NAL9602](INFO): Sent 178 bytes from file Logs/20130522T150009/shore0000.lzma
2013-05-22T15:32:43.430Z,1369236763.430 [NAL9602](INFO): Packets left to send: 0
2013-05-22T15:32:43.431Z,1369236763.431 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T150009/shore0000.lzma.parts/0000.sbd
2013-05-22T15:32:54.848Z,1369236774.848 [NAL9602](INFO): SBD MO Status=1, MOMSN=12273, MT Status=0, MTMSN=0
2013-05-22T15:32:54.898Z,1369236774.898 [NAL9602](INFO): Sent 332 bytes from file Logs/20130522T150308/shore0000.lzma
2013-05-22T15:32:54.898Z,1369236774.898 [NAL9602](INFO): Packets left to send: 1
2013-05-22T15:32:54.900Z,1369236774.899 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T150308/shore0000.lzma.parts/0001.sbd
2013-05-22T15:33:06.291Z,1369236786.291 [NAL9602](INFO): SBD MO Status=1, MOMSN=12274, MT Status=0, MTMSN=0
2013-05-22T15:33:06.342Z,1369236786.342 [NAL9602](INFO): Sent 53 bytes from file Logs/20130522T150308/shore0000.lzma
2013-05-22T15:33:06.342Z,1369236786.342 [NAL9602](INFO): Packets left to send: 0
2013-05-22T15:33:06.343Z,1369236786.343 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T150308/shore0000.lzma.parts/0000.sbd
2013-05-22T15:33:21.348Z,1369236801.348 [NAL9602](INFO): SBD MO Status=1, MOMSN=12275, MT Status=0, MTMSN=0
2013-05-22T15:33:21.398Z,1369236801.398 [NAL9602](INFO): Sent 332 bytes from file Logs/20130522T151258/shore0000.lzma
2013-05-22T15:33:21.398Z,1369236801.398 [NAL9602](INFO): Packets left to send: 4
2013-05-22T15:33:21.399Z,1369236801.399 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T151258/shore0000.lzma.parts/0004.sbd
2013-05-22T15:33:40.796Z,1369236820.796 [NAL9602](INFO): SBD MO Status=1, MOMSN=12276, MT Status=0, MTMSN=0
2013-05-22T15:33:40.854Z,1369236820.854 [NAL9602](INFO): Sent 332 bytes from file Logs/20130522T151258/shore0000.lzma
2013-05-22T15:33:40.854Z,1369236820.854 [NAL9602](INFO): Packets left to send: 3
2013-05-22T15:33:40.855Z,1369236820.855 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T151258/shore0000.lzma.parts/0003.sbd
2013-05-22T15:33:53.032Z,1369236833.032 [NAL9602](INFO): SBD MO Status=1, MOMSN=12277, MT Status=0, MTMSN=0
2013-05-22T15:33:53.082Z,1369236833.082 [NAL9602](INFO): Sent 332 bytes from file Logs/20130522T151258/shore0000.lzma
2013-05-22T15:33:53.082Z,1369236833.082 [NAL9602](INFO): Packets left to send: 2
2013-05-22T15:33:53.083Z,1369236833.083 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T151258/shore0000.lzma.parts/0002.sbd
2013-05-22T15:34:02.063Z,1369236842.063 [NAL9602](INFO): SBD MO Status=1, MOMSN=12278, MT Status=0, MTMSN=0
2013-05-22T15:34:02.110Z,1369236842.110 [NAL9602](INFO): Sent 332 bytes from file Logs/20130522T151258/shore0000.lzma
2013-05-22T15:34:02.110Z,1369236842.110 [NAL9602](INFO): Packets left to send: 1
2013-05-22T15:34:02.111Z,1369236842.111 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T151258/shore0000.lzma.parts/0001.sbd
2013-05-22T15:34:14.809Z,1369236854.809 [NAL9602](INFO): SBD MO Status=1, MOMSN=12279, MT Status=0, MTMSN=0
2013-05-22T15:34:14.858Z,1369236854.858 [NAL9602](INFO): Sent 306 bytes from file Logs/20130522T151258/shore0000.lzma
2013-05-22T15:34:14.858Z,1369236854.858 [NAL9602](INFO): Packets left to send: 0
2013-05-22T15:34:14.859Z,1369236854.859 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T151258/shore0000.lzma.parts/0000.sbd
2013-05-22T15:34:24.412Z,1369236864.412 [NAL9602](INFO): SBD MO Status=0, MOMSN=12280, MT Status=0, MTMSN=0
2013-05-22T15:34:28.261Z,1369236868.260 [Default:Iridium:Read_Iridium] Stopped
2013-05-22T15:34:28.261Z,1369236868.261 [Default:Iridium](INFO): Completed Default:Iridium
2013-05-22T15:34:28.261Z,1369236868.261 [Default:Iridium] Stopped
2013-05-22T15:34:28.261Z,1369236868.261 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-05-22T15:34:28.261Z,1369236868.261 [Default:Iridium:A.SetSpeed] Stopped
2013-05-22T15:34:28.261Z,1369236868.261 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-05-22T15:34:28.262Z,1369236868.262 [Default:F.Wait] Running Loop=1
2013-05-22T15:34:28.262Z,1369236868.262 [Default:F.Wait](DEBUG): Initialize Wait Component.
2013-05-22T15:34:28.652Z,1369236868.652 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-05-22T15:34:28.652Z,1369236868.652 [Default:CallIridium:B] Stopped
2013-05-22T15:34:28.652Z,1369236868.652 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-05-22T15:34:28.652Z,1369236868.652 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-05-22T15:34:28.652Z,1369236868.652 [Default:CallIridium] Stopped
2013-05-22T15:34:28.652Z,1369236868.652 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-05-22T15:34:38.623Z,1369236878.623 [NAL9602](INFO): Powering down
2013-05-22T15:39:28.660Z,1369237168.660 [Default:CallIridium] Running Loop=1
2013-05-22T15:39:28.660Z,1369237168.660 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-05-22T15:39:28.660Z,1369237168.660 [Default:CallIridium:A] Running Loop=1
2013-05-22T15:39:28.660Z,1369237168.660 [Default:CallIridium:A] Stopped
2013-05-22T15:39:28.660Z,1369237168.661 [Default:CallIridium:B] Running Loop=1
2013-05-22T15:39:28.661Z,1369237168.661 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-05-22T15:39:33.626Z,1369237173.626 [Default:Iridium] Running Loop=1
2013-05-22T15:39:33.626Z,1369237173.626 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-05-22T15:39:33.626Z,1369237173.626 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-05-22T15:39:33.627Z,1369237173.626 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-05-22T15:39:33.627Z,1369237173.627 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-05-22T15:39:33.627Z,1369237173.627 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-22T15:39:33.627Z,1369237173.628 [Default:Iridium:B.GoToSurface] Stopped
2013-05-22T15:39:33.628Z,1369237173.628 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-05-22T15:39:33.628Z,1369237173.628 [Default:Iridium:Read_Iridium] Running Loop=1
2013-05-22T15:39:33.628Z,1369237173.628 [Default:GPS] Running Loop=1
2013-05-22T15:39:33.628Z,1369237173.628 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-05-22T15:39:33.628Z,1369237173.628 [Default:GPS:A.SetSpeed] Running Loop=1
2013-05-22T15:39:33.628Z,1369237173.628 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-05-22T15:39:33.629Z,1369237173.629 [Default:GPS:B.GoToSurface] Running Loop=1
2013-05-22T15:39:33.629Z,1369237173.629 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-22T15:39:33.629Z,1369237173.629 [Default:GPS:B.GoToSurface] Stopped
2013-05-22T15:39:33.629Z,1369237173.629 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-05-22T15:39:33.630Z,1369237173.630 [Default:GPS:Read_GPS] Running Loop=1
2013-05-22T15:39:34.271Z,1369237174.271 [NAL9602](INFO): Powering up
2013-05-22T15:39:44.822Z,1369237184.822 [NAL9602](INFO): NAL9602 initialized
2013-05-22T15:40:04.506Z,1369237204.506 [NAL9602](INFO): SBD MO Status=1, MOMSN=12281, MT Status=0, MTMSN=0
2013-05-22T15:40:04.554Z,1369237204.554 [NAL9602](INFO): Sent 284 bytes from file Logs/20130522T151258/shore0001.lzma
2013-05-22T15:40:04.554Z,1369237204.554 [NAL9602](INFO): Packets left to send: 0
2013-05-22T15:40:04.555Z,1369237204.555 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T151258/shore0001.lzma.parts/0000.sbd
2013-05-22T15:40:14.499Z,1369237214.499 [NAL9602](INFO): SBD MO Status=0, MOMSN=12282, MT Status=0, MTMSN=0
2013-05-22T15:40:18.297Z,1369237218.297 [Default:Iridium:Read_Iridium] Stopped
2013-05-22T15:40:18.298Z,1369237218.298 [Default:Iridium](INFO): Completed Default:Iridium
2013-05-22T15:40:18.298Z,1369237218.298 [Default:Iridium] Stopped
2013-05-22T15:40:18.298Z,1369237218.298 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-05-22T15:40:18.298Z,1369237218.298 [Default:Iridium:A.SetSpeed] Stopped
2013-05-22T15:40:18.298Z,1369237218.298 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-05-22T15:40:18.691Z,1369237218.691 [Depth_Keller](ERROR): Pressure reading out of range: 1830.563232 decibar
2013-05-22T15:40:18.707Z,1369237218.707 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-05-22T15:40:18.707Z,1369237218.707 [Default:CallIridium:B] Stopped
2013-05-22T15:40:18.708Z,1369237218.708 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-05-22T15:40:18.708Z,1369237218.708 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-05-22T15:40:18.708Z,1369237218.708 [Default:CallIridium] Stopped
2013-05-22T15:40:18.708Z,1369237218.708 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-05-22T15:40:36.513Z,1369237236.513 [NAL9602](IMPORTANT): GPS fix at: 1369237234.00
2013-05-22T15:40:36.532Z,1369237236.532 [Default:GPS:Read_GPS] Stopped
2013-05-22T15:40:36.532Z,1369237236.532 [Default:GPS:D] Running Loop=1
2013-05-22T15:40:36.989Z,1369237236.989 [Default:GPS:D] Stopped
2013-05-22T15:40:36.990Z,1369237236.990 [Default:GPS](INFO): Completed Default:GPS
2013-05-22T15:40:36.990Z,1369237236.990 [Default:GPS] Stopped
2013-05-22T15:40:36.990Z,1369237236.990 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-05-22T15:40:36.990Z,1369237236.990 [Default:GPS:A.SetSpeed] Stopped
2013-05-22T15:40:36.990Z,1369237236.990 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-05-22T15:40:57.499Z,1369237257.499 [NAL9602](INFO): Powering down
2013-05-22T15:45:17.502Z,1369237517.502 [Default:CallIridium] Running Loop=1
2013-05-22T15:45:17.502Z,1369237517.503 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-05-22T15:45:17.503Z,1369237517.503 [Default:CallIridium:A] Running Loop=1
2013-05-22T15:45:17.503Z,1369237517.503 [Default:CallIridium:A] Stopped
2013-05-22T15:45:17.503Z,1369237517.503 [Default:CallIridium:B] Running Loop=1
2013-05-22T15:45:17.503Z,1369237517.503 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-05-22T15:45:22.495Z,1369237522.495 [Default:Iridium] Running Loop=1
2013-05-22T15:45:22.495Z,1369237522.495 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-05-22T15:45:22.495Z,1369237522.495 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-05-22T15:45:22.495Z,1369237522.495 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-05-22T15:45:22.495Z,1369237522.495 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-05-22T15:45:22.495Z,1369237522.495 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-22T15:45:22.496Z,1369237522.496 [Default:Iridium:B.GoToSurface] Stopped
2013-05-22T15:45:22.496Z,1369237522.496 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-05-22T15:45:22.496Z,1369237522.496 [Default:Iridium:Read_Iridium] Running Loop=1
2013-05-22T15:45:22.496Z,1369237522.497 [Default:GPS] Running Loop=1
2013-05-22T15:45:22.497Z,1369237522.497 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-05-22T15:45:22.497Z,1369237522.497 [Default:GPS:A.SetSpeed] Running Loop=1
2013-05-22T15:45:22.497Z,1369237522.497 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-05-22T15:45:22.497Z,1369237522.497 [Default:GPS:B.GoToSurface] Running Loop=1
2013-05-22T15:45:22.497Z,1369237522.497 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-22T15:45:22.498Z,1369237522.498 [Default:GPS:B.GoToSurface] Stopped
2013-05-22T15:45:22.498Z,1369237522.498 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-05-22T15:45:22.498Z,1369237522.498 [Default:GPS:Read_GPS] Running Loop=1
2013-05-22T15:45:23.104Z,1369237523.104 [NAL9602](INFO): Powering up
2013-05-22T15:45:34.074Z,1369237534.074 [NAL9602](INFO): NAL9602 initialized
2013-05-22T15:45:50.564Z,1369237550.564 [NAL9602](INFO): SBD MO Status=1, MOMSN=12283, MT Status=0, MTMSN=0
2013-05-22T15:45:50.614Z,1369237550.614 [NAL9602](INFO): Sent 161 bytes from file Logs/20130522T151258/shore0002.lzma
2013-05-22T15:45:50.614Z,1369237550.614 [NAL9602](INFO): Packets left to send: 0
2013-05-22T15:45:50.615Z,1369237550.615 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T151258/shore0002.lzma.parts/0000.sbd
2013-05-22T15:45:57.768Z,1369237557.768 [NAL9602](INFO): SBD MO Status=0, MOMSN=12284, MT Status=0, MTMSN=0
2013-05-22T15:46:01.562Z,1369237561.562 [Default:Iridium:Read_Iridium] Stopped
2013-05-22T15:46:01.562Z,1369237561.562 [Default:Iridium](INFO): Completed Default:Iridium
2013-05-22T15:46:01.563Z,1369237561.563 [Default:Iridium] Stopped
2013-05-22T15:46:01.563Z,1369237561.563 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-05-22T15:46:01.563Z,1369237561.563 [Default:Iridium:A.SetSpeed] Stopped
2013-05-22T15:46:01.563Z,1369237561.563 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-05-22T15:46:01.891Z,1369237561.891 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-05-22T15:46:01.891Z,1369237561.891 [Default:CallIridium:B] Stopped
2013-05-22T15:46:01.891Z,1369237561.891 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-05-22T15:46:01.891Z,1369237561.891 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-05-22T15:46:01.891Z,1369237561.891 [Default:CallIridium] Stopped
2013-05-22T15:46:01.891Z,1369237561.891 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-05-22T15:46:28.166Z,1369237588.166 [NAL9602](IMPORTANT): GPS fix at: 1369237586.00
2013-05-22T15:46:28.182Z,1369237588.182 [Default:GPS:Read_GPS] Stopped
2013-05-22T15:46:28.182Z,1369237588.182 [Default:GPS:D] Running Loop=1
2013-05-22T15:46:28.591Z,1369237588.591 [Default:GPS:D] Stopped
2013-05-22T15:46:28.591Z,1369237588.591 [Default:GPS](INFO): Completed Default:GPS
2013-05-22T15:46:28.591Z,1369237588.591 [Default:GPS] Stopped
2013-05-22T15:46:28.591Z,1369237588.591 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-05-22T15:46:28.591Z,1369237588.591 [Default:GPS:A.SetSpeed] Stopped
2013-05-22T15:46:28.591Z,1369237588.592 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-05-22T15:46:49.123Z,1369237609.124 [NAL9602](INFO): Powering down
2013-05-22T15:50:59.161Z,1369237859.161 [Default:CallIridium] Running Loop=1
2013-05-22T15:50:59.161Z,1369237859.161 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-05-22T15:50:59.161Z,1369237859.161 [Default:CallIridium:A] Running Loop=1
2013-05-22T15:50:59.162Z,1369237859.162 [Default:CallIridium:A] Stopped
2013-05-22T15:50:59.162Z,1369237859.162 [Default:CallIridium:B] Running Loop=1
2013-05-22T15:50:59.162Z,1369237859.162 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-05-22T15:51:04.174Z,1369237864.174 [Default:Iridium] Running Loop=1
2013-05-22T15:51:04.174Z,1369237864.174 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-05-22T15:51:04.174Z,1369237864.174 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-05-22T15:51:04.174Z,1369237864.174 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-05-22T15:51:04.175Z,1369237864.175 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-05-22T15:51:04.175Z,1369237864.175 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-22T15:51:04.176Z,1369237864.175 [Default:Iridium:B.GoToSurface] Stopped
2013-05-22T15:51:04.176Z,1369237864.175 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-05-22T15:51:04.176Z,1369237864.176 [Default:Iridium:Read_Iridium] Running Loop=1
2013-05-22T15:51:04.176Z,1369237864.176 [Default:GPS] Running Loop=1
2013-05-22T15:51:04.176Z,1369237864.176 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-05-22T15:51:04.176Z,1369237864.176 [Default:GPS:A.SetSpeed] Running Loop=1
2013-05-22T15:51:04.176Z,1369237864.176 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-05-22T15:51:04.176Z,1369237864.177 [Default:GPS:B.GoToSurface] Running Loop=1
2013-05-22T15:51:04.177Z,1369237864.177 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-22T15:51:04.178Z,1369237864.178 [Default:GPS:B.GoToSurface] Stopped
2013-05-22T15:51:04.178Z,1369237864.178 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-05-22T15:51:04.178Z,1369237864.178 [Default:GPS:Read_GPS] Running Loop=1
2013-05-22T15:51:04.773Z,1369237864.773 [NAL9602](INFO): Powering up
2013-05-22T15:51:15.774Z,1369237875.774 [NAL9602](INFO): NAL9602 initialized
2013-05-22T15:51:42.916Z,1369237902.916 [NAL9602](INFO): SBD MO Status=1, MOMSN=12285, MT Status=0, MTMSN=0
2013-05-22T15:51:42.966Z,1369237902.966 [NAL9602](INFO): Sent 153 bytes from file Logs/20130522T151258/shore0003.lzma
2013-05-22T15:51:42.966Z,1369237902.966 [NAL9602](INFO): Packets left to send: 0
2013-05-22T15:51:42.967Z,1369237902.967 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T151258/shore0003.lzma.parts/0000.sbd
2013-05-22T15:51:52.924Z,1369237912.924 [NAL9602](INFO): SBD MO Status=0, MOMSN=12286, MT Status=0, MTMSN=0
2013-05-22T15:51:56.632Z,1369237916.632 [Default:Iridium:Read_Iridium] Stopped
2013-05-22T15:51:56.633Z,1369237916.633 [Default:Iridium](INFO): Completed Default:Iridium
2013-05-22T15:51:56.633Z,1369237916.633 [Default:Iridium] Stopped
2013-05-22T15:51:56.633Z,1369237916.633 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-05-22T15:51:56.648Z,1369237916.648 [Default:Iridium:A.SetSpeed] Stopped
2013-05-22T15:51:56.649Z,1369237916.649 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-05-22T15:51:56.998Z,1369237916.998 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-05-22T15:51:56.998Z,1369237916.998 [Default:CallIridium:B] Stopped
2013-05-22T15:51:56.998Z,1369237916.999 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-05-22T15:51:56.999Z,1369237916.999 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-05-22T15:51:56.999Z,1369237916.999 [Default:CallIridium] Stopped
2013-05-22T15:51:56.999Z,1369237916.999 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-05-22T15:52:00.482Z,1369237920.482 [NAL9602](IMPORTANT): GPS fix at: 1369237919.00
2013-05-22T15:52:00.499Z,1369237920.499 [Default:GPS:Read_GPS] Stopped
2013-05-22T15:52:00.499Z,1369237920.499 [Default:GPS:D] Running Loop=1
2013-05-22T15:52:00.878Z,1369237920.878 [Default:GPS:D] Stopped
2013-05-22T15:52:00.879Z,1369237920.879 [Default:GPS](INFO): Completed Default:GPS
2013-05-22T15:52:00.879Z,1369237920.879 [Default:GPS] Stopped
2013-05-22T15:52:00.879Z,1369237920.879 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-05-22T15:52:00.879Z,1369237920.879 [Default:GPS:A.SetSpeed] Stopped
2013-05-22T15:52:00.879Z,1369237920.879 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-05-22T15:52:21.423Z,1369237941.423 [NAL9602](INFO): Powering down
2013-05-22T15:56:56.426Z,1369238216.426 [Default:CallIridium] Running Loop=1
2013-05-22T15:56:56.427Z,1369238216.427 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-05-22T15:56:56.427Z,1369238216.427 [Default:CallIridium:A] Running Loop=1
2013-05-22T15:56:56.427Z,1369238216.427 [Default:CallIridium:A] Stopped
2013-05-22T15:56:56.427Z,1369238216.427 [Default:CallIridium:B] Running Loop=1
2013-05-22T15:56:56.427Z,1369238216.427 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-05-22T15:57:01.460Z,1369238221.460 [Default:Iridium] Running Loop=1
2013-05-22T15:57:01.460Z,1369238221.460 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-05-22T15:57:01.460Z,1369238221.460 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-05-22T15:57:01.460Z,1369238221.460 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-05-22T15:57:01.460Z,1369238221.460 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-05-22T15:57:01.460Z,1369238221.460 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-22T15:57:01.461Z,1369238221.461 [Default:Iridium:B.GoToSurface] Stopped
2013-05-22T15:57:01.461Z,1369238221.461 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-05-22T15:57:01.461Z,1369238221.461 [Default:Iridium:Read_Iridium] Running Loop=1
2013-05-22T15:57:01.462Z,1369238221.462 [Default:GPS] Running Loop=1
2013-05-22T15:57:01.462Z,1369238221.462 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-05-22T15:57:01.462Z,1369238221.462 [Default:GPS:A.SetSpeed] Running Loop=1
2013-05-22T15:57:01.462Z,1369238221.462 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-05-22T15:57:01.462Z,1369238221.462 [Default:GPS:B.GoToSurface] Running Loop=1
2013-05-22T15:57:01.462Z,1369238221.462 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-22T15:57:01.463Z,1369238221.463 [Default:GPS:B.GoToSurface] Stopped
2013-05-22T15:57:01.463Z,1369238221.463 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-05-22T15:57:01.463Z,1369238221.463 [Default:GPS:Read_GPS] Running Loop=1
2013-05-22T15:57:02.055Z,1369238222.055 [NAL9602](INFO): Powering up
2013-05-22T15:57:12.566Z,1369238232.566 [NAL9602](INFO): NAL9602 initialized
2013-05-22T15:57:28.704Z,1369238248.704 [NAL9602](INFO): SBD MO Status=1, MOMSN=12287, MT Status=0, MTMSN=0
2013-05-22T15:57:28.754Z,1369238248.754 [NAL9602](INFO): Sent 156 bytes from file Logs/20130522T151258/shore0004.lzma
2013-05-22T15:57:28.754Z,1369238248.754 [NAL9602](INFO): Packets left to send: 0
2013-05-22T15:57:28.755Z,1369238248.755 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T151258/shore0004.lzma.parts/0000.sbd
2013-05-22T15:57:37.904Z,1369238257.904 [NAL9602](INFO): SBD MO Status=0, MOMSN=12288, MT Status=0, MTMSN=0
2013-05-22T15:57:41.739Z,1369238261.740 [Default:Iridium:Read_Iridium] Stopped
2013-05-22T15:57:41.740Z,1369238261.740 [Default:Iridium](INFO): Completed Default:Iridium
2013-05-22T15:57:41.740Z,1369238261.740 [Default:Iridium] Stopped
2013-05-22T15:57:41.740Z,1369238261.740 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-05-22T15:57:41.740Z,1369238261.740 [Default:Iridium:A.SetSpeed] Stopped
2013-05-22T15:57:41.740Z,1369238261.740 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-05-22T15:57:42.106Z,1369238262.106 [Depth_Keller](ERROR): Pressure reading out of range: 1830.568359 decibar
2013-05-22T15:57:42.122Z,1369238262.122 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-05-22T15:57:42.122Z,1369238262.122 [Default:CallIridium:B] Stopped
2013-05-22T15:57:42.122Z,1369238262.122 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-05-22T15:57:42.123Z,1369238262.122 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-05-22T15:57:42.123Z,1369238262.123 [Default:CallIridium] Stopped
2013-05-22T15:57:42.123Z,1369238262.123 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-05-22T15:58:33.178Z,1369238313.178 [NAL9602](IMPORTANT): GPS fix at: 1369238312.00
2013-05-22T15:58:33.194Z,1369238313.194 [Default:GPS:Read_GPS] Stopped
2013-05-22T15:58:33.194Z,1369238313.194 [Default:GPS:D] Running Loop=1
2013-05-22T15:58:33.557Z,1369238313.557 [Default:GPS:D] Stopped
2013-05-22T15:58:33.558Z,1369238313.558 [Default:GPS](INFO): Completed Default:GPS
2013-05-22T15:58:33.558Z,1369238313.558 [Default:GPS] Stopped
2013-05-22T15:58:33.558Z,1369238313.558 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-05-22T15:58:33.558Z,1369238313.558 [Default:GPS:A.SetSpeed] Stopped
2013-05-22T15:58:33.558Z,1369238313.558 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-05-22T15:58:54.087Z,1369238334.087 [NAL9602](INFO): Powering down
2013-05-22T16:02:39.157Z,1369238559.157 [Default:CallIridium] Running Loop=1
2013-05-22T16:02:39.157Z,1369238559.158 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-05-22T16:02:39.158Z,1369238559.158 [Default:CallIridium:A] Running Loop=1
2013-05-22T16:02:39.158Z,1369238559.158 [Default:CallIridium:A] Stopped
2013-05-22T16:02:39.158Z,1369238559.158 [Default:CallIridium:B] Running Loop=1
2013-05-22T16:02:39.158Z,1369238559.158 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-05-22T16:02:44.115Z,1369238564.115 [Default:Iridium] Running Loop=1
2013-05-22T16:02:44.116Z,1369238564.115 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-05-22T16:02:44.116Z,1369238564.116 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-05-22T16:02:44.116Z,1369238564.116 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-05-22T16:02:44.116Z,1369238564.116 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-05-22T16:02:44.116Z,1369238564.116 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-22T16:02:44.117Z,1369238564.117 [Default:Iridium:B.GoToSurface] Stopped
2013-05-22T16:02:44.117Z,1369238564.117 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-05-22T16:02:44.117Z,1369238564.117 [Default:Iridium:Read_Iridium] Running Loop=1
2013-05-22T16:02:44.117Z,1369238564.118 [Default:GPS] Running Loop=1
2013-05-22T16:02:44.118Z,1369238564.118 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-05-22T16:02:44.118Z,1369238564.118 [Default:GPS:A.SetSpeed] Running Loop=1
2013-05-22T16:02:44.118Z,1369238564.118 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-05-22T16:02:44.118Z,1369238564.118 [Default:GPS:B.GoToSurface] Running Loop=1
2013-05-22T16:02:44.118Z,1369238564.118 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-22T16:02:44.119Z,1369238564.119 [Default:GPS:B.GoToSurface] Stopped
2013-05-22T16:02:44.119Z,1369238564.119 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-05-22T16:02:44.119Z,1369238564.119 [Default:GPS:Read_GPS] Running Loop=1
2013-05-22T16:02:44.774Z,1369238564.774 [NAL9602](INFO): Powering up
2013-05-22T16:02:55.690Z,1369238575.690 [NAL9602](INFO): NAL9602 initialized
2013-05-22T16:03:13.380Z,1369238593.380 [Radio_Freewave](INFO): Powering down
2013-05-22T16:03:13.820Z,1369238593.820 [Radio_Freewave](FAULT): LCB fault:  Software Overcurrent.
2013-05-22T16:03:13.820Z,1369238593.820 [Radio_Freewave] Hardware Fault, FailCount= 1
2013-05-22T16:03:13.821Z,1369238593.820 [Radio_Freewave](ERROR): Hardware Fault
2013-05-22T16:03:13.872Z,1369238593.872 [CBIT](ERROR): Hardware Fault in component: Radio_Freewave
2013-05-22T16:03:14.296Z,1369238594.296 [CBIT](INFO): Clearing failed state for component Radio_Freewave
2013-05-22T16:03:14.296Z,1369238594.296 [Radio_Freewave] No Fault, FailCount= 1
2013-05-22T16:03:14.632Z,1369238594.632 [Radio_Freewave](INFO): Powering up
2013-05-22T16:03:15.416Z,1369238595.416 [NAL9602](INFO): SBD MO Status=2, MOMSN=12289, MT Status=2, MTMSN=0
2013-05-22T16:03:15.417Z,1369238595.417 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-22T16:03:16.599Z,1369238596.599 [Radio_Freewave](INFO): Powering down
2013-05-22T16:03:33.795Z,1369238613.795 [Radio_Freewave](INFO): Powering up
2013-05-22T16:03:37.046Z,1369238617.046 [Radio_Freewave](INFO): Powering down
2013-05-22T16:03:38.244Z,1369238618.244 [Radio_Freewave](INFO): Powering up
2013-05-22T16:04:07.748Z,1369238647.748 [NAL9602](INFO): SBD MO Status=1, MOMSN=12289, MT Status=0, MTMSN=0
2013-05-22T16:04:07.798Z,1369238647.798 [NAL9602](INFO): Sent 166 bytes from file Logs/20130522T151258/shore0005.lzma
2013-05-22T16:04:07.798Z,1369238647.798 [NAL9602](INFO): Packets left to send: 0
2013-05-22T16:04:07.799Z,1369238647.799 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T151258/shore0005.lzma.parts/0000.sbd
2013-05-22T16:04:18.548Z,1369238658.548 [NAL9602](INFO): SBD MO Status=0, MOMSN=12290, MT Status=0, MTMSN=0
2013-05-22T16:04:22.231Z,1369238662.231 [Default:Iridium:Read_Iridium] Stopped
2013-05-22T16:04:22.232Z,1369238662.232 [Default:Iridium](INFO): Completed Default:Iridium
2013-05-22T16:04:22.232Z,1369238662.232 [Default:Iridium] Stopped
2013-05-22T16:04:22.232Z,1369238662.232 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-05-22T16:04:22.232Z,1369238662.232 [Default:Iridium:A.SetSpeed] Stopped
2013-05-22T16:04:22.232Z,1369238662.232 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-05-22T16:04:22.602Z,1369238662.602 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-05-22T16:04:22.602Z,1369238662.602 [Default:CallIridium:B] Stopped
2013-05-22T16:04:22.602Z,1369238662.602 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-05-22T16:04:22.603Z,1369238662.603 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-05-22T16:04:22.603Z,1369238662.603 [Default:CallIridium] Stopped
2013-05-22T16:04:22.603Z,1369238662.603 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-05-22T16:04:32.450Z,1369238672.450 [NAL9602](IMPORTANT): GPS fix at: 1369238672.00
2013-05-22T16:04:32.466Z,1369238672.466 [Default:GPS:Read_GPS] Stopped
2013-05-22T16:04:32.467Z,1369238672.467 [Default:GPS:D] Running Loop=1
2013-05-22T16:04:32.881Z,1369238672.881 [Default:GPS:D] Stopped
2013-05-22T16:04:32.882Z,1369238672.882 [Default:GPS](INFO): Completed Default:GPS
2013-05-22T16:04:32.882Z,1369238672.882 [Default:GPS] Stopped
2013-05-22T16:04:32.882Z,1369238672.882 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-05-22T16:04:32.882Z,1369238672.882 [Default:GPS:A.SetSpeed] Stopped
2013-05-22T16:04:32.882Z,1369238672.882 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-05-22T16:04:53.475Z,1369238693.476 [NAL9602](INFO): Powering down
2013-05-22T16:09:23.462Z,1369238963.462 [Default:CallIridium] Running Loop=1
2013-05-22T16:09:23.463Z,1369238963.463 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-05-22T16:09:23.463Z,1369238963.463 [Default:CallIridium:A] Running Loop=1
2013-05-22T16:09:23.463Z,1369238963.463 [Default:CallIridium:A] Stopped
2013-05-22T16:09:23.463Z,1369238963.463 [Default:CallIridium:B] Running Loop=1
2013-05-22T16:09:23.463Z,1369238963.463 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-05-22T16:09:28.463Z,1369238968.463 [Default:Iridium] Running Loop=1
2013-05-22T16:09:28.463Z,1369238968.463 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-05-22T16:09:28.463Z,1369238968.463 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-05-22T16:09:28.463Z,1369238968.463 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-05-22T16:09:28.463Z,1369238968.463 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-05-22T16:09:28.463Z,1369238968.463 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-22T16:09:28.464Z,1369238968.464 [Default:Iridium:B.GoToSurface] Stopped
2013-05-22T16:09:28.464Z,1369238968.464 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-05-22T16:09:28.464Z,1369238968.464 [Default:Iridium:Read_Iridium] Running Loop=1
2013-05-22T16:09:28.465Z,1369238968.464 [Default:GPS] Running Loop=1
2013-05-22T16:09:28.465Z,1369238968.465 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-05-22T16:09:28.465Z,1369238968.465 [Default:GPS:A.SetSpeed] Running Loop=1
2013-05-22T16:09:28.465Z,1369238968.465 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-05-22T16:09:28.465Z,1369238968.465 [Default:GPS:B.GoToSurface] Running Loop=1
2013-05-22T16:09:28.465Z,1369238968.465 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-22T16:09:28.466Z,1369238968.466 [Default:GPS:B.GoToSurface] Stopped
2013-05-22T16:09:28.466Z,1369238968.466 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-05-22T16:09:28.466Z,1369238968.466 [Default:GPS:Read_GPS] Running Loop=1
2013-05-22T16:09:29.063Z,1369238969.063 [NAL9602](INFO): Powering up
2013-05-22T16:09:40.022Z,1369238980.022 [NAL9602](INFO): NAL9602 initialized
2013-05-22T16:10:02.539Z,1369239002.539 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=12291, MT Status=1, MTMSN=872
2013-05-22T16:10:02.586Z,1369239002.586 [NAL9602](INFO): Sent 260 bytes from file Logs/20130522T151258/shore0006.lzma
2013-05-22T16:10:02.586Z,1369239002.586 [NAL9602](INFO): Packets left to send: 0
2013-05-22T16:10:02.587Z,1369239002.588 [NAL9602](INFO): Stored copy of sent data in Logs/20130522T151258/shore0006.lzma.parts/0000.sbd
2013-05-22T16:10:03.130Z,1369239003.130 [NAL9602](INFO): Received command:Restart app
2013-05-22T16:10:03.170Z,1369239003.170 [CommandLine](IMPORTANT): got command restart application
2013-05-22T16:10:04.164Z,1369239004.164 [NAL9602](IMPORTANT): GPS fix at: 1369239004.00
2013-05-22T16:10:04.185Z,1369239004.185 [Default:GPS:Read_GPS] Stopped
2013-05-22T16:10:04.185Z,1369239004.185 [Default:GPS:D] Running Loop=1
2013-05-22T16:10:04.261Z,1369239004.261 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2013-05-22T16:10:04.262Z,1369239004.261 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2013-05-22T16:10:04.521Z,1369239004.521 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2013-05-22T16:10:04.603Z,1369239004.603 [Default:GPS:D] Stopped
2013-05-22T16:10:04.603Z,1369239004.603 [Default:GPS](INFO): Completed Default:GPS
2013-05-22T16:10:04.603Z,1369239004.603 [Default:GPS] Stopped
2013-05-22T16:10:04.604Z,1369239004.603 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-05-22T16:10:04.604Z,1369239004.604 [Default:GPS:A.SetSpeed] Stopped
2013-05-22T16:10:04.604Z,1369239004.604 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-05-22T16:10:04.842Z,1369239004.842 [WetLabsBB2FL](INFO): Powering down
2013-05-22T16:10:04.857Z,1369239004.857 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2013-05-22T16:10:05.052Z,1369239005.053 [CTD_NeilBrown](INFO): Powering down
2013-05-22T16:10:05.061Z,1369239005.061 [ComponentRegistry](INFO): Shutting down DVL_micro ThreadHandler
2013-05-22T16:10:05.174Z,1369239005.174 [DVL_micro](INFO): uninitialize:Powering down
2013-05-22T16:10:05.181Z,1369239005.181 [ComponentRegistry](INFO): Shutting down AsyncPiEstimator ThreadHandler
2013-05-22T16:10:05.434Z,1369239005.434 [AsyncPiEstimator](DEBUG): Uninitialize AsyncPiEstimator.
2013-05-22T16:10:05.451Z,1369239005.451 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2013-05-22T16:10:05.456Z,1369239005.456 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2013-05-22T16:10:05.458Z,1369239005.458 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2013-05-22T16:10:05.582Z,1369239005.582 [controlThread](DEBUG): Uninitializing ControlThread
2013-05-22T16:10:05.582Z,1369239005.582 [AHRS_sp3003D](INFO): Powering down
2013-05-22T16:10:05.671Z,1369239005.671 [NAL9602](INFO): Powering down
2013-05-22T16:10:05.672Z,1369239005.672 [DAT](INFO): Powering down
2013-05-22T16:10:05.673Z,1369239005.673 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2013-05-22T16:10:05.674Z,1369239005.674 [NavChart](DEBUG): Uninitialize NavChart Derivation.
2013-05-22T16:10:05.675Z,1369239005.675 [Default] Stopped
2013-05-22T16:10:05.675Z,1369239005.675 [Default](INFO): Aggregate::uninitialize Default
2013-05-22T16:10:05.675Z,1369239005.675 [Default:Iridium] Stopped
2013-05-22T16:10:05.675Z,1369239005.675 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-05-22T16:10:05.675Z,1369239005.675 [Default:Iridium:A.SetSpeed] Stopped
2013-05-22T16:10:05.675Z,1369239005.675 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-05-22T16:10:05.675Z,1369239005.675 [Default:Iridium:Read_Iridium] Stopped
2013-05-22T16:10:05.675Z,1369239005.675 [Default:CallIridium] Stopped
2013-05-22T16:10:05.675Z,1369239005.675 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-05-22T16:10:05.675Z,1369239005.675 [Default:CallIridium:B] Stopped
2013-05-22T16:10:05.676Z,1369239005.676 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-05-22T16:10:05.676Z,1369239005.676 [Default:D.SetSpeed] Stopped
2013-05-22T16:10:05.676Z,1369239005.676 [Default:D.SetSpeed](DEBUG): Uninitialize.
2013-05-22T16:10:05.676Z,1369239005.676 [Default:E.GoToSurface] Stopped
2013-05-22T16:10:05.676Z,1369239005.676 [Default:E.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-05-22T16:10:05.676Z,1369239005.676 [Default:F.Wait] Stopped
2013-05-22T16:10:05.676Z,1369239005.676 [Default:F.Wait](DEBUG): Uninitialize Wait Component.
2013-05-22T16:10:05.680Z,1369239005.681 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2013-05-22T16:10:05.681Z,1369239005.681 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2013-05-22T16:10:05.681Z,1369239005.681 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2013-05-22T16:10:05.682Z,1369239005.682 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2013-05-22T16:10:05.682Z,1369239005.682 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2013-05-22T16:10:05.682Z,1369239005.682 [BuoyancyServo](INFO): Powering down
2013-05-22T16:10:05.693Z,1369239005.694 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2013-05-22T16:10:05.694Z,1369239005.694 [ElevatorServo](INFO): Powering down
2013-05-22T16:10:05.695Z,1369239005.694 [MassServo](DEBUG): Uninitialize Mass Servo.
2013-05-22T16:10:05.695Z,1369239005.695 [MassServo](INFO): Powering down
2013-05-22T16:10:05.695Z,1369239005.695 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2013-05-22T16:10:05.696Z,1369239005.695 [RudderServo](INFO): Powering down
2013-05-22T16:10:05.696Z,1369239005.696 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2013-05-22T16:10:05.697Z,1369239005.697 [ThrusterServo](INFO): Powering down
2013-05-22T16:10:05.697Z,1369239005.697 [SBIT](DEBUG): Uninitialize SBIT Component.
2013-05-22T16:10:05.698Z,1369239005.698 [IBIT](DEBUG): Uninitialize IBIT Component.
2013-05-22T16:10:05.698Z,1369239005.698 [CBIT](DEBUG): Uninitialize CBIT Component.