2013-03-03T22:54:20.549Z,1362351260.549 [Supervisor](DEBUG): Initializing supervisor.
2013-03-03T22:54:20.552Z,1362351260.552 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0
2013-03-03T22:54:20.553Z,1362351260.553 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2013-03-03T22:54:20.554Z,1362351260.554 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0
2013-03-03T22:54:20.558Z,1362351260.557 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2013-03-03T22:54:20.568Z,1362351260.568 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2013-03-03T22:54:20.569Z,1362351260.569 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0
2013-03-03T22:54:20.570Z,1362351260.570 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2013-03-03T22:54:20.571Z,1362351260.571 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0
2013-03-03T22:54:20.572Z,1362351260.572 [Supervisor](INFO): Looking for Config files in directory: Config/
2013-03-03T22:54:20.573Z,1362351260.573 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2013-03-03T22:54:20.853Z,1362351260.853 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2013-03-03T22:54:20.854Z,1362351260.854 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2013-03-03T22:54:21.041Z,1362351261.041 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2013-03-03T22:54:21.041Z,1362351261.041 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2013-03-03T22:54:21.126Z,1362351261.126 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2013-03-03T22:54:21.127Z,1362351261.127 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2013-03-03T22:54:21.328Z,1362351261.328 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2013-03-03T22:54:21.329Z,1362351261.329 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2013-03-03T22:54:21.461Z,1362351261.461 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2013-03-03T22:54:21.462Z,1362351261.462 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2013-03-03T22:54:21.707Z,1362351261.707 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2013-03-03T22:54:21.708Z,1362351261.708 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2013-03-03T22:54:22.280Z,1362351262.280 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2013-03-03T22:54:22.280Z,1362351262.280 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2013-03-03T22:54:22.530Z,1362351262.530 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2013-03-03T22:54:22.531Z,1362351262.531 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2013-03-03T22:54:22.630Z,1362351262.630 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2013-03-03T22:54:22.630Z,1362351262.630 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2013-03-03T22:54:23.038Z,1362351263.039 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2013-03-03T22:54:23.039Z,1362351263.039 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2013-03-03T22:54:23.154Z,1362351263.154 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2013-03-03T22:54:23.154Z,1362351263.154 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2013-03-03T22:54:23.240Z,1362351263.240 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2013-03-03T22:54:23.241Z,1362351263.241 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2013-03-03T22:54:23.343Z,1362351263.343 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2013-03-03T22:54:23.471Z,1362351263.471 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2013-03-03T22:54:23.557Z,1362351263.557 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2013-03-03T22:54:23.659Z,1362351263.658 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2013-03-03T22:54:23.760Z,1362351263.760 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2013-03-03T22:54:23.879Z,1362351263.879 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2013-03-03T22:54:23.973Z,1362351263.973 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2013-03-03T22:54:24.061Z,1362351264.061 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2013-03-03T22:54:24.091Z,1362351264.091 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2013-03-03T22:54:24.244Z,1362351264.244 [InternalSim] Loaded
2013-03-03T22:54:24.244Z,1362351264.244 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2013-03-03T22:54:24.245Z,1362351264.245 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2013-03-03T22:54:24.246Z,1362351264.246 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2013-03-03T22:54:24.303Z,1362351264.303 [SBIT](DEBUG): Construct Startup Built In Test.
2013-03-03T22:54:24.331Z,1362351264.331 [SBIT] Loaded
2013-03-03T22:54:24.332Z,1362351264.332 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2013-03-03T22:54:24.333Z,1362351264.333 [IBIT](DEBUG): Construct Initiated Built In Test.
2013-03-03T22:54:24.362Z,1362351264.362 [IBIT] Loaded
2013-03-03T22:54:24.362Z,1362351264.362 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2013-03-03T22:54:24.365Z,1362351264.365 [CBIT](DEBUG): Construct CBIT Built In Test.
2013-03-03T22:54:24.486Z,1362351264.486 [CBIT] Loaded
2013-03-03T22:54:24.486Z,1362351264.486 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2013-03-03T22:54:24.487Z,1362351264.487 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2013-03-03T22:54:24.487Z,1362351264.487 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2013-03-03T22:54:24.636Z,1362351264.636 [BuoyancyServo] Loaded
2013-03-03T22:54:24.636Z,1362351264.636 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2013-03-03T22:54:24.649Z,1362351264.649 [ElevatorServo] Loaded
2013-03-03T22:54:24.649Z,1362351264.649 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2013-03-03T22:54:24.661Z,1362351264.661 [MassServo] Loaded
2013-03-03T22:54:24.661Z,1362351264.661 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2013-03-03T22:54:24.673Z,1362351264.673 [RudderServo] Loaded
2013-03-03T22:54:24.674Z,1362351264.674 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2013-03-03T22:54:24.685Z,1362351264.685 [ThrusterServo] Loaded
2013-03-03T22:54:24.685Z,1362351264.685 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2013-03-03T22:54:24.686Z,1362351264.686 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2013-03-03T22:54:24.686Z,1362351264.686 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2013-03-03T22:54:24.703Z,1362351264.703 [DepthRateCalculator] Loaded
2013-03-03T22:54:24.703Z,1362351264.703 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2013-03-03T22:54:28.227Z,1362351268.227 [HFRadarModelCalc] Loaded
2013-03-03T22:54:28.228Z,1362351268.227 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2013-03-03T22:54:28.244Z,1362351268.244 [NavChart] Loaded
2013-03-03T22:54:28.244Z,1362351268.244 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2013-03-03T22:54:28.250Z,1362351268.250 [PitchRateCalculator] Loaded
2013-03-03T22:54:28.250Z,1362351268.250 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2013-03-03T22:54:28.257Z,1362351268.257 [SpeedCalculator] Loaded
2013-03-03T22:54:28.257Z,1362351268.257 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2013-03-03T22:54:28.272Z,1362351268.272 [TempGradientCalculator] Loaded
2013-03-03T22:54:28.273Z,1362351268.273 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2013-03-03T22:54:28.279Z,1362351268.279 [YawRateCalculator] Loaded
2013-03-03T22:54:28.279Z,1362351268.279 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2013-03-03T22:54:28.320Z,1362351268.320 [Navigation] Loaded
2013-03-03T22:54:28.320Z,1362351268.320 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread.
2013-03-03T22:54:28.320Z,1362351268.320 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2013-03-03T22:54:28.321Z,1362351268.321 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2013-03-03T22:54:28.545Z,1362351268.545 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2013-03-03T22:54:28.546Z,1362351268.546 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2013-03-03T22:54:28.567Z,1362351268.567 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2013-03-03T22:54:28.568Z,1362351268.568 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2013-03-03T22:54:28.607Z,1362351268.607 [VerticalControl](DEBUG): Construct VerticalControl.
2013-03-03T22:54:28.701Z,1362351268.701 [VerticalControl] Loaded
2013-03-03T22:54:28.702Z,1362351268.702 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2013-03-03T22:54:28.703Z,1362351268.703 [HorizontalControl](DEBUG): Construct HorizontalControl.
2013-03-03T22:54:28.760Z,1362351268.760 [HorizontalControl] Loaded
2013-03-03T22:54:28.760Z,1362351268.760 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2013-03-03T22:54:28.761Z,1362351268.761 [SpeedControl](DEBUG): Construct SpeedControl.
2013-03-03T22:54:28.763Z,1362351268.763 [SpeedControl] Loaded
2013-03-03T22:54:28.763Z,1362351268.763 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2013-03-03T22:54:28.764Z,1362351268.764 [LoopControl](DEBUG): Construct LoopControl.
2013-03-03T22:54:28.765Z,1362351268.764 [LoopControl] Loaded
2013-03-03T22:54:28.765Z,1362351268.765 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2013-03-03T22:54:28.765Z,1362351268.765 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2013-03-03T22:54:28.766Z,1362351268.766 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2013-03-03T22:54:28.771Z,1362351268.772 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator.
2013-03-03T22:54:28.776Z,1362351268.776 [AsyncPiEstimator] Loaded
2013-03-03T22:54:28.777Z,1362351268.777 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread.
2013-03-03T22:54:28.778Z,1362351268.778 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406A44E0
2013-03-03T22:54:28.779Z,1362351268.779 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2013-03-03T22:54:28.779Z,1362351268.779 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2013-03-03T22:54:28.906Z,1362351268.906 [AHRS_sp3003D] Loaded
2013-03-03T22:54:28.906Z,1362351268.906 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2013-03-03T22:54:29.213Z,1362351269.214 [Batt_Ocean_Server] Loaded
2013-03-03T22:54:29.214Z,1362351269.214 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2013-03-03T22:54:29.228Z,1362351269.228 [Depth_Keller] Loaded
2013-03-03T22:54:29.228Z,1362351269.228 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2013-03-03T22:54:29.234Z,1362351269.234 [DropWeight] Loaded
2013-03-03T22:54:29.234Z,1362351269.234 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2013-03-03T22:54:29.411Z,1362351269.411 [DVL_micro] Loaded
2013-03-03T22:54:29.412Z,1362351269.411 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread.
2013-03-03T22:54:29.413Z,1362351269.413 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 407284E0
2013-03-03T22:54:29.497Z,1362351269.497 [NAL9602] Loaded
2013-03-03T22:54:29.498Z,1362351269.498 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2013-03-03T22:54:29.548Z,1362351269.548 [Onboard] Loaded
2013-03-03T22:54:29.548Z,1362351269.548 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2013-03-03T22:54:29.555Z,1362351269.555 [Radio_Freewave] Loaded
2013-03-03T22:54:29.556Z,1362351269.556 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread.
2013-03-03T22:54:29.557Z,1362351269.556 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2013-03-03T22:54:29.557Z,1362351269.557 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2013-03-03T22:54:29.613Z,1362351269.613 [Aanderaa_O2] Loaded
2013-03-03T22:54:29.613Z,1362351269.613 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2013-03-03T22:54:29.647Z,1362351269.647 [CTD_NeilBrown] Loaded
2013-03-03T22:54:29.647Z,1362351269.647 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2013-03-03T22:54:29.648Z,1362351269.648 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4077A4E0
2013-03-03T22:54:29.661Z,1362351269.661 [ISUS] Loaded
2013-03-03T22:54:29.662Z,1362351269.662 [ComponentRegistry](DEBUG): SyncComponent "ISUS" handled in the control thread.
2013-03-03T22:54:29.677Z,1362351269.677 [PAR_Licor] Loaded
2013-03-03T22:54:29.678Z,1362351269.678 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2013-03-03T22:54:29.708Z,1362351269.708 [WetLabsBB2FL] Loaded
2013-03-03T22:54:29.708Z,1362351269.708 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2013-03-03T22:54:29.709Z,1362351269.709 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407AA4E0
2013-03-03T22:54:29.710Z,1362351269.710 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2013-03-03T22:54:29.712Z,1362351269.712 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2013-03-03T22:54:29.713Z,1362351269.713 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2013-03-03T22:54:29.720Z,1362351269.720 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2013-03-03T22:54:29.721Z,1362351269.721 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 407DA4E0
2013-03-03T22:54:29.725Z,1362351269.725 [Supervisor](DEBUG): Running supervisor.
2013-03-03T22:54:29.726Z,1362351269.726 [CommandLine](INFO): Thread ID is 901
2013-03-03T22:54:29.729Z,1362351269.729 [controlThread](INFO): Thread ID is 900
2013-03-03T22:54:29.729Z,1362351269.729 [controlThread](DEBUG): Initializing ControlThread
2013-03-03T22:54:29.730Z,1362351269.730 [CycleStarter](INFO): Thread ID is 899
2013-03-03T22:54:29.730Z,1362351269.730 [InternalSim](DEBUG):  InternalSim initializing...
2013-03-03T22:54:29.763Z,1362351269.763 [logger](INFO): Thread ID is 902
2013-03-03T22:54:29.793Z,1362351269.793 [SBIT](INFO): Initialize SBIT Component.
2013-03-03T22:54:29.793Z,1362351269.793 [SBIT](IMPORTANT): Tethys CM Info:
$Rev: 10204
2013-03-03T22:54:29.794Z,1362351269.794 [IBIT](INFO): Initialize IBIT Component.
2013-03-03T22:54:29.795Z,1362351269.795 [CBIT](DEBUG): Initialize CBIT Component.
2013-03-03T22:54:29.795Z,1362351269.795 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2013-03-03T22:54:29.807Z,1362351269.807 [AsyncPiEstimator](INFO): Thread ID is 963
2013-03-03T22:54:29.808Z,1362351269.807 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator.
2013-03-03T22:54:29.820Z,1362351269.820 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2013-03-03T22:54:29.820Z,1362351269.820 [NavChart](DEBUG): Initialize NavChart Derivation.
2013-03-03T22:54:29.821Z,1362351269.821 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2013-03-03T22:54:29.821Z,1362351269.821 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2013-03-03T22:54:29.822Z,1362351269.822 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2013-03-03T22:54:29.823Z,1362351269.823 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2013-03-03T22:54:29.823Z,1362351269.823 [Navigation](DEBUG): Initializing Navigation.
2013-03-03T22:54:29.824Z,1362351269.824 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2013-03-03T22:54:29.826Z,1362351269.826 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2013-03-03T22:54:29.826Z,1362351269.826 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2013-03-03T22:54:29.827Z,1362351269.827 [LoopControl](DEBUG): Initialize LoopControlComponent.
2013-03-03T22:54:29.831Z,1362351269.831 [DVL_micro](INFO): Thread ID is 965
2013-03-03T22:54:29.840Z,1362351269.840 [DVL_micro](INFO): Initializing
2013-03-03T22:54:29.841Z,1362351269.841 [DVL_micro](INFO): start:Powering up
2013-03-03T22:54:29.841Z,1362351269.841 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-03-03T22:54:29.842Z,1362351269.842 [DVL_micro](INFO): Cycling power to configure device.
2013-03-03T22:54:29.856Z,1362351269.856 [CTD_NeilBrown](INFO): Thread ID is 966
2013-03-03T22:54:29.856Z,1362351269.856 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2013-03-03T22:54:29.859Z,1362351269.859 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2013-03-03T22:54:29.875Z,1362351269.875 [WetLabsBB2FL](INFO): Thread ID is 967
2013-03-03T22:54:29.876Z,1362351269.876 [WetLabsBB2FL](INFO): Powering down
2013-03-03T22:54:29.908Z,1362351269.908 [NavChartDb](INFO): Thread ID is 968
2013-03-03T22:54:29.910Z,1362351269.910 [NavChartDb](FAULT): Change detected in ENC collection. Wiping NavChart Directory
2013-03-03T22:54:29.914Z,1362351269.914 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2013-03-03T22:54:29.915Z,1362351269.915 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA50M.000
2013-03-03T22:54:29.917Z,1362351269.917 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US2WC11M.000
2013-03-03T22:54:29.919Z,1362351269.919 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US1WC07M.000
2013-03-03T22:54:29.921Z,1362351269.921 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US3CA52M.000
2013-03-03T22:54:29.923Z,1362351269.923 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA61M.000
2013-03-03T22:54:29.924Z,1362351269.924 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA83M.000
2013-03-03T22:54:29.926Z,1362351269.926 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA62M.000
2013-03-03T22:54:29.937Z,1362351269.937 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4CA60M.000
2013-03-03T22:54:30.115Z,1362351270.115 [NavChartDb](INFO): Setup scan of Resources/US5CA62M.000
2013-03-03T22:54:31.684Z,1362351271.684 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2013-03-03T22:54:31.721Z,1362351271.721 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2013-03-03T22:54:31.733Z,1362351271.733 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2013-03-03T22:54:31.743Z,1362351271.743 [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-03-03T22:54:31.744Z,1362351271.744 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2013-03-03T22:54:31.797Z,1362351271.797 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2013-03-03T22:54:31.803Z,1362351271.803 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2013-03-03T22:54:31.813Z,1362351271.813 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-03-03T22:54:31.825Z,1362351271.825 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2013-03-03T22:54:31.828Z,1362351271.828 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-03-03T22:54:31.835Z,1362351271.835 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2013-03-03T22:54:31.844Z,1362351271.844 [Default:D.SetSpeed](DEBUG): Construct.
2013-03-03T22:54:31.847Z,1362351271.847 [Default:E.GoToSurface](DEBUG): Construct GoToSurface.
2013-03-03T22:54:31.851Z,1362351271.852 [Default:F.Wait](DEBUG): Construct Wait.
2013-03-03T22:54:31.855Z,1362351271.855 [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-03-03T22:54:31.860Z,1362351271.860 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,NAL9602,Onboard,Radio_Freewave,Aanderaa_O2,ISUS,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,
2013-03-03T22:54:31.920Z,1362351271.920 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-03-03T22:54:31.935Z,1362351271.935 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-03-03T22:54:31.936Z,1362351271.935 [DVL_micro](INFO): Querying output modes
2013-03-03T22:54:31.936Z,1362351271.936 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-03-03T22:54:31.947Z,1362351271.947 [DVL_micro](DEBUG): cmdResponse: 01 03 16
2013-03-03T22:54:31.947Z,1362351271.947 [DVL_micro](INFO): NQ1 output enabled
2013-03-03T22:54:31.947Z,1362351271.947 [DVL_micro](INFO): RSSI output enabled
2013-03-03T22:54:31.947Z,1362351271.947 [DVL_micro](INFO): ADCP output enabled
2013-03-03T22:54:31.947Z,1362351271.947 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-03-03T22:54:31.959Z,1362351271.959 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 
2013-03-03T22:54:31.964Z,1362351271.964 [DVL_micro](INFO): pause:Powering down
2013-03-03T22:54:32.062Z,1362351272.062 [Radio_Freewave](INFO): Powering up
2013-03-03T22:54:32.335Z,1362351272.335 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2013-03-03T22:54:32.336Z,1362351272.336 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2013-03-03T22:54:32.343Z,1362351272.343 [ElevatorServo](DEBUG): Initializing EZServoServo.
2013-03-03T22:54:32.343Z,1362351272.343 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2013-03-03T22:54:32.350Z,1362351272.350 [MassServo](DEBUG): Initializing EZServoServo.
2013-03-03T22:54:32.351Z,1362351272.351 [MassServo](DEBUG): Initializing MassServo.
2013-03-03T22:54:32.356Z,1362351272.356 [RudderServo](DEBUG): Initializing EZServoServo.
2013-03-03T22:54:32.357Z,1362351272.357 [RudderServo](DEBUG): Initializing RudderServo.
2013-03-03T22:54:32.363Z,1362351272.363 [ThrusterServo](DEBUG): Initializing EZServoServo.
2013-03-03T22:54:32.364Z,1362351272.364 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2013-03-03T22:54:34.463Z,1362351274.463 [Aanderaa_O2](INFO): Powering down
2013-03-03T22:54:34.777Z,1362351274.777 [NAL9602](INFO): Powering up NAL9602
2013-03-03T22:54:45.371Z,1362351285.371 [NAL9602](INFO): NAL9602 initialized
2013-03-03T22:54:45.424Z,1362351285.424 [SBIT](IMPORTANT): Beginning Startup BIT
2013-03-03T22:54:45.427Z,1362351285.427 [CBIT](IMPORTANT): Beginning GF scan
2013-03-03T22:55:12.186Z,1362351312.186 [CBIT](FAULT): Chan 4 High side GF detected
mA:
CHAN 5 (24V): 0.030513
CHAN 4 (Batt): 0.009183
CHAN 2 (12V): 0.003061
CHAN 1 (5V): 0.000670
CHAN 0 (3.3V): 0.000574
OPEN: 0.000574
Full Scale Calc: 0.392
2013-03-03T22:55:39.109Z,1362351339.109 [SBIT](IMPORTANT): SBIT PASSED
2013-03-03T22:55:39.519Z,1362351339.519 [MissionManager](IMPORTANT): Started mission Startup
2013-03-03T22:55:39.519Z,1362351339.519 [Startup] Running Loop=1
2013-03-03T22:55:39.519Z,1362351339.519 [Startup](INFO): Aggregate::initialize Startup
2013-03-03T22:55:39.520Z,1362351339.520 [Startup:A.GoToSurface] Running Loop=1
2013-03-03T22:55:39.520Z,1362351339.520 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-03T22:55:39.525Z,1362351339.526 [Startup:StartupSatComms] Running Loop=1
2013-03-03T22:55:39.526Z,1362351339.526 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2013-03-03T22:55:39.526Z,1362351339.526 [Startup:StartupSatComms:A] Running Loop=1
2013-03-03T22:55:39.923Z,1362351339.923 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2013-03-03T22:55:51.875Z,1362351351.875 [NAL9602](IMPORTANT): GPS fix at: 1362351352.00
2013-03-03T22:55:51.891Z,1362351351.891 [Startup:StartupSatComms:A] Stopped
2013-03-03T22:55:51.891Z,1362351351.891 [Startup:StartupSatComms:B] Running Loop=1
2013-03-03T22:55:52.307Z,1362351352.307 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2013-03-03T22:56:40.193Z,1362351400.193 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=6075, MT Status=1, MTMSN=481
2013-03-03T22:56:40.243Z,1362351400.243 [NAL9602](INFO): Sent 332 bytes from file Logs/20130302T231750/shore0000.lzma
2013-03-03T22:56:40.243Z,1362351400.243 [NAL9602](INFO): Packets left to send: 2
2013-03-03T22:56:40.245Z,1362351400.245 [NAL9602](INFO): Stored copy of sent data in Logs/20130302T231750/shore0000.lzma.parts/0002.sbd
2013-03-03T22:56:40.703Z,1362351400.703 [NAL9602](INFO): Received command:Lets see if she is talking to us...
2013-03-03T22:56:40.743Z,1362351400.743 [CommandLine](IMPORTANT): got command load 
2013-03-03T22:56:40.743Z,1362351400.743 [CommandLine](FAULT): Incomplete syntax. Try: help load
2013-03-03T22:56:48.753Z,1362351408.753 [NAL9602](INFO): SBD MO Status=2, MOMSN=6076, MT Status=2, MTMSN=0
2013-03-03T22:56:48.754Z,1362351408.754 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-03-03T22:56:51.963Z,1362351411.963 [Startup:StartupSatComms:B](INFO): Timed out from 2013-03-03T22:55:51.9Z
2013-03-03T22:56:51.963Z,1362351411.963 [Startup:StartupSatComms:B:A_Timeout] Running Loop=1
2013-03-03T22:56:51.964Z,1362351411.964 [Startup:StartupSatComms:B:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:B:A_Timeout
2013-03-03T22:56:51.964Z,1362351411.964 [Startup:StartupSatComms:B:A_Timeout](INFO): Completed Startup:StartupSatComms:B:A_Timeout
2013-03-03T22:56:51.964Z,1362351411.964 [Startup:StartupSatComms:B] Stopped
2013-03-03T22:56:51.964Z,1362351411.964 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2013-03-03T22:56:51.964Z,1362351411.964 [Startup:StartupSatComms] Stopped
2013-03-03T22:56:51.964Z,1362351411.964 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2013-03-03T22:56:51.965Z,1362351411.965 [Startup](INFO): Completed Startup
2013-03-03T22:56:51.965Z,1362351411.965 [Startup] Stopped
2013-03-03T22:56:51.965Z,1362351411.965 [Startup](INFO): Aggregate::uninitialize Startup
2013-03-03T22:56:51.965Z,1362351411.965 [Startup:A.GoToSurface] Stopped
2013-03-03T22:56:51.965Z,1362351411.966 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-03T22:56:52.399Z,1362351412.399 [MissionManager](IMPORTANT): Started mission Default
2013-03-03T22:56:52.400Z,1362351412.399 [Default] Running Loop=1
2013-03-03T22:56:52.400Z,1362351412.400 [Default](INFO): Aggregate::initialize Default
2013-03-03T22:56:52.400Z,1362351412.400 [Default:D.SetSpeed] Running Loop=1
2013-03-03T22:56:52.400Z,1362351412.400 [Default:D.SetSpeed](DEBUG): Initialize.
2013-03-03T22:56:52.400Z,1362351412.400 [Default:E.GoToSurface] Running Loop=1
2013-03-03T22:56:52.400Z,1362351412.400 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-03T22:56:52.400Z,1362351412.400 [Default:Iridium] Running Loop=1
2013-03-03T22:56:52.400Z,1362351412.400 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-03-03T22:56:52.400Z,1362351412.401 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-03T22:56:52.401Z,1362351412.401 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-03-03T22:56:52.401Z,1362351412.401 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-03-03T22:56:52.401Z,1362351412.401 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-03T22:56:52.401Z,1362351412.401 [Default:E.GoToSurface] Running Loop=1
2013-03-03T22:56:52.407Z,1362351412.407 [Default:D.SetSpeed] Running Loop=1
2013-03-03T22:56:52.412Z,1362351412.412 [Default:CallIridium] Running Loop=1
2013-03-03T22:56:52.412Z,1362351412.412 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-03-03T22:56:52.412Z,1362351412.412 [Default:CallIridium:A] Running Loop=1
2013-03-03T22:56:52.414Z,1362351412.414 [Default:CallIridium:A] Stopped
2013-03-03T22:56:52.414Z,1362351412.414 [Default:CallIridium:B] Running Loop=1
2013-03-03T22:56:52.415Z,1362351412.415 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-03-03T22:56:52.421Z,1362351412.421 [Default:Iridium:B.GoToSurface] Stopped
2013-03-03T22:56:52.421Z,1362351412.421 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-03T22:56:52.421Z,1362351412.421 [Default:Iridium:Read_Iridium] Running Loop=1
2013-03-03T22:56:52.421Z,1362351412.421 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-03T22:56:52.426Z,1362351412.426 [Default:GPS] Running Loop=1
2013-03-03T22:56:52.426Z,1362351412.426 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-03-03T22:56:52.426Z,1362351412.426 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-03T22:56:52.426Z,1362351412.426 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-03-03T22:56:52.427Z,1362351412.427 [Default:GPS:B.GoToSurface] Running Loop=1
2013-03-03T22:56:52.427Z,1362351412.427 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-03T22:56:52.433Z,1362351412.433 [Default:GPS:B.GoToSurface] Stopped
2013-03-03T22:56:52.433Z,1362351412.433 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-03T22:56:52.433Z,1362351412.433 [Default:GPS:Read_GPS] Running Loop=1
2013-03-03T22:56:52.433Z,1362351412.433 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-03T22:56:52.763Z,1362351412.763 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2013-03-03T22:56:52.766Z,1362351412.766 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2013-03-03T22:56:56.977Z,1362351416.977 [NAL9602](INFO): SBD MO Status=2, MOMSN=6076, MT Status=2, MTMSN=0
2013-03-03T22:56:56.978Z,1362351416.978 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-03-03T22:56:58.183Z,1362351418.183 [NAL9602](IMPORTANT): GPS fix at: 1362351418.00
2013-03-03T22:56:58.200Z,1362351418.200 [Default:GPS:Read_GPS] Stopped
2013-03-03T22:56:58.200Z,1362351418.200 [Default:GPS:D] Running Loop=1
2013-03-03T22:56:58.614Z,1362351418.614 [Default:GPS:D] Stopped
2013-03-03T22:56:58.615Z,1362351418.615 [Default:GPS](INFO): Completed Default:GPS
2013-03-03T22:56:58.615Z,1362351418.615 [Default:GPS] Stopped
2013-03-03T22:56:58.615Z,1362351418.615 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-03-03T22:56:58.616Z,1362351418.616 [Default:GPS:A.SetSpeed] Stopped
2013-03-03T22:56:58.616Z,1362351418.616 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-03-03T22:57:09.129Z,1362351429.129 [NAL9602](INFO): SBD MO Status=1, MOMSN=6076, MT Status=0, MTMSN=0
2013-03-03T22:57:09.187Z,1362351429.187 [NAL9602](INFO): Sent 332 bytes from file Logs/20130302T231750/shore0000.lzma
2013-03-03T22:57:09.187Z,1362351429.187 [NAL9602](INFO): Packets left to send: 1
2013-03-03T22:57:09.188Z,1362351429.188 [NAL9602](INFO): Stored copy of sent data in Logs/20130302T231750/shore0000.lzma.parts/0001.sbd
2013-03-03T22:57:16.964Z,1362351436.964 [NAL9602](INFO): SBD MO Status=2, MOMSN=6077, MT Status=2, MTMSN=0
2013-03-03T22:57:16.964Z,1362351436.964 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-03-03T22:57:25.577Z,1362351445.577 [NAL9602](INFO): SBD MO Status=2, MOMSN=6077, MT Status=2, MTMSN=0
2013-03-03T22:57:25.577Z,1362351445.577 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-03-03T22:57:36.181Z,1362351456.181 [NAL9602](INFO): SBD MO Status=1, MOMSN=6077, MT Status=0, MTMSN=0
2013-03-03T22:57:36.231Z,1362351456.231 [NAL9602](INFO): Sent 20 bytes from file Logs/20130302T231750/shore0000.lzma
2013-03-03T22:57:36.231Z,1362351456.231 [NAL9602](INFO): Packets left to send: 0
2013-03-03T22:57:36.232Z,1362351456.232 [NAL9602](INFO): Stored copy of sent data in Logs/20130302T231750/shore0000.lzma.parts/0000.sbd
2013-03-03T22:57:45.278Z,1362351465.278 [NAL9602](INFO): SBD MO Status=1, MOMSN=6078, MT Status=0, MTMSN=0
2013-03-03T22:57:45.327Z,1362351465.327 [NAL9602](INFO): Sent 85 bytes from file Logs/20130302T231750/shore0001.lzma
2013-03-03T22:57:45.327Z,1362351465.327 [NAL9602](INFO): Packets left to send: 0
2013-03-03T22:57:45.329Z,1362351465.329 [NAL9602](INFO): Stored copy of sent data in Logs/20130302T231750/shore0001.lzma.parts/0000.sbd
2013-03-03T22:57:57.048Z,1362351477.048 [NAL9602](INFO): SBD MO Status=1, MOMSN=6079, MT Status=0, MTMSN=0
2013-03-03T22:57:57.099Z,1362351477.099 [NAL9602](INFO): Sent 291 bytes from file Logs/20130302T232149/shore0000.lzma
2013-03-03T22:57:57.099Z,1362351477.099 [NAL9602](INFO): Packets left to send: 0
2013-03-03T22:57:57.101Z,1362351477.101 [NAL9602](INFO): Stored copy of sent data in Logs/20130302T232149/shore0000.lzma.parts/0000.sbd
2013-03-03T22:58:05.738Z,1362351485.738 [NAL9602](INFO): SBD MO Status=1, MOMSN=6080, MT Status=0, MTMSN=0
2013-03-03T22:58:05.791Z,1362351485.791 [NAL9602](INFO): Sent 332 bytes from file Logs/20130302T232654/shore0000.lzma
2013-03-03T22:58:05.791Z,1362351485.791 [NAL9602](INFO): Packets left to send: 1
2013-03-03T22:58:05.793Z,1362351485.793 [NAL9602](INFO): Stored copy of sent data in Logs/20130302T232654/shore0000.lzma.parts/0001.sbd
2013-03-03T22:58:14.358Z,1362351494.358 [NAL9602](INFO): SBD MO Status=1, MOMSN=6081, MT Status=0, MTMSN=0
2013-03-03T22:58:14.411Z,1362351494.411 [NAL9602](INFO): Sent 108 bytes from file Logs/20130302T232654/shore0000.lzma
2013-03-03T22:58:14.411Z,1362351494.411 [NAL9602](INFO): Packets left to send: 0
2013-03-03T22:58:14.412Z,1362351494.412 [NAL9602](INFO): Stored copy of sent data in Logs/20130302T232654/shore0000.lzma.parts/0000.sbd
2013-03-03T22:58:36.230Z,1362351516.230 [NAL9602](INFO): SBD MO Status=2, MOMSN=6082, MT Status=0, MTMSN=0
2013-03-03T22:58:36.230Z,1362351516.230 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-03-03T22:58:55.525Z,1362351535.525 [NAL9602](INFO): SBD MO Status=1, MOMSN=6082, MT Status=0, MTMSN=0
2013-03-03T22:58:55.575Z,1362351535.575 [NAL9602](INFO): Sent 332 bytes from file Logs/20130302T234509/shore0000.lzma
2013-03-03T22:58:55.575Z,1362351535.575 [NAL9602](INFO): Packets left to send: 3
2013-03-03T22:58:55.577Z,1362351535.577 [NAL9602](INFO): Stored copy of sent data in Logs/20130302T234509/shore0000.lzma.parts/0003.sbd
2013-03-03T22:59:04.660Z,1362351544.660 [NAL9602](INFO): SBD MO Status=1, MOMSN=6083, MT Status=0, MTMSN=0
2013-03-03T22:59:04.711Z,1362351544.711 [NAL9602](INFO): Sent 332 bytes from file Logs/20130302T234509/shore0000.lzma
2013-03-03T22:59:04.711Z,1362351544.711 [NAL9602](INFO): Packets left to send: 2
2013-03-03T22:59:04.712Z,1362351544.712 [NAL9602](INFO): Stored copy of sent data in Logs/20130302T234509/shore0000.lzma.parts/0002.sbd
2013-03-03T22:59:15.697Z,1362351555.697 [NAL9602](INFO): SBD MO Status=1, MOMSN=6084, MT Status=0, MTMSN=0
2013-03-03T22:59:15.747Z,1362351555.747 [NAL9602](INFO): Sent 332 bytes from file Logs/20130302T234509/shore0000.lzma
2013-03-03T22:59:15.747Z,1362351555.747 [NAL9602](INFO): Packets left to send: 1
2013-03-03T22:59:15.748Z,1362351555.748 [NAL9602](INFO): Stored copy of sent data in Logs/20130302T234509/shore0000.lzma.parts/0001.sbd
2013-03-03T22:59:22.377Z,1362351562.377 [NAL9602](INFO): SBD MO Status=1, MOMSN=6085, MT Status=0, MTMSN=0
2013-03-03T22:59:22.427Z,1362351562.427 [NAL9602](INFO): Sent 11 bytes from file Logs/20130302T234509/shore0000.lzma
2013-03-03T22:59:22.427Z,1362351562.427 [NAL9602](INFO): Packets left to send: 0
2013-03-03T22:59:22.428Z,1362351562.428 [NAL9602](INFO): Stored copy of sent data in Logs/20130302T234509/shore0000.lzma.parts/0000.sbd
2013-03-03T22:59:33.817Z,1362351573.816 [NAL9602](INFO): SBD MO Status=1, MOMSN=6086, MT Status=0, MTMSN=0
2013-03-03T22:59:33.867Z,1362351573.867 [NAL9602](INFO): Sent 332 bytes from file Logs/20130302T234509/shore0001.lzma
2013-03-03T22:59:33.867Z,1362351573.867 [NAL9602](INFO): Packets left to send: 7
2013-03-03T22:59:33.869Z,1362351573.869 [NAL9602](INFO): Stored copy of sent data in Logs/20130302T234509/shore0001.lzma.parts/0007.sbd
2013-03-03T22:59:46.093Z,1362351586.093 [NAL9602](INFO): SBD MO Status=2, MOMSN=6087, MT Status=2, MTMSN=0
2013-03-03T22:59:46.094Z,1362351586.093 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-03-03T22:59:58.613Z,1362351598.613 [NAL9602](INFO): SBD MO Status=1, MOMSN=6087, MT Status=0, MTMSN=0
2013-03-03T22:59:58.663Z,1362351598.663 [NAL9602](INFO): Sent 332 bytes from file Logs/20130302T234509/shore0001.lzma
2013-03-03T22:59:58.663Z,1362351598.663 [NAL9602](INFO): Packets left to send: 6
2013-03-03T22:59:58.664Z,1362351598.664 [NAL9602](INFO): Stored copy of sent data in Logs/20130302T234509/shore0001.lzma.parts/0006.sbd
2013-03-03T23:00:08.090Z,1362351608.090 [NAL9602](INFO): SBD MO Status=1, MOMSN=6088, MT Status=0, MTMSN=0
2013-03-03T23:00:08.139Z,1362351608.139 [NAL9602](INFO): Sent 332 bytes from file Logs/20130302T234509/shore0001.lzma
2013-03-03T23:00:08.139Z,1362351608.139 [NAL9602](INFO): Packets left to send: 5
2013-03-03T23:00:08.140Z,1362351608.140 [NAL9602](INFO): Stored copy of sent data in Logs/20130302T234509/shore0001.lzma.parts/0005.sbd
2013-03-03T23:00:19.480Z,1362351619.480 [NAL9602](INFO): SBD MO Status=1, MOMSN=6089, MT Status=0, MTMSN=0
2013-03-03T23:00:19.527Z,1362351619.527 [NAL9602](INFO): Sent 332 bytes from file Logs/20130302T234509/shore0001.lzma
2013-03-03T23:00:19.527Z,1362351619.527 [NAL9602](INFO): Packets left to send: 4
2013-03-03T23:00:19.528Z,1362351619.528 [NAL9602](INFO): Stored copy of sent data in Logs/20130302T234509/shore0001.lzma.parts/0004.sbd
2013-03-03T23:00:27.323Z,1362351627.323 [NAL9602](INFO): SBD MO Status=1, MOMSN=6090, MT Status=0, MTMSN=0
2013-03-03T23:00:27.373Z,1362351627.373 [NAL9602](INFO): Sent 332 bytes from file Logs/20130302T234509/shore0001.lzma
2013-03-03T23:00:27.373Z,1362351627.373 [NAL9602](INFO): Packets left to send: 3
2013-03-03T23:00:27.374Z,1362351627.374 [NAL9602](INFO): Stored copy of sent data in Logs/20130302T234509/shore0001.lzma.parts/0003.sbd
2013-03-03T23:00:36.817Z,1362351636.817 [NAL9602](INFO): SBD MO Status=1, MOMSN=6091, MT Status=0, MTMSN=0
2013-03-03T23:00:36.873Z,1362351636.873 [NAL9602](INFO): Sent 332 bytes from file Logs/20130302T234509/shore0001.lzma
2013-03-03T23:00:36.873Z,1362351636.874 [NAL9602](INFO): Packets left to send: 2
2013-03-03T23:00:36.875Z,1362351636.875 [NAL9602](INFO): Stored copy of sent data in Logs/20130302T234509/shore0001.lzma.parts/0002.sbd
2013-03-03T23:00:44.253Z,1362351644.253 [NAL9602](INFO): SBD MO Status=1, MOMSN=6092, MT Status=0, MTMSN=0
2013-03-03T23:00:44.303Z,1362351644.303 [NAL9602](INFO): Sent 332 bytes from file Logs/20130302T234509/shore0001.lzma
2013-03-03T23:00:44.303Z,1362351644.303 [NAL9602](INFO): Packets left to send: 1
2013-03-03T23:00:44.304Z,1362351644.304 [NAL9602](INFO): Stored copy of sent data in Logs/20130302T234509/shore0001.lzma.parts/0001.sbd
2013-03-03T23:00:50.113Z,1362351650.113 [NAL9602](INFO): SBD MO Status=1, MOMSN=6093, MT Status=0, MTMSN=0
2013-03-03T23:00:50.163Z,1362351650.163 [NAL9602](INFO): Sent 63 bytes from file Logs/20130302T234509/shore0001.lzma
2013-03-03T23:00:50.163Z,1362351650.163 [NAL9602](INFO): Packets left to send: 0
2013-03-03T23:00:50.164Z,1362351650.164 [NAL9602](INFO): Stored copy of sent data in Logs/20130302T234509/shore0001.lzma.parts/0000.sbd
2013-03-03T23:00:58.009Z,1362351658.009 [NAL9602](INFO): SBD MO Status=1, MOMSN=6094, MT Status=0, MTMSN=0
2013-03-03T23:00:58.059Z,1362351658.059 [NAL9602](INFO): Sent 332 bytes from file Logs/20130303T205234/shore0000.lzma
2013-03-03T23:00:58.059Z,1362351658.059 [NAL9602](INFO): Packets left to send: 2
2013-03-03T23:00:58.060Z,1362351658.060 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T205234/shore0000.lzma.parts/0002.sbd
2013-03-03T23:01:19.119Z,1362351679.119 [NAL9602](INFO): SBD MO Status=2, MOMSN=6095, MT Status=2, MTMSN=0
2013-03-03T23:01:19.119Z,1362351679.119 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-03-03T23:01:31.622Z,1362351691.622 [NAL9602](INFO): SBD MO Status=1, MOMSN=6095, MT Status=0, MTMSN=0
2013-03-03T23:01:31.673Z,1362351691.673 [NAL9602](INFO): Sent 332 bytes from file Logs/20130303T205234/shore0000.lzma
2013-03-03T23:01:31.673Z,1362351691.673 [NAL9602](INFO): Packets left to send: 1
2013-03-03T23:01:31.674Z,1362351691.674 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T205234/shore0000.lzma.parts/0001.sbd
2013-03-03T23:01:41.072Z,1362351701.072 [NAL9602](INFO): SBD MO Status=1, MOMSN=6096, MT Status=0, MTMSN=0
2013-03-03T23:01:41.119Z,1362351701.119 [NAL9602](INFO): Sent 128 bytes from file Logs/20130303T205234/shore0000.lzma
2013-03-03T23:01:41.119Z,1362351701.119 [NAL9602](INFO): Packets left to send: 0
2013-03-03T23:01:41.120Z,1362351701.120 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T205234/shore0000.lzma.parts/0000.sbd
2013-03-03T23:01:51.705Z,1362351711.705 [NAL9602](INFO): SBD MO Status=1, MOMSN=6097, MT Status=0, MTMSN=0
2013-03-03T23:01:51.755Z,1362351711.755 [NAL9602](INFO): Sent 332 bytes from file Logs/20130303T205708/shore0000.lzma
2013-03-03T23:01:51.755Z,1362351711.755 [NAL9602](INFO): Packets left to send: 2
2013-03-03T23:01:51.757Z,1362351711.757 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T205708/shore0000.lzma.parts/0002.sbd
2013-03-03T23:02:00.736Z,1362351720.736 [NAL9602](INFO): SBD MO Status=1, MOMSN=6098, MT Status=0, MTMSN=0
2013-03-03T23:02:00.787Z,1362351720.787 [NAL9602](INFO): Sent 332 bytes from file Logs/20130303T205708/shore0000.lzma
2013-03-03T23:02:00.787Z,1362351720.787 [NAL9602](INFO): Packets left to send: 1
2013-03-03T23:02:00.788Z,1362351720.788 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T205708/shore0000.lzma.parts/0001.sbd
2013-03-03T23:02:12.176Z,1362351732.176 [NAL9602](INFO): SBD MO Status=1, MOMSN=6099, MT Status=0, MTMSN=0
2013-03-03T23:02:12.227Z,1362351732.227 [NAL9602](INFO): Sent 76 bytes from file Logs/20130303T205708/shore0000.lzma
2013-03-03T23:02:12.227Z,1362351732.227 [NAL9602](INFO): Packets left to send: 0
2013-03-03T23:02:12.228Z,1362351732.228 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T205708/shore0000.lzma.parts/0000.sbd
2013-03-03T23:02:22.004Z,1362351742.004 [NAL9602](INFO): SBD MO Status=1, MOMSN=6100, MT Status=0, MTMSN=0
2013-03-03T23:02:22.051Z,1362351742.051 [NAL9602](INFO): Sent 239 bytes from file Logs/20130303T205708/shore0001.lzma
2013-03-03T23:02:22.051Z,1362351742.051 [NAL9602](INFO): Packets left to send: 0
2013-03-03T23:02:22.053Z,1362351742.053 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T205708/shore0001.lzma.parts/0000.sbd
2013-03-03T23:02:31.049Z,1362351751.049 [NAL9602](INFO): SBD MO Status=1, MOMSN=6101, MT Status=0, MTMSN=0
2013-03-03T23:02:31.099Z,1362351751.099 [NAL9602](INFO): Sent 332 bytes from file Logs/20130303T215152/shore0000.lzma
2013-03-03T23:02:31.099Z,1362351751.099 [NAL9602](INFO): Packets left to send: 2
2013-03-03T23:02:31.101Z,1362351751.101 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T215152/shore0000.lzma.parts/0002.sbd
2013-03-03T23:02:48.885Z,1362351768.885 [NAL9602](INFO): SBD MO Status=1, MOMSN=6102, MT Status=0, MTMSN=0
2013-03-03T23:02:48.935Z,1362351768.935 [NAL9602](INFO): Sent 332 bytes from file Logs/20130303T215152/shore0000.lzma
2013-03-03T23:02:48.935Z,1362351768.935 [NAL9602](INFO): Packets left to send: 1
2013-03-03T23:02:48.936Z,1362351768.936 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T215152/shore0000.lzma.parts/0001.sbd
2013-03-03T23:02:56.725Z,1362351776.725 [NAL9602](INFO): SBD MO Status=1, MOMSN=6103, MT Status=0, MTMSN=0
2013-03-03T23:02:56.775Z,1362351776.775 [NAL9602](INFO): Sent 123 bytes from file Logs/20130303T215152/shore0000.lzma
2013-03-03T23:02:56.775Z,1362351776.775 [NAL9602](INFO): Packets left to send: 0
2013-03-03T23:02:56.776Z,1362351776.776 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T215152/shore0000.lzma.parts/0000.sbd
2013-03-03T23:03:06.953Z,1362351786.953 [NAL9602](INFO): SBD MO Status=1, MOMSN=6104, MT Status=0, MTMSN=0
2013-03-03T23:03:07.003Z,1362351787.003 [NAL9602](INFO): Sent 332 bytes from file Logs/20130303T215408/shore0000.lzma
2013-03-03T23:03:07.003Z,1362351787.003 [NAL9602](INFO): Packets left to send: 2
2013-03-03T23:03:07.004Z,1362351787.004 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T215408/shore0000.lzma.parts/0002.sbd
2013-03-03T23:03:17.989Z,1362351797.989 [NAL9602](INFO): SBD MO Status=1, MOMSN=6105, MT Status=0, MTMSN=0
2013-03-03T23:03:18.039Z,1362351798.039 [NAL9602](INFO): Sent 332 bytes from file Logs/20130303T215408/shore0000.lzma
2013-03-03T23:03:18.039Z,1362351798.039 [NAL9602](INFO): Packets left to send: 1
2013-03-03T23:03:18.040Z,1362351798.040 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T215408/shore0000.lzma.parts/0001.sbd
2013-03-03T23:03:29.458Z,1362351809.458 [NAL9602](INFO): SBD MO Status=1, MOMSN=6106, MT Status=0, MTMSN=0
2013-03-03T23:03:29.516Z,1362351809.516 [NAL9602](INFO): Sent 116 bytes from file Logs/20130303T215408/shore0000.lzma
2013-03-03T23:03:29.516Z,1362351809.516 [NAL9602](INFO): Packets left to send: 0
2013-03-03T23:03:29.517Z,1362351809.517 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T215408/shore0000.lzma.parts/0000.sbd
2013-03-03T23:03:39.302Z,1362351819.302 [NAL9602](INFO): SBD MO Status=1, MOMSN=6107, MT Status=0, MTMSN=0
2013-03-03T23:03:39.351Z,1362351819.351 [NAL9602](INFO): Sent 60 bytes from file Logs/20130303T215408/shore0001.lzma
2013-03-03T23:03:39.351Z,1362351819.351 [NAL9602](INFO): Packets left to send: 0
2013-03-03T23:03:39.354Z,1362351819.353 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T215408/shore0001.lzma.parts/0000.sbd
2013-03-03T23:03:52.689Z,1362351832.689 [NAL9602](INFO): SBD MO Status=1, MOMSN=6108, MT Status=0, MTMSN=0
2013-03-03T23:03:52.739Z,1362351832.739 [NAL9602](INFO): Sent 332 bytes from file Logs/20130303T221159/shore0000.lzma
2013-03-03T23:03:52.739Z,1362351832.739 [NAL9602](INFO): Packets left to send: 2
2013-03-03T23:03:52.741Z,1362351832.741 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T221159/shore0000.lzma.parts/0002.sbd
2013-03-03T23:04:05.362Z,1362351845.362 [NAL9602](INFO): SBD MO Status=1, MOMSN=6109, MT Status=0, MTMSN=0
2013-03-03T23:04:05.411Z,1362351845.411 [NAL9602](INFO): Sent 332 bytes from file Logs/20130303T221159/shore0000.lzma
2013-03-03T23:04:05.411Z,1362351845.411 [NAL9602](INFO): Packets left to send: 1
2013-03-03T23:04:05.412Z,1362351845.412 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T221159/shore0000.lzma.parts/0001.sbd
2013-03-03T23:04:13.971Z,1362351853.971 [NAL9602](INFO): SBD MO Status=1, MOMSN=6110, MT Status=0, MTMSN=0
2013-03-03T23:04:14.019Z,1362351854.019 [NAL9602](INFO): Sent 94 bytes from file Logs/20130303T221159/shore0000.lzma
2013-03-03T23:04:14.019Z,1362351854.019 [NAL9602](INFO): Packets left to send: 0
2013-03-03T23:04:14.257Z,1362351854.257 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T221159/shore0000.lzma.parts/0000.sbd
2013-03-03T23:04:25.178Z,1362351865.178 [NAL9602](INFO): SBD MO Status=1, MOMSN=6111, MT Status=0, MTMSN=0
2013-03-03T23:04:25.227Z,1362351865.227 [NAL9602](INFO): Sent 332 bytes from file Logs/20130303T221159/shore0001.lzma
2013-03-03T23:04:25.227Z,1362351865.227 [NAL9602](INFO): Packets left to send: 2
2013-03-03T23:04:25.229Z,1362351865.229 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T221159/shore0001.lzma.parts/0002.sbd
2013-03-03T23:04:35.385Z,1362351875.385 [NAL9602](INFO): SBD MO Status=1, MOMSN=6112, MT Status=0, MTMSN=0
2013-03-03T23:04:35.435Z,1362351875.435 [NAL9602](INFO): Sent 332 bytes from file Logs/20130303T221159/shore0001.lzma
2013-03-03T23:04:35.435Z,1362351875.435 [NAL9602](INFO): Packets left to send: 1
2013-03-03T23:04:35.436Z,1362351875.436 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T221159/shore0001.lzma.parts/0001.sbd
2013-03-03T23:04:47.685Z,1362351887.685 [NAL9602](INFO): SBD MO Status=1, MOMSN=6113, MT Status=0, MTMSN=0
2013-03-03T23:04:47.735Z,1362351887.735 [NAL9602](INFO): Sent 151 bytes from file Logs/20130303T221159/shore0001.lzma
2013-03-03T23:04:47.735Z,1362351887.735 [NAL9602](INFO): Packets left to send: 0
2013-03-03T23:04:47.736Z,1362351887.736 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T221159/shore0001.lzma.parts/0000.sbd
2013-03-03T23:05:01.101Z,1362351901.102 [NAL9602](INFO): SBD MO Status=1, MOMSN=6114, MT Status=0, MTMSN=0
2013-03-03T23:05:01.151Z,1362351901.151 [NAL9602](INFO): Sent 332 bytes from file Logs/20130303T222928/shore0000.lzma
2013-03-03T23:05:01.151Z,1362351901.151 [NAL9602](INFO): Packets left to send: 3
2013-03-03T23:05:01.153Z,1362351901.153 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T222928/shore0000.lzma.parts/0003.sbd
2013-03-03T23:05:14.505Z,1362351914.505 [NAL9602](INFO): SBD MO Status=1, MOMSN=6115, MT Status=0, MTMSN=0
2013-03-03T23:05:14.555Z,1362351914.555 [NAL9602](INFO): Sent 332 bytes from file Logs/20130303T222928/shore0000.lzma
2013-03-03T23:05:14.555Z,1362351914.555 [NAL9602](INFO): Packets left to send: 2
2013-03-03T23:05:14.556Z,1362351914.556 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T222928/shore0000.lzma.parts/0002.sbd
2013-03-03T23:05:25.936Z,1362351925.936 [NAL9602](INFO): SBD MO Status=1, MOMSN=6116, MT Status=0, MTMSN=0
2013-03-03T23:05:25.987Z,1362351925.987 [NAL9602](INFO): Sent 332 bytes from file Logs/20130303T222928/shore0000.lzma
2013-03-03T23:05:25.987Z,1362351925.987 [NAL9602](INFO): Packets left to send: 1
2013-03-03T23:05:25.988Z,1362351925.988 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T222928/shore0000.lzma.parts/0001.sbd
2013-03-03T23:05:32.981Z,1362351932.981 [NAL9602](INFO): SBD MO Status=1, MOMSN=6117, MT Status=0, MTMSN=0
2013-03-03T23:05:33.031Z,1362351933.031 [NAL9602](INFO): Sent 23 bytes from file Logs/20130303T222928/shore0000.lzma
2013-03-03T23:05:33.031Z,1362351933.031 [NAL9602](INFO): Packets left to send: 0
2013-03-03T23:05:33.032Z,1362351933.032 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T222928/shore0000.lzma.parts/0000.sbd
2013-03-03T23:05:42.817Z,1362351942.817 [NAL9602](INFO): SBD MO Status=1, MOMSN=6118, MT Status=0, MTMSN=0
2013-03-03T23:05:42.867Z,1362351942.867 [NAL9602](INFO): Sent 332 bytes from file Logs/20130303T222928/shore0001.lzma
2013-03-03T23:05:42.867Z,1362351942.867 [NAL9602](INFO): Packets left to send: 2
2013-03-03T23:05:42.869Z,1362351942.869 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T222928/shore0001.lzma.parts/0002.sbd
2013-03-03T23:05:51.945Z,1362351951.945 [NAL9602](INFO): SBD MO Status=1, MOMSN=6119, MT Status=0, MTMSN=0
2013-03-03T23:05:51.999Z,1362351951.999 [NAL9602](INFO): Sent 332 bytes from file Logs/20130303T222928/shore0001.lzma
2013-03-03T23:05:51.999Z,1362351951.999 [NAL9602](INFO): Packets left to send: 1
2013-03-03T23:05:52.000Z,1362351952.000 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T222928/shore0001.lzma.parts/0001.sbd
2013-03-03T23:06:00.977Z,1362351960.977 [NAL9602](INFO): SBD MO Status=1, MOMSN=6120, MT Status=0, MTMSN=0
2013-03-03T23:06:01.027Z,1362351961.027 [NAL9602](INFO): Sent 209 bytes from file Logs/20130303T222928/shore0001.lzma
2013-03-03T23:06:01.027Z,1362351961.027 [NAL9602](INFO): Packets left to send: 0
2013-03-03T23:06:01.028Z,1362351961.028 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T222928/shore0001.lzma.parts/0000.sbd
2013-03-03T23:06:10.817Z,1362351970.817 [NAL9602](INFO): SBD MO Status=1, MOMSN=6121, MT Status=0, MTMSN=0
2013-03-03T23:06:10.867Z,1362351970.867 [NAL9602](INFO): Sent 332 bytes from file Logs/20130303T225420/shore0000.lzma
2013-03-03T23:06:10.867Z,1362351970.867 [NAL9602](INFO): Packets left to send: 2
2013-03-03T23:06:10.869Z,1362351970.869 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T225420/shore0000.lzma.parts/0002.sbd
2013-03-03T23:06:23.465Z,1362351983.465 [NAL9602](INFO): SBD MO Status=1, MOMSN=6122, MT Status=0, MTMSN=0
2013-03-03T23:06:23.516Z,1362351983.516 [NAL9602](INFO): Sent 332 bytes from file Logs/20130303T225420/shore0000.lzma
2013-03-03T23:06:23.516Z,1362351983.516 [NAL9602](INFO): Packets left to send: 1
2013-03-03T23:06:23.517Z,1362351983.517 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T225420/shore0000.lzma.parts/0001.sbd
2013-03-03T23:06:34.614Z,1362351994.614 [NAL9602](INFO): SBD MO Status=1, MOMSN=6123, MT Status=0, MTMSN=0
2013-03-03T23:06:34.663Z,1362351994.663 [NAL9602](INFO): Sent 230 bytes from file Logs/20130303T225420/shore0000.lzma
2013-03-03T23:06:34.663Z,1362351994.663 [NAL9602](INFO): Packets left to send: 0
2013-03-03T23:06:34.664Z,1362351994.664 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T225420/shore0000.lzma.parts/0000.sbd
2013-03-03T23:06:42.972Z,1362352002.972 [NAL9602](INFO): SBD MO Status=0, MOMSN=6124, MT Status=0, MTMSN=0
2013-03-03T23:06:55.513Z,1362352015.513 [NAL9602](INFO): SBD MO Status=1, MOMSN=6125, MT Status=0, MTMSN=0
2013-03-03T23:06:55.563Z,1362352015.563 [NAL9602](INFO): Sent 332 bytes from file Logs/20130303T225420/shore0001.lzma
2013-03-03T23:06:55.563Z,1362352015.563 [NAL9602](INFO): Packets left to send: 1
2013-03-03T23:06:55.565Z,1362352015.565 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T225420/shore0001.lzma.parts/0001.sbd
2013-03-03T23:07:06.166Z,1362352026.166 [NAL9602](INFO): SBD MO Status=1, MOMSN=6126, MT Status=0, MTMSN=0
2013-03-03T23:07:06.216Z,1362352026.216 [NAL9602](INFO): Sent 61 bytes from file Logs/20130303T225420/shore0001.lzma
2013-03-03T23:07:06.216Z,1362352026.216 [NAL9602](INFO): Packets left to send: 0
2013-03-03T23:07:06.217Z,1362352026.217 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T225420/shore0001.lzma.parts/0000.sbd
2013-03-03T23:07:13.365Z,1362352033.365 [NAL9602](INFO): SBD MO Status=0, MOMSN=6127, MT Status=0, MTMSN=0
2013-03-03T23:07:13.455Z,1362352033.455 [Default:Iridium:Read_Iridium] Stopped
2013-03-03T23:07:13.456Z,1362352033.456 [Default:Iridium](INFO): Completed Default:Iridium
2013-03-03T23:07:13.456Z,1362352033.456 [Default:Iridium] Stopped
2013-03-03T23:07:13.456Z,1362352033.456 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-03-03T23:07:13.456Z,1362352033.456 [Default:Iridium:A.SetSpeed] Stopped
2013-03-03T23:07:13.456Z,1362352033.456 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-03-03T23:07:13.456Z,1362352033.456 [Default:F.Wait] Running Loop=1
2013-03-03T23:07:13.456Z,1362352033.456 [Default:F.Wait](DEBUG): Initialize Wait Component.
2013-03-03T23:07:13.788Z,1362352033.788 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-03-03T23:07:13.788Z,1362352033.788 [Default:CallIridium:B] Stopped
2013-03-03T23:07:13.788Z,1362352033.788 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-03-03T23:07:13.788Z,1362352033.788 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-03-03T23:07:13.788Z,1362352033.788 [Default:CallIridium] Stopped
2013-03-03T23:07:13.789Z,1362352033.789 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-03-03T23:07:23.925Z,1362352043.925 [NAL9602](INFO): Powering down
2013-03-03T23:12:13.963Z,1362352333.963 [Default:CallIridium] Running Loop=1
2013-03-03T23:12:13.964Z,1362352333.964 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-03-03T23:12:13.964Z,1362352333.964 [Default:CallIridium:A] Running Loop=1
2013-03-03T23:12:13.964Z,1362352333.964 [Default:CallIridium:A] Stopped
2013-03-03T23:12:13.964Z,1362352333.964 [Default:CallIridium:B] Running Loop=1
2013-03-03T23:12:13.964Z,1362352333.964 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-03-03T23:12:18.937Z,1362352338.937 [Default:Iridium] Running Loop=1
2013-03-03T23:12:18.937Z,1362352338.937 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-03-03T23:12:18.937Z,1362352338.937 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-03T23:12:18.937Z,1362352338.937 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-03-03T23:12:18.937Z,1362352338.937 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-03-03T23:12:18.937Z,1362352338.937 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-03T23:12:18.938Z,1362352338.938 [Default:Iridium:B.GoToSurface] Stopped
2013-03-03T23:12:18.938Z,1362352338.938 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-03T23:12:18.938Z,1362352338.938 [Default:Iridium:Read_Iridium] Running Loop=1
2013-03-03T23:12:18.939Z,1362352338.939 [Default:GPS] Running Loop=1
2013-03-03T23:12:18.939Z,1362352338.939 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-03-03T23:12:18.939Z,1362352338.939 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-03T23:12:18.939Z,1362352338.939 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-03-03T23:12:18.939Z,1362352338.939 [Default:GPS:B.GoToSurface] Running Loop=1
2013-03-03T23:12:18.939Z,1362352338.939 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-03T23:12:18.940Z,1362352338.940 [Default:GPS:B.GoToSurface] Stopped
2013-03-03T23:12:18.940Z,1362352338.940 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-03T23:12:18.940Z,1362352338.940 [Default:GPS:Read_GPS] Running Loop=1
2013-03-03T23:12:19.558Z,1362352339.559 [NAL9602](INFO): Powering up
2013-03-03T23:12:30.007Z,1362352350.007 [NAL9602](INFO): NAL9602 initialized
2013-03-03T23:12:46.148Z,1362352366.148 [NAL9602](INFO): SBD MO Status=1, MOMSN=6128, MT Status=0, MTMSN=0
2013-03-03T23:12:46.199Z,1362352366.199 [NAL9602](INFO): Sent 106 bytes from file Logs/20130303T225420/shore0002.lzma
2013-03-03T23:12:46.199Z,1362352366.199 [NAL9602](INFO): Packets left to send: 0
2013-03-03T23:12:46.201Z,1362352366.201 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T225420/shore0002.lzma.parts/0000.sbd
2013-03-03T23:13:03.389Z,1362352383.389 [NAL9602](INFO): SBD MO Status=0, MOMSN=6129, MT Status=0, MTMSN=0
2013-03-03T23:13:03.485Z,1362352383.485 [Default:Iridium:Read_Iridium] Stopped
2013-03-03T23:13:03.486Z,1362352383.486 [Default:Iridium](INFO): Completed Default:Iridium
2013-03-03T23:13:03.486Z,1362352383.486 [Default:Iridium] Stopped
2013-03-03T23:13:03.486Z,1362352383.486 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-03-03T23:13:03.486Z,1362352383.486 [Default:Iridium:A.SetSpeed] Stopped
2013-03-03T23:13:03.486Z,1362352383.486 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-03-03T23:13:03.783Z,1362352383.783 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-03-03T23:13:03.783Z,1362352383.783 [Default:CallIridium:B] Stopped
2013-03-03T23:13:03.783Z,1362352383.783 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-03-03T23:13:03.784Z,1362352383.783 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-03-03T23:13:03.784Z,1362352383.783 [Default:CallIridium] Stopped
2013-03-03T23:13:03.784Z,1362352383.784 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-03-03T23:13:04.551Z,1362352384.551 [NAL9602](IMPORTANT): GPS fix at: 1362352386.00
2013-03-03T23:13:04.584Z,1362352384.584 [Default:GPS:Read_GPS] Stopped
2013-03-03T23:13:04.585Z,1362352384.585 [Default:GPS:D] Running Loop=1
2013-03-03T23:13:04.979Z,1362352384.979 [Default:GPS:D] Stopped
2013-03-03T23:13:04.980Z,1362352384.980 [Default:GPS](INFO): Completed Default:GPS
2013-03-03T23:13:04.980Z,1362352384.980 [Default:GPS] Stopped
2013-03-03T23:13:04.980Z,1362352384.980 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-03-03T23:13:04.980Z,1362352384.980 [Default:GPS:A.SetSpeed] Stopped
2013-03-03T23:13:04.980Z,1362352384.980 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-03-03T23:13:25.517Z,1362352405.517 [NAL9602](INFO): Powering down
2013-03-03T23:18:05.557Z,1362352685.557 [Default:CallIridium] Running Loop=1
2013-03-03T23:18:05.557Z,1362352685.557 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-03-03T23:18:05.557Z,1362352685.557 [Default:CallIridium:A] Running Loop=1
2013-03-03T23:18:05.557Z,1362352685.557 [Default:CallIridium:A] Stopped
2013-03-03T23:18:05.558Z,1362352685.557 [Default:CallIridium:B] Running Loop=1
2013-03-03T23:18:05.558Z,1362352685.558 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-03-03T23:18:10.532Z,1362352690.532 [Default:Iridium] Running Loop=1
2013-03-03T23:18:10.532Z,1362352690.532 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-03-03T23:18:10.532Z,1362352690.532 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-03T23:18:10.532Z,1362352690.532 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-03-03T23:18:10.532Z,1362352690.532 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-03-03T23:18:10.532Z,1362352690.532 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-03T23:18:10.533Z,1362352690.533 [Default:Iridium:B.GoToSurface] Stopped
2013-03-03T23:18:10.533Z,1362352690.533 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-03T23:18:10.533Z,1362352690.533 [Default:Iridium:Read_Iridium] Running Loop=1
2013-03-03T23:18:10.534Z,1362352690.534 [Default:GPS] Running Loop=1
2013-03-03T23:18:10.534Z,1362352690.534 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-03-03T23:18:10.534Z,1362352690.534 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-03T23:18:10.534Z,1362352690.534 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-03-03T23:18:10.534Z,1362352690.534 [Default:GPS:B.GoToSurface] Running Loop=1
2013-03-03T23:18:10.534Z,1362352690.534 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-03T23:18:10.535Z,1362352690.535 [Default:GPS:B.GoToSurface] Stopped
2013-03-03T23:18:10.535Z,1362352690.535 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-03T23:18:10.535Z,1362352690.536 [Default:GPS:Read_GPS] Running Loop=1
2013-03-03T23:18:11.156Z,1362352691.156 [NAL9602](INFO): Powering up
2013-03-03T23:18:21.992Z,1362352701.992 [NAL9602](INFO): NAL9602 initialized
2013-03-03T23:18:46.589Z,1362352726.589 [NAL9602](INFO): SBD MO Status=1, MOMSN=6130, MT Status=0, MTMSN=0
2013-03-03T23:18:46.639Z,1362352726.639 [NAL9602](INFO): Sent 138 bytes from file Logs/20130303T225420/shore0003.lzma
2013-03-03T23:18:46.639Z,1362352726.639 [NAL9602](INFO): Packets left to send: 0
2013-03-03T23:18:46.641Z,1362352726.641 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T225420/shore0003.lzma.parts/0000.sbd
2013-03-03T23:18:52.589Z,1362352732.589 [NAL9602](INFO): SBD MO Status=0, MOMSN=6131, MT Status=0, MTMSN=0
2013-03-03T23:18:52.683Z,1362352732.683 [Default:Iridium:Read_Iridium] Stopped
2013-03-03T23:18:52.683Z,1362352732.684 [Default:Iridium](INFO): Completed Default:Iridium
2013-03-03T23:18:52.684Z,1362352732.684 [Default:Iridium] Stopped
2013-03-03T23:18:52.684Z,1362352732.684 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-03-03T23:18:52.684Z,1362352732.684 [Default:Iridium:A.SetSpeed] Stopped
2013-03-03T23:18:52.684Z,1362352732.684 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-03-03T23:18:53.009Z,1362352733.009 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-03-03T23:18:53.009Z,1362352733.009 [Default:CallIridium:B] Stopped
2013-03-03T23:18:53.009Z,1362352733.009 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-03-03T23:18:53.009Z,1362352733.009 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-03-03T23:18:53.009Z,1362352733.010 [Default:CallIridium] Stopped
2013-03-03T23:18:53.010Z,1362352733.010 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-03-03T23:18:53.792Z,1362352733.792 [NAL9602](IMPORTANT): GPS fix at: 1362352736.00
2013-03-03T23:18:53.810Z,1362352733.810 [Default:GPS:Read_GPS] Stopped
2013-03-03T23:18:53.811Z,1362352733.810 [Default:GPS:D] Running Loop=1
2013-03-03T23:18:54.228Z,1362352734.228 [Default:GPS:D] Stopped
2013-03-03T23:18:54.229Z,1362352734.229 [Default:GPS](INFO): Completed Default:GPS
2013-03-03T23:18:54.229Z,1362352734.229 [Default:GPS] Stopped
2013-03-03T23:18:54.229Z,1362352734.229 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-03-03T23:18:54.229Z,1362352734.229 [Default:GPS:A.SetSpeed] Stopped
2013-03-03T23:18:54.229Z,1362352734.229 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-03-03T23:19:14.841Z,1362352754.841 [NAL9602](INFO): Powering down
2013-03-03T23:21:33.491Z,1362352893.491 [NavChartDb](INFO): Done scanning features of Resources/US5CA62M.000
2013-03-03T23:23:54.792Z,1362353034.792 [Default:CallIridium] Running Loop=1
2013-03-03T23:23:54.793Z,1362353034.793 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-03-03T23:23:54.793Z,1362353034.793 [Default:CallIridium:A] Running Loop=1
2013-03-03T23:23:54.793Z,1362353034.793 [Default:CallIridium:A] Stopped
2013-03-03T23:23:54.793Z,1362353034.793 [Default:CallIridium:B] Running Loop=1
2013-03-03T23:23:54.793Z,1362353034.793 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-03-03T23:23:59.804Z,1362353039.804 [Default:Iridium] Running Loop=1
2013-03-03T23:23:59.804Z,1362353039.804 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-03-03T23:23:59.804Z,1362353039.804 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-03T23:23:59.804Z,1362353039.804 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-03-03T23:23:59.804Z,1362353039.805 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-03-03T23:23:59.805Z,1362353039.805 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-03T23:23:59.805Z,1362353039.805 [Default:Iridium:B.GoToSurface] Stopped
2013-03-03T23:23:59.805Z,1362353039.805 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-03T23:23:59.805Z,1362353039.806 [Default:Iridium:Read_Iridium] Running Loop=1
2013-03-03T23:23:59.806Z,1362353039.806 [Default:GPS] Running Loop=1
2013-03-03T23:23:59.806Z,1362353039.806 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-03-03T23:23:59.806Z,1362353039.806 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-03T23:23:59.806Z,1362353039.806 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-03-03T23:23:59.809Z,1362353039.809 [Default:GPS:B.GoToSurface] Running Loop=1
2013-03-03T23:23:59.809Z,1362353039.809 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-03T23:23:59.810Z,1362353039.810 [Default:GPS:B.GoToSurface] Stopped
2013-03-03T23:23:59.810Z,1362353039.810 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-03T23:23:59.810Z,1362353039.810 [Default:GPS:Read_GPS] Running Loop=1
2013-03-03T23:24:00.404Z,1362353040.404 [NAL9602](INFO): Powering up
2013-03-03T23:24:11.239Z,1362353051.239 [NAL9602](INFO): NAL9602 initialized
2013-03-03T23:24:30.576Z,1362353070.576 [NAL9602](INFO): SBD MO Status=1, MOMSN=6132, MT Status=0, MTMSN=0
2013-03-03T23:24:30.623Z,1362353070.623 [NAL9602](INFO): Sent 140 bytes from file Logs/20130303T225420/shore0004.lzma
2013-03-03T23:24:30.623Z,1362353070.623 [NAL9602](INFO): Packets left to send: 0
2013-03-03T23:24:30.625Z,1362353070.625 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T225420/shore0004.lzma.parts/0000.sbd
2013-03-03T23:24:40.177Z,1362353080.177 [NAL9602](INFO): SBD MO Status=0, MOMSN=6133, MT Status=0, MTMSN=0
2013-03-03T23:24:40.265Z,1362353080.265 [Default:Iridium:Read_Iridium] Stopped
2013-03-03T23:24:40.265Z,1362353080.265 [Default:Iridium](INFO): Completed Default:Iridium
2013-03-03T23:24:40.265Z,1362353080.265 [Default:Iridium] Stopped
2013-03-03T23:24:40.265Z,1362353080.265 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-03-03T23:24:40.265Z,1362353080.265 [Default:Iridium:A.SetSpeed] Stopped
2013-03-03T23:24:40.265Z,1362353080.265 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-03-03T23:24:40.589Z,1362353080.589 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-03-03T23:24:40.589Z,1362353080.589 [Default:CallIridium:B] Stopped
2013-03-03T23:24:40.589Z,1362353080.589 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-03-03T23:24:40.589Z,1362353080.589 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-03-03T23:24:40.589Z,1362353080.589 [Default:CallIridium] Stopped
2013-03-03T23:24:40.589Z,1362353080.589 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-03-03T23:24:41.379Z,1362353081.379 [NAL9602](IMPORTANT): GPS fix at: 1362353084.00
2013-03-03T23:24:41.396Z,1362353081.397 [Default:GPS:Read_GPS] Stopped
2013-03-03T23:24:41.397Z,1362353081.397 [Default:GPS:D] Running Loop=1
2013-03-03T23:24:41.815Z,1362353081.815 [Default:GPS:D] Stopped
2013-03-03T23:24:41.815Z,1362353081.815 [Default:GPS](INFO): Completed Default:GPS
2013-03-03T23:24:41.815Z,1362353081.815 [Default:GPS] Stopped
2013-03-03T23:24:41.815Z,1362353081.815 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-03-03T23:24:41.815Z,1362353081.815 [Default:GPS:A.SetSpeed] Stopped
2013-03-03T23:24:41.816Z,1362353081.816 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-03-03T23:25:02.357Z,1362353102.357 [NAL9602](INFO): Powering down
2013-03-03T23:29:42.340Z,1362353382.340 [Default:CallIridium] Running Loop=1
2013-03-03T23:29:42.341Z,1362353382.341 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-03-03T23:29:42.341Z,1362353382.341 [Default:CallIridium:A] Running Loop=1
2013-03-03T23:29:42.341Z,1362353382.341 [Default:CallIridium:A] Stopped
2013-03-03T23:29:42.341Z,1362353382.341 [Default:CallIridium:B] Running Loop=1
2013-03-03T23:29:42.341Z,1362353382.341 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-03-03T23:29:47.393Z,1362353387.393 [Default:Iridium] Running Loop=1
2013-03-03T23:29:47.393Z,1362353387.393 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-03-03T23:29:47.393Z,1362353387.393 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-03T23:29:47.393Z,1362353387.393 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-03-03T23:29:47.393Z,1362353387.393 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-03-03T23:29:47.393Z,1362353387.393 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-03T23:29:47.394Z,1362353387.394 [Default:Iridium:B.GoToSurface] Stopped
2013-03-03T23:29:47.394Z,1362353387.394 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-03T23:29:47.394Z,1362353387.394 [Default:Iridium:Read_Iridium] Running Loop=1
2013-03-03T23:29:47.395Z,1362353387.395 [Default:GPS] Running Loop=1
2013-03-03T23:29:47.395Z,1362353387.395 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-03-03T23:29:47.395Z,1362353387.395 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-03T23:29:47.395Z,1362353387.395 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-03-03T23:29:47.395Z,1362353387.395 [Default:GPS:B.GoToSurface] Running Loop=1
2013-03-03T23:29:47.395Z,1362353387.395 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-03T23:29:47.396Z,1362353387.396 [Default:GPS:B.GoToSurface] Stopped
2013-03-03T23:29:47.396Z,1362353387.396 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-03T23:29:47.396Z,1362353387.396 [Default:GPS:Read_GPS] Running Loop=1
2013-03-03T23:29:47.987Z,1362353387.987 [NAL9602](INFO): Powering up
2013-03-03T23:29:58.419Z,1362353398.419 [NAL9602](INFO): NAL9602 initialized
2013-03-03T23:30:14.202Z,1362353414.202 [NAL9602](INFO): SBD MO Status=1, MOMSN=6134, MT Status=0, MTMSN=0
2013-03-03T23:30:14.251Z,1362353414.251 [NAL9602](INFO): Sent 138 bytes from file Logs/20130303T225420/shore0005.lzma
2013-03-03T23:30:14.251Z,1362353414.251 [NAL9602](INFO): Packets left to send: 0
2013-03-03T23:30:14.253Z,1362353414.253 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T225420/shore0005.lzma.parts/0000.sbd
2013-03-03T23:30:22.166Z,1362353422.166 [NAL9602](INFO): SBD MO Status=0, MOMSN=6135, MT Status=0, MTMSN=0
2013-03-03T23:30:22.248Z,1362353422.248 [Default:Iridium:Read_Iridium] Stopped
2013-03-03T23:30:22.249Z,1362353422.249 [Default:Iridium](INFO): Completed Default:Iridium
2013-03-03T23:30:22.249Z,1362353422.249 [Default:Iridium] Stopped
2013-03-03T23:30:22.249Z,1362353422.249 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-03-03T23:30:22.249Z,1362353422.249 [Default:Iridium:A.SetSpeed] Stopped
2013-03-03T23:30:22.249Z,1362353422.249 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-03-03T23:30:22.587Z,1362353422.587 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-03-03T23:30:22.587Z,1362353422.588 [Default:CallIridium:B] Stopped
2013-03-03T23:30:22.588Z,1362353422.588 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-03-03T23:30:22.588Z,1362353422.588 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-03-03T23:30:22.588Z,1362353422.588 [Default:CallIridium] Stopped
2013-03-03T23:30:22.588Z,1362353422.588 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-03-03T23:30:23.373Z,1362353423.373 [NAL9602](IMPORTANT): GPS fix at: 1362353426.00
2013-03-03T23:30:23.390Z,1362353423.390 [Default:GPS:Read_GPS] Stopped
2013-03-03T23:30:23.390Z,1362353423.390 [Default:GPS:D] Running Loop=1
2013-03-03T23:30:23.849Z,1362353423.849 [Default:GPS:D] Stopped
2013-03-03T23:30:23.850Z,1362353423.849 [Default:GPS](INFO): Completed Default:GPS
2013-03-03T23:30:23.850Z,1362353423.850 [Default:GPS] Stopped
2013-03-03T23:30:23.850Z,1362353423.850 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-03-03T23:30:23.850Z,1362353423.850 [Default:GPS:A.SetSpeed] Stopped
2013-03-03T23:30:23.850Z,1362353423.850 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-03-03T23:30:44.361Z,1362353444.361 [NAL9602](INFO): Powering down
2013-03-03T23:32:37.534Z,1362353557.534 [NavChartDb](INFO): # of records loaded: 5000
2013-03-03T23:34:30.675Z,1362353670.675 [NavChartDb](INFO): # of records loaded: 10000
2013-03-03T23:35:24.419Z,1362353724.419 [Default:CallIridium] Running Loop=1
2013-03-03T23:35:24.419Z,1362353724.419 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-03-03T23:35:24.419Z,1362353724.419 [Default:CallIridium:A] Running Loop=1
2013-03-03T23:35:24.419Z,1362353724.420 [Default:CallIridium:A] Stopped
2013-03-03T23:35:24.420Z,1362353724.420 [Default:CallIridium:B] Running Loop=1
2013-03-03T23:35:24.420Z,1362353724.420 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-03-03T23:35:29.395Z,1362353729.395 [Default:Iridium] Running Loop=1
2013-03-03T23:35:29.395Z,1362353729.395 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-03-03T23:35:29.395Z,1362353729.395 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-03T23:35:29.395Z,1362353729.395 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-03-03T23:35:29.396Z,1362353729.396 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-03-03T23:35:29.396Z,1362353729.396 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-03T23:35:29.396Z,1362353729.396 [Default:Iridium:B.GoToSurface] Stopped
2013-03-03T23:35:29.396Z,1362353729.396 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-03T23:35:29.397Z,1362353729.397 [Default:Iridium:Read_Iridium] Running Loop=1
2013-03-03T23:35:29.397Z,1362353729.397 [Default:GPS] Running Loop=1
2013-03-03T23:35:29.397Z,1362353729.397 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-03-03T23:35:29.397Z,1362353729.397 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-03T23:35:29.397Z,1362353729.397 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-03-03T23:35:29.397Z,1362353729.397 [Default:GPS:B.GoToSurface] Running Loop=1
2013-03-03T23:35:29.397Z,1362353729.397 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-03T23:35:29.398Z,1362353729.398 [Default:GPS:B.GoToSurface] Stopped
2013-03-03T23:35:29.398Z,1362353729.398 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-03T23:35:29.398Z,1362353729.398 [Default:GPS:Read_GPS] Running Loop=1
2013-03-03T23:35:29.996Z,1362353729.996 [NAL9602](INFO): Powering up
2013-03-03T23:35:40.879Z,1362353740.879 [NAL9602](INFO): NAL9602 initialized
2013-03-03T23:35:58.976Z,1362353758.976 [NAL9602](IMPORTANT): GPS fix at: 1362353762.00
2013-03-03T23:35:58.980Z,1362353758.980 [NavChartDb](INFO): # of records loaded: 15000
2013-03-03T23:35:59.017Z,1362353759.017 [Default:GPS:Read_GPS] Stopped
2013-03-03T23:35:59.017Z,1362353759.017 [Default:GPS:D] Running Loop=1
2013-03-03T23:35:59.337Z,1362353759.337 [Default:GPS:D] Stopped
2013-03-03T23:35:59.337Z,1362353759.337 [Default:GPS](INFO): Completed Default:GPS
2013-03-03T23:35:59.337Z,1362353759.337 [Default:GPS] Stopped
2013-03-03T23:35:59.337Z,1362353759.337 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-03-03T23:35:59.337Z,1362353759.337 [Default:GPS:A.SetSpeed] Stopped
2013-03-03T23:35:59.338Z,1362353759.338 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-03-03T23:37:43.406Z,1362353863.406 [NavChartDb](INFO): # of records loaded: 20000
2013-03-03T23:38:39.521Z,1362353919.521 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#6 STATUS: 65535
2013-03-03T23:40:04.089Z,1362354004.089 [NAL9602](INFO): SBD MO Status=1, MOMSN=6136, MT Status=0, MTMSN=0
2013-03-03T23:40:04.143Z,1362354004.143 [NAL9602](INFO): Sent 136 bytes from file Logs/20130303T225420/shore0006.lzma
2013-03-03T23:40:04.143Z,1362354004.143 [NAL9602](INFO): Packets left to send: 0
2013-03-03T23:40:04.145Z,1362354004.145 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T225420/shore0006.lzma.parts/0000.sbd
2013-03-03T23:40:11.697Z,1362354011.697 [NAL9602](INFO): SBD MO Status=0, MOMSN=6137, MT Status=0, MTMSN=0
2013-03-03T23:40:11.792Z,1362354011.792 [Default:Iridium:Read_Iridium] Stopped
2013-03-03T23:40:11.793Z,1362354011.793 [Default:Iridium](INFO): Completed Default:Iridium
2013-03-03T23:40:11.793Z,1362354011.793 [Default:Iridium] Stopped
2013-03-03T23:40:11.793Z,1362354011.793 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-03-03T23:40:11.793Z,1362354011.793 [Default:Iridium:A.SetSpeed] Stopped
2013-03-03T23:40:11.793Z,1362354011.793 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-03-03T23:40:12.150Z,1362354012.150 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-03-03T23:40:12.150Z,1362354012.150 [Default:CallIridium:B] Stopped
2013-03-03T23:40:12.150Z,1362354012.150 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-03-03T23:40:12.151Z,1362354012.151 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-03-03T23:40:12.151Z,1362354012.151 [Default:CallIridium] Stopped
2013-03-03T23:40:12.151Z,1362354012.151 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-03-03T23:40:22.293Z,1362354022.293 [NAL9602](INFO): Powering down
2013-03-03T23:40:48.717Z,1362354048.717 [NavChartDb](INFO): # of records loaded: 25000
2013-03-03T23:41:45.188Z,1362354105.188 [NavChartDb](INFO): Calculating coverage of Resources/US5CA62M.000
2013-03-03T23:45:12.309Z,1362354312.309 [Default:CallIridium] Running Loop=1
2013-03-03T23:45:12.309Z,1362354312.309 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-03-03T23:45:12.309Z,1362354312.309 [Default:CallIridium:A] Running Loop=1
2013-03-03T23:45:12.309Z,1362354312.309 [Default:CallIridium:A] Stopped
2013-03-03T23:45:12.310Z,1362354312.310 [Default:CallIridium:B] Running Loop=1
2013-03-03T23:45:12.310Z,1362354312.310 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-03-03T23:45:17.291Z,1362354317.291 [Default:Iridium] Running Loop=1
2013-03-03T23:45:17.291Z,1362354317.291 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-03-03T23:45:17.291Z,1362354317.291 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-03T23:45:17.291Z,1362354317.291 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-03-03T23:45:17.291Z,1362354317.291 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-03-03T23:45:17.292Z,1362354317.292 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-03T23:45:17.292Z,1362354317.292 [Default:Iridium:B.GoToSurface] Stopped
2013-03-03T23:45:17.292Z,1362354317.292 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-03T23:45:17.292Z,1362354317.292 [Default:Iridium:Read_Iridium] Running Loop=1
2013-03-03T23:45:17.293Z,1362354317.293 [Default:GPS] Running Loop=1
2013-03-03T23:45:17.293Z,1362354317.293 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-03-03T23:45:17.293Z,1362354317.293 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-03T23:45:17.293Z,1362354317.293 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-03-03T23:45:17.293Z,1362354317.293 [Default:GPS:B.GoToSurface] Running Loop=1
2013-03-03T23:45:17.293Z,1362354317.293 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-03T23:45:17.294Z,1362354317.294 [Default:GPS:B.GoToSurface] Stopped
2013-03-03T23:45:17.294Z,1362354317.294 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-03T23:45:17.294Z,1362354317.294 [Default:GPS:Read_GPS] Running Loop=1
2013-03-03T23:45:17.924Z,1362354317.924 [NAL9602](INFO): Powering up
2013-03-03T23:45:28.331Z,1362354328.331 [NAL9602](INFO): NAL9602 initialized
2013-03-03T23:45:48.072Z,1362354348.072 [NAL9602](INFO): SBD MO Status=1, MOMSN=6138, MT Status=0, MTMSN=0
2013-03-03T23:45:48.119Z,1362354348.119 [NAL9602](INFO): Sent 135 bytes from file Logs/20130303T225420/shore0007.lzma
2013-03-03T23:45:48.119Z,1362354348.119 [NAL9602](INFO): Packets left to send: 0
2013-03-03T23:45:48.121Z,1362354348.121 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T225420/shore0007.lzma.parts/0000.sbd
2013-03-03T23:45:56.522Z,1362354356.522 [NAL9602](INFO): SBD MO Status=0, MOMSN=6139, MT Status=0, MTMSN=0
2013-03-03T23:45:56.613Z,1362354356.613 [Default:Iridium:Read_Iridium] Stopped
2013-03-03T23:45:56.613Z,1362354356.613 [Default:Iridium](INFO): Completed Default:Iridium
2013-03-03T23:45:56.613Z,1362354356.613 [Default:Iridium] Stopped
2013-03-03T23:45:56.613Z,1362354356.614 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-03-03T23:45:56.614Z,1362354356.614 [Default:Iridium:A.SetSpeed] Stopped
2013-03-03T23:45:56.614Z,1362354356.614 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-03-03T23:45:56.896Z,1362354356.896 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-03-03T23:45:56.896Z,1362354356.896 [Default:CallIridium:B] Stopped
2013-03-03T23:45:56.896Z,1362354356.896 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-03-03T23:45:56.896Z,1362354356.896 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-03-03T23:45:56.896Z,1362354356.896 [Default:CallIridium] Stopped
2013-03-03T23:45:56.896Z,1362354356.896 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-03-03T23:45:57.673Z,1362354357.673 [NAL9602](IMPORTANT): GPS fix at: 1362354362.00
2013-03-03T23:45:57.690Z,1362354357.690 [Default:GPS:Read_GPS] Stopped
2013-03-03T23:45:57.690Z,1362354357.690 [Default:GPS:D] Running Loop=1
2013-03-03T23:45:58.099Z,1362354358.099 [Default:GPS:D] Stopped
2013-03-03T23:45:58.100Z,1362354358.100 [Default:GPS](INFO): Completed Default:GPS
2013-03-03T23:45:58.100Z,1362354358.100 [Default:GPS] Stopped
2013-03-03T23:45:58.100Z,1362354358.100 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-03-03T23:45:58.100Z,1362354358.100 [Default:GPS:A.SetSpeed] Stopped
2013-03-03T23:45:58.100Z,1362354358.100 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-03-03T23:46:18.629Z,1362354378.629 [NAL9602](INFO): Powering down
2013-03-03T23:48:42.123Z,1362354522.123 [NavChartDb](INFO): Done scanning edges of Resources/US5CA62M.000
2013-03-03T23:48:42.485Z,1362354522.485 [NavChartDb](INFO): # of records loaded: 30000
2013-03-03T23:50:58.691Z,1362354658.691 [Default:CallIridium] Running Loop=1
2013-03-03T23:50:58.691Z,1362354658.691 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-03-03T23:50:58.691Z,1362354658.691 [Default:CallIridium:A] Running Loop=1
2013-03-03T23:50:58.692Z,1362354658.691 [Default:CallIridium:A] Stopped
2013-03-03T23:50:58.692Z,1362354658.692 [Default:CallIridium:B] Running Loop=1
2013-03-03T23:50:58.692Z,1362354658.692 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-03-03T23:51:03.648Z,1362354663.648 [Default:Iridium] Running Loop=1
2013-03-03T23:51:03.648Z,1362354663.648 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-03-03T23:51:03.648Z,1362354663.648 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-03T23:51:03.648Z,1362354663.648 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-03-03T23:51:03.648Z,1362354663.648 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-03-03T23:51:03.649Z,1362354663.648 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-03T23:51:03.649Z,1362354663.649 [Default:Iridium:B.GoToSurface] Stopped
2013-03-03T23:51:03.649Z,1362354663.649 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-03T23:51:03.649Z,1362354663.649 [Default:Iridium:Read_Iridium] Running Loop=1
2013-03-03T23:51:03.650Z,1362354663.650 [Default:GPS] Running Loop=1
2013-03-03T23:51:03.650Z,1362354663.650 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-03-03T23:51:03.650Z,1362354663.650 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-03T23:51:03.650Z,1362354663.650 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-03-03T23:51:03.650Z,1362354663.650 [Default:GPS:B.GoToSurface] Running Loop=1
2013-03-03T23:51:03.650Z,1362354663.650 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-03T23:51:03.651Z,1362354663.651 [Default:GPS:B.GoToSurface] Stopped
2013-03-03T23:51:03.651Z,1362354663.651 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-03T23:51:03.651Z,1362354663.651 [Default:GPS:Read_GPS] Running Loop=1
2013-03-03T23:51:04.275Z,1362354664.274 [NAL9602](INFO): Powering up
2013-03-03T23:51:15.111Z,1362354675.111 [NAL9602](INFO): NAL9602 initialized
2013-03-03T23:51:50.075Z,1362354710.075 [NAL9602](INFO): SBD MO Status=2, MOMSN=6140, MT Status=2, MTMSN=0
2013-03-03T23:51:50.076Z,1362354710.076 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-03-03T23:51:51.277Z,1362354711.277 [NAL9602](IMPORTANT): GPS fix at: 1362354716.00
2013-03-03T23:51:51.294Z,1362354711.294 [Default:GPS:Read_GPS] Stopped
2013-03-03T23:51:51.294Z,1362354711.294 [Default:GPS:D] Running Loop=1
2013-03-03T23:51:51.757Z,1362354711.757 [Default:GPS:D] Stopped
2013-03-03T23:51:51.757Z,1362354711.757 [Default:GPS](INFO): Completed Default:GPS
2013-03-03T23:51:51.757Z,1362354711.757 [Default:GPS] Stopped
2013-03-03T23:51:51.757Z,1362354711.757 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-03-03T23:51:51.757Z,1362354711.757 [Default:GPS:A.SetSpeed] Stopped
2013-03-03T23:51:51.757Z,1362354711.757 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-03-03T23:52:50.480Z,1362354770.480 [NAL9602](INFO): SBD MO Status=2, MOMSN=6140, MT Status=2, MTMSN=0
2013-03-03T23:52:50.480Z,1362354770.480 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-03-03T23:53:44.841Z,1362354824.841 [NAL9602](INFO): SBD MO Status=2, MOMSN=6140, MT Status=2, MTMSN=0
2013-03-03T23:53:44.841Z,1362354824.842 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-03-03T23:53:58.702Z,1362354838.702 [NavChartDb](INFO): # of records loaded: 35000
2013-03-03T23:54:03.921Z,1362354843.921 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=6140, MT Status=1, MTMSN=482
2013-03-03T23:54:03.974Z,1362354843.974 [NAL9602](INFO): Sent 137 bytes from file Logs/20130303T225420/shore0008.lzma
2013-03-03T23:54:03.974Z,1362354843.974 [NAL9602](INFO): Packets left to send: 0
2013-03-03T23:54:03.976Z,1362354843.976 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T225420/shore0008.lzma.parts/0000.sbd
2013-03-03T23:54:04.475Z,1362354844.475 [NAL9602](INFO): Received command:gfscan
2013-03-03T23:54:04.547Z,1362354844.547 [CommandLine](IMPORTANT): got command gfscan
2013-03-03T23:54:04.752Z,1362354844.752 [CBIT](IMPORTANT): Beginning GF scan
2013-03-03T23:54:05.578Z,1362354845.579 [Radio_Freewave](INFO): Powering down
2013-03-03T23:54:05.920Z,1362354845.920 [Radio_Freewave](FAULT): LCB fault:  Software Overcurrent.
2013-03-03T23:54:05.920Z,1362354845.921 [Radio_Freewave] Hardware Fault, FailCount= 1
2013-03-03T23:54:05.920Z,1362354845.921 [Radio_Freewave](ERROR): Hardware Fault
2013-03-03T23:54:05.940Z,1362354845.940 [CBIT](ERROR): Hardware Fault in component: Radio_Freewave
2013-03-03T23:54:06.321Z,1362354846.321 [Radio_Freewave](INFO): Powering up
2013-03-03T23:54:06.501Z,1362354846.501 [CBIT](INFO): Clearing failed state for component Radio_Freewave
2013-03-03T23:54:06.501Z,1362354846.501 [Radio_Freewave] No Fault, FailCount= 1
2013-03-03T23:54:21.445Z,1362354861.445 [NAL9602](INFO): SBD MO Status=0, MOMSN=6141, MT Status=0, MTMSN=0
2013-03-03T23:54:38.821Z,1362354878.821 [NAL9602](INFO): SBD MO Status=1, MOMSN=6142, MT Status=0, MTMSN=0
2013-03-03T23:54:38.873Z,1362354878.873 [NAL9602](INFO): Sent 296 bytes from file Logs/20130303T225420/shore0009.lzma
2013-03-03T23:54:38.873Z,1362354878.874 [NAL9602](INFO): Packets left to send: 0
2013-03-03T23:54:38.875Z,1362354878.875 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T225420/shore0009.lzma.parts/0000.sbd
2013-03-03T23:54:50.466Z,1362354890.466 [NAL9602](INFO): SBD MO Status=0, MOMSN=6143, MT Status=0, MTMSN=0
2013-03-03T23:54:50.557Z,1362354890.557 [Default:Iridium:Read_Iridium] Stopped
2013-03-03T23:54:50.558Z,1362354890.558 [Default:Iridium](INFO): Completed Default:Iridium
2013-03-03T23:54:50.558Z,1362354890.558 [Default:Iridium] Stopped
2013-03-03T23:54:50.558Z,1362354890.558 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-03-03T23:54:50.558Z,1362354890.558 [Default:Iridium:A.SetSpeed] Stopped
2013-03-03T23:54:50.558Z,1362354890.558 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-03-03T23:54:50.836Z,1362354890.836 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-03-03T23:54:50.836Z,1362354890.836 [Default:CallIridium:B] Stopped
2013-03-03T23:54:50.836Z,1362354890.836 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-03-03T23:54:50.836Z,1362354890.836 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-03-03T23:54:50.836Z,1362354890.836 [Default:CallIridium] Stopped
2013-03-03T23:54:50.836Z,1362354890.836 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-03-03T23:55:01.021Z,1362354901.021 [NAL9602](INFO): Powering down
2013-03-03T23:58:12.499Z,1362355092.499 [NavChartDb](INFO): Done scanning nodes of Resources/US5CA62M.000
2013-03-03T23:58:12.614Z,1362355092.614 [NavChartDb](INFO): # of records loaded: 37376
2013-03-03T23:58:12.623Z,1362355092.623 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US5CA62M.000
2013-03-03T23:58:12.799Z,1362355092.799 [NavChartDb](INFO): Setup scan of Resources/US5CA83M.000
2013-03-03T23:59:51.021Z,1362355191.020 [Default:CallIridium] Running Loop=1
2013-03-03T23:59:51.021Z,1362355191.021 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-03-03T23:59:51.021Z,1362355191.021 [Default:CallIridium:A] Running Loop=1
2013-03-03T23:59:51.021Z,1362355191.021 [Default:CallIridium:A] Stopped
2013-03-03T23:59:51.021Z,1362355191.021 [Default:CallIridium:B] Running Loop=1
2013-03-03T23:59:51.022Z,1362355191.022 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-03-03T23:59:55.997Z,1362355195.997 [Default:Iridium] Running Loop=1
2013-03-03T23:59:55.997Z,1362355195.997 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-03-03T23:59:55.997Z,1362355195.997 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-03T23:59:55.997Z,1362355195.997 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-03-03T23:59:55.997Z,1362355195.997 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-03-03T23:59:55.997Z,1362355195.997 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-03T23:59:55.998Z,1362355195.998 [Default:Iridium:B.GoToSurface] Stopped
2013-03-03T23:59:55.998Z,1362355195.998 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-03T23:59:55.998Z,1362355195.998 [Default:Iridium:Read_Iridium] Running Loop=1
2013-03-03T23:59:55.999Z,1362355195.999 [Default:GPS] Running Loop=1
2013-03-03T23:59:55.999Z,1362355196.000 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-03-03T23:59:55.999Z,1362355196.000 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-03T23:59:55.000Z,1362355196.000 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-03-03T23:59:55.000Z,1362355196.000 [Default:GPS:B.GoToSurface] Running Loop=1
2013-03-03T23:59:55.000Z,1362355196.000 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-03T23:59:56.001Z,1362355196.001 [Default:GPS:B.GoToSurface] Stopped
2013-03-03T23:59:56.001Z,1362355196.001 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-03T23:59:56.001Z,1362355196.001 [Default:GPS:Read_GPS] Running Loop=1
2013-03-03T23:59:56.616Z,1362355196.616 [NAL9602](INFO): Powering up
2013-03-04T00:00:07.451Z,1362355207.451 [NAL9602](INFO): NAL9602 initialized
2013-03-04T00:00:35.173Z,1362355235.173 [NAL9602](INFO): SBD MO Status=1, MOMSN=6144, MT Status=0, MTMSN=0
2013-03-04T00:00:35.223Z,1362355235.223 [NAL9602](INFO): Sent 162 bytes from file Logs/20130303T225420/shore0010.lzma
2013-03-04T00:00:35.223Z,1362355235.223 [NAL9602](INFO): Packets left to send: 0
2013-03-04T00:00:35.225Z,1362355235.225 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T225420/shore0010.lzma.parts/0000.sbd
2013-03-04T00:00:44.371Z,1362355244.371 [NAL9602](INFO): SBD MO Status=0, MOMSN=6145, MT Status=0, MTMSN=0
2013-03-04T00:00:44.452Z,1362355244.452 [Default:Iridium:Read_Iridium] Stopped
2013-03-04T00:00:44.453Z,1362355244.453 [Default:Iridium](INFO): Completed Default:Iridium
2013-03-04T00:00:44.453Z,1362355244.453 [Default:Iridium] Stopped
2013-03-04T00:00:44.453Z,1362355244.453 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-03-04T00:00:44.453Z,1362355244.453 [Default:Iridium:A.SetSpeed] Stopped
2013-03-04T00:00:44.453Z,1362355244.453 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-03-04T00:00:44.787Z,1362355244.787 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-03-04T00:00:44.787Z,1362355244.787 [Default:CallIridium:B] Stopped
2013-03-04T00:00:44.787Z,1362355244.787 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-03-04T00:00:44.787Z,1362355244.787 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-03-04T00:00:44.787Z,1362355244.787 [Default:CallIridium] Stopped
2013-03-04T00:00:44.787Z,1362355244.787 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-03-04T00:00:45.577Z,1362355245.578 [NAL9602](IMPORTANT): GPS fix at: 1362355251.00
2013-03-04T00:00:45.596Z,1362355245.596 [Default:GPS:Read_GPS] Stopped
2013-03-04T00:00:45.596Z,1362355245.596 [Default:GPS:D] Running Loop=1
2013-03-04T00:00:46.096Z,1362355246.096 [Default:GPS:D] Stopped
2013-03-04T00:00:46.096Z,1362355246.096 [Default:GPS](INFO): Completed Default:GPS
2013-03-04T00:00:46.096Z,1362355246.096 [Default:GPS] Stopped
2013-03-04T00:00:46.097Z,1362355246.096 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-03-04T00:00:46.097Z,1362355246.097 [Default:GPS:A.SetSpeed] Stopped
2013-03-04T00:00:46.097Z,1362355246.097 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-03-04T00:01:06.557Z,1362355266.557 [NAL9602](INFO): Powering down
2013-03-04T00:03:22.095Z,1362355402.095 [CommandLine](IMPORTANT): got command ibit
2013-03-04T00:03:26.556Z,1362355406.556 [IBIT](IMPORTANT): Beginning Initiated BIT
2013-03-04T00:03:26.557Z,1362355406.556 [IBIT](IMPORTANT): Beginning control surface checks.

2013-03-04T00:03:26.558Z,1362355406.559 [CBIT](IMPORTANT): Beginning GF scan
2013-03-04T00:03:31.553Z,1362355411.553 [NAL9602](INFO): Powering up
2013-03-04T00:03:42.223Z,1362355422.223 [NAL9602](INFO): NAL9602 initialized
2013-03-04T00:03:52.687Z,1362355432.687 [CBIT](IMPORTANT): No ground fault detected
2013-03-04T00:03:55.443Z,1362355435.443 [NAL9602](IMPORTANT): GPS fix at: 1362355442.00
2013-03-04T00:03:58.647Z,1362355438.647 [NAL9602](IMPORTANT): GPS fix at: 1362355445.00
2013-03-04T00:04:01.443Z,1362355441.443 [NAL9602](IMPORTANT): GPS fix at: 1362355448.00
2013-03-04T00:04:04.304Z,1362355444.304 [NAL9602](IMPORTANT): GPS fix at: 1362355450.00
2013-03-04T00:04:07.451Z,1362355447.451 [NAL9602](IMPORTANT): GPS fix at: 1362355454.00
2013-03-04T00:04:10.255Z,1362355450.255 [NAL9602](IMPORTANT): GPS fix at: 1362355457.00
2013-03-04T00:04:13.455Z,1362355453.455 [NAL9602](IMPORTANT): GPS fix at: 1362355460.00
2013-03-04T00:04:16.255Z,1362355456.255 [NAL9602](IMPORTANT): GPS fix at: 1362355462.00
2013-03-04T00:04:19.456Z,1362355459.456 [NAL9602](IMPORTANT): GPS fix at: 1362355466.00
2013-03-04T00:04:22.255Z,1362355462.255 [NAL9602](IMPORTANT): GPS fix at: 1362355468.00
2013-03-04T00:04:25.450Z,1362355465.450 [NAL9602](IMPORTANT): GPS fix at: 1362355472.00
2013-03-04T00:04:28.255Z,1362355468.255 [NAL9602](IMPORTANT): GPS fix at: 1362355474.00
2013-03-04T00:04:31.455Z,1362355471.455 [NAL9602](IMPORTANT): GPS fix at: 1362355478.00
2013-03-04T00:04:34.255Z,1362355474.255 [NAL9602](IMPORTANT): GPS fix at: 1362355481.00
2013-03-04T00:04:37.451Z,1362355477.451 [NAL9602](IMPORTANT): GPS fix at: 1362355484.00
2013-03-04T00:04:40.255Z,1362355480.255 [NAL9602](IMPORTANT): GPS fix at: 1362355487.00
2013-03-04T00:04:43.455Z,1362355483.455 [NAL9602](IMPORTANT): GPS fix at: 1362355490.00
2013-03-04T00:04:46.287Z,1362355486.287 [NAL9602](IMPORTANT): GPS fix at: 1362355493.00
2013-03-04T00:04:49.492Z,1362355489.492 [NAL9602](IMPORTANT): GPS fix at: 1362355496.00
2013-03-04T00:04:52.250Z,1362355492.250 [NAL9602](IMPORTANT): GPS fix at: 1362355499.00
2013-03-04T00:04:55.515Z,1362355495.515 [NAL9602](IMPORTANT): GPS fix at: 1362355502.00
2013-03-04T00:04:58.255Z,1362355498.255 [NAL9602](IMPORTANT): GPS fix at: 1362355505.00
2013-03-04T00:05:01.450Z,1362355501.450 [NAL9602](IMPORTANT): GPS fix at: 1362355508.00
2013-03-04T00:05:04.255Z,1362355504.255 [NAL9602](IMPORTANT): GPS fix at: 1362355511.00
2013-03-04T00:05:07.451Z,1362355507.451 [NAL9602](IMPORTANT): GPS fix at: 1362355514.00
2013-03-04T00:05:10.295Z,1362355510.295 [NAL9602](IMPORTANT): GPS fix at: 1362355517.00
2013-03-04T00:05:13.455Z,1362355513.455 [NAL9602](IMPORTANT): GPS fix at: 1362355520.00
2013-03-04T00:05:16.255Z,1362355516.255 [NAL9602](IMPORTANT): GPS fix at: 1362355523.00
2013-03-04T00:05:17.584Z,1362355517.584 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired.
2013-03-04T00:05:17.949Z,1362355517.949 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 234.669998
Voltage: 16.159876
2013-03-04T00:05:17.950Z,1362355517.950 [IBIT](IMPORTANT): batteryCapacityThreshold: 5.000000 Ah
2013-03-04T00:05:17.950Z,1362355517.950 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.500000 V
2013-03-04T00:05:18.345Z,1362355518.345 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2013-03-04T00:05:18.345Z,1362355518.345 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2013-03-04T00:05:18.346Z,1362355518.346 [IBIT](IMPORTANT): Pressure:16.044212 PSI
2013-03-04T00:05:18.346Z,1362355518.346 [IBIT](IMPORTANT): Humidity:7.687750 %
2013-03-04T00:05:18.749Z,1362355518.749 [IBIT](IMPORTANT): surfaceThreshold: 0.500000 m
2013-03-04T00:05:18.749Z,1362355518.750 [IBIT](IMPORTANT): buoyancyNeutral: 498.000000 cc
2013-03-04T00:05:18.750Z,1362355518.750 [IBIT](IMPORTANT): massDefault: 1.090000 cm
2013-03-04T00:05:18.750Z,1362355518.750 [IBIT](IMPORTANT): stopDepth: 100.000000 m
2013-03-04T00:05:18.751Z,1362355518.750 [IBIT](IMPORTANT): abortDepth: 125.000000 m
2013-03-04T00:05:18.751Z,1362355518.751 [IBIT](IMPORTANT): IBIT FAILED
2013-03-04T00:05:24.244Z,1362355524.244 [NAL9602](IMPORTANT): GPS fix at: 1362355526.00
2013-03-04T00:05:49.224Z,1362355549.224 [NAL9602](INFO): Powering down
2013-03-04T00:05:49.243Z,1362355549.243 [Default:CallIridium] Running Loop=1
2013-03-04T00:05:49.243Z,1362355549.243 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-03-04T00:05:49.243Z,1362355549.243 [Default:CallIridium:A] Running Loop=1
2013-03-04T00:05:49.243Z,1362355549.243 [Default:CallIridium:A] Stopped
2013-03-04T00:05:49.243Z,1362355549.243 [Default:CallIridium:B] Running Loop=1
2013-03-04T00:05:49.244Z,1362355549.244 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-03-04T00:05:54.209Z,1362355554.209 [Default:Iridium] Running Loop=1
2013-03-04T00:05:54.209Z,1362355554.209 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-03-04T00:05:54.209Z,1362355554.209 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-04T00:05:54.209Z,1362355554.209 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-03-04T00:05:54.209Z,1362355554.209 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-03-04T00:05:54.209Z,1362355554.209 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-04T00:05:54.210Z,1362355554.210 [Default:Iridium:B.GoToSurface] Stopped
2013-03-04T00:05:54.210Z,1362355554.210 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-04T00:05:54.210Z,1362355554.210 [Default:Iridium:Read_Iridium] Running Loop=1
2013-03-04T00:05:54.211Z,1362355554.211 [Default:GPS] Running Loop=1
2013-03-04T00:05:54.211Z,1362355554.211 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-03-04T00:05:54.211Z,1362355554.211 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-04T00:05:54.211Z,1362355554.211 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-03-04T00:05:54.211Z,1362355554.211 [Default:GPS:B.GoToSurface] Running Loop=1
2013-03-04T00:05:54.211Z,1362355554.211 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-04T00:05:54.212Z,1362355554.212 [Default:GPS:B.GoToSurface] Stopped
2013-03-04T00:05:54.212Z,1362355554.212 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-04T00:05:54.212Z,1362355554.212 [Default:GPS:Read_GPS] Running Loop=1
2013-03-04T00:05:54.880Z,1362355554.880 [NAL9602](INFO): Powering up
2013-03-04T00:06:05.715Z,1362355565.715 [NAL9602](INFO): NAL9602 initialized
2013-03-04T00:06:29.576Z,1362355589.576 [NAL9602](INFO): SBD MO Status=1, MOMSN=6146, MT Status=0, MTMSN=0
2013-03-04T00:06:29.623Z,1362355589.623 [NAL9602](INFO): Sent 332 bytes from file Logs/20130303T225420/shore0011.lzma
2013-03-04T00:06:29.623Z,1362355589.623 [NAL9602](INFO): Packets left to send: 2
2013-03-04T00:06:29.626Z,1362355589.626 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T225420/shore0011.lzma.parts/0002.sbd
2013-03-04T00:06:40.706Z,1362355600.706 [NAL9602](INFO): SBD MO Status=1, MOMSN=6147, MT Status=0, MTMSN=0
2013-03-04T00:06:40.755Z,1362355600.755 [NAL9602](INFO): Sent 332 bytes from file Logs/20130303T225420/shore0011.lzma
2013-03-04T00:06:40.755Z,1362355600.755 [NAL9602](INFO): Packets left to send: 1
2013-03-04T00:06:40.757Z,1362355600.757 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T225420/shore0011.lzma.parts/0001.sbd
2013-03-04T00:07:48.000Z,1362355669.000 [NAL9602](ERROR): Verify xmit timeout failure.
2013-03-04T00:07:49.831Z,1362355669.830 [NAL9602](ERROR): Fill buffer uart error: serial timeout
2013-03-04T00:07:49.831Z,1362355669.831 [NAL9602](ERROR): Failed to receive READY. Modem reported: 
2013-03-04T00:08:25.298Z,1362355705.298 [NAL9602](INFO): SBD MO Status=1, MOMSN=6148, MT Status=0, MTMSN=0
2013-03-04T00:08:25.347Z,1362355705.347 [NAL9602](INFO): Sent 292 bytes from file Logs/20130303T225420/shore0011.lzma
2013-03-04T00:08:25.347Z,1362355705.347 [NAL9602](INFO): Packets left to send: 0
2013-03-04T00:08:25.348Z,1362355705.348 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T225420/shore0011.lzma.parts/0000.sbd
2013-03-04T00:08:44.602Z,1362355724.602 [NAL9602](INFO): SBD MO Status=2, MOMSN=6149, MT Status=2, MTMSN=0
2013-03-04T00:08:44.602Z,1362355724.602 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-03-04T00:08:45.704Z,1362355725.704 [NAL9602](IMPORTANT): GPS fix at: 1362355732.00
2013-03-04T00:08:45.721Z,1362355725.721 [Default:GPS:Read_GPS] Stopped
2013-03-04T00:08:45.721Z,1362355725.721 [Default:GPS:D] Running Loop=1
2013-03-04T00:08:46.131Z,1362355726.131 [Default:GPS:D] Stopped
2013-03-04T00:08:46.132Z,1362355726.132 [Default:GPS](INFO): Completed Default:GPS
2013-03-04T00:08:46.132Z,1362355726.132 [Default:GPS] Stopped
2013-03-04T00:08:46.132Z,1362355726.132 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-03-04T00:08:46.132Z,1362355726.132 [Default:GPS:A.SetSpeed] Stopped
2013-03-04T00:08:46.132Z,1362355726.132 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-03-04T00:09:02.423Z,1362355742.423 [CommandLine](IMPORTANT): got command gfscan
2013-03-04T00:09:02.513Z,1362355742.513 [NAL9602](INFO): SBD MO Status=2, MOMSN=6149, MT Status=2, MTMSN=0
2013-03-04T00:09:02.514Z,1362355742.514 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-03-04T00:09:02.614Z,1362355742.614 [CBIT](IMPORTANT): Beginning GF scan
2013-03-04T00:09:07.362Z,1362355747.362 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-03-04T00:09:10.607Z,1362355750.607 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-03-04T00:09:17.752Z,1362355757.751 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-03-04T00:09:22.193Z,1362355762.193 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-03-04T00:09:29.111Z,1362355769.111 [CBIT](INFO): No ground fault detected
2013-03-04T00:09:41.401Z,1362355781.401 [NAL9602](INFO): SBD MO Status=0, MOMSN=6149, MT Status=0, MTMSN=0
2013-03-04T00:09:41.496Z,1362355781.496 [Default:Iridium:Read_Iridium] Stopped
2013-03-04T00:09:41.496Z,1362355781.496 [Default:Iridium](INFO): Completed Default:Iridium
2013-03-04T00:09:41.496Z,1362355781.496 [Default:Iridium] Stopped
2013-03-04T00:09:41.496Z,1362355781.497 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-03-04T00:09:41.497Z,1362355781.497 [Default:Iridium:A.SetSpeed] Stopped
2013-03-04T00:09:41.497Z,1362355781.497 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-03-04T00:09:41.823Z,1362355781.823 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-03-04T00:09:41.824Z,1362355781.824 [Default:CallIridium:B] Stopped
2013-03-04T00:09:41.824Z,1362355781.824 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-03-04T00:09:41.824Z,1362355781.824 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-03-04T00:09:41.824Z,1362355781.824 [Default:CallIridium] Stopped
2013-03-04T00:09:41.824Z,1362355781.824 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-03-04T00:09:51.997Z,1362355791.997 [NAL9602](INFO): Powering down
2013-03-04T00:14:42.013Z,1362356082.013 [Default:CallIridium] Running Loop=1
2013-03-04T00:14:42.013Z,1362356082.013 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-03-04T00:14:42.013Z,1362356082.013 [Default:CallIridium:A] Running Loop=1
2013-03-04T00:14:42.014Z,1362356082.014 [Default:CallIridium:A] Stopped
2013-03-04T00:14:42.014Z,1362356082.014 [Default:CallIridium:B] Running Loop=1
2013-03-04T00:14:42.014Z,1362356082.014 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-03-04T00:14:47.013Z,1362356087.013 [Default:Iridium] Running Loop=1
2013-03-04T00:14:47.013Z,1362356087.013 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-03-04T00:14:47.013Z,1362356087.013 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-04T00:14:47.013Z,1362356087.013 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-03-04T00:14:47.013Z,1362356087.013 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-03-04T00:14:47.013Z,1362356087.013 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-04T00:14:47.014Z,1362356087.014 [Default:Iridium:B.GoToSurface] Stopped
2013-03-04T00:14:47.014Z,1362356087.014 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-04T00:14:47.014Z,1362356087.014 [Default:Iridium:Read_Iridium] Running Loop=1
2013-03-04T00:14:47.015Z,1362356087.015 [Default:GPS] Running Loop=1
2013-03-04T00:14:47.015Z,1362356087.015 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-03-04T00:14:47.015Z,1362356087.015 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-04T00:14:47.015Z,1362356087.015 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-03-04T00:14:47.015Z,1362356087.015 [Default:GPS:B.GoToSurface] Running Loop=1
2013-03-04T00:14:47.015Z,1362356087.015 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-04T00:14:47.016Z,1362356087.016 [Default:GPS:B.GoToSurface] Stopped
2013-03-04T00:14:47.016Z,1362356087.016 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-04T00:14:47.016Z,1362356087.016 [Default:GPS:Read_GPS] Running Loop=1
2013-03-04T00:14:47.684Z,1362356087.684 [NAL9602](INFO): Powering up
2013-03-04T00:14:58.523Z,1362356098.523 [NAL9602](INFO): NAL9602 initialized
2013-03-04T00:15:23.997Z,1362356123.997 [NAL9602](INFO): SBD MO Status=2, MOMSN=6150, MT Status=2, MTMSN=0
2013-03-04T00:15:23.998Z,1362356123.997 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-03-04T00:15:25.200Z,1362356125.200 [NAL9602](IMPORTANT): GPS fix at: 1362356132.00
2013-03-04T00:15:25.216Z,1362356125.216 [Default:GPS:Read_GPS] Stopped
2013-03-04T00:15:25.216Z,1362356125.217 [Default:GPS:D] Running Loop=1
2013-03-04T00:15:25.660Z,1362356125.660 [Default:GPS:D] Stopped
2013-03-04T00:15:25.660Z,1362356125.660 [Default:GPS](INFO): Completed Default:GPS
2013-03-04T00:15:25.660Z,1362356125.660 [Default:GPS] Stopped
2013-03-04T00:15:25.660Z,1362356125.660 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-03-04T00:15:25.660Z,1362356125.661 [Default:GPS:A.SetSpeed] Stopped
2013-03-04T00:15:25.660Z,1362356125.661 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-03-04T00:15:53.132Z,1362356153.132 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=6150, MT Status=1, MTMSN=483
2013-03-04T00:15:53.187Z,1362356153.187 [NAL9602](INFO): Sent 182 bytes from file Logs/20130303T225420/shore0012.lzma
2013-03-04T00:15:53.187Z,1362356153.187 [NAL9602](INFO): Packets left to send: 0
2013-03-04T00:15:53.189Z,1362356153.189 [NAL9602](INFO): Stored copy of sent data in Logs/20130303T225420/shore0012.lzma.parts/0000.sbd
2013-03-04T00:15:53.639Z,1362356153.639 [NAL9602](INFO): Received command:gfscan
2013-03-04T00:15:53.663Z,1362356153.663 [CommandLine](IMPORTANT): got command gfscan
2013-03-04T00:15:53.746Z,1362356153.746 [CBIT](IMPORTANT): Beginning GF scan
2013-03-04T00:16:20.081Z,1362356180.081 [CBIT](INFO): No ground fault detected
2013-03-04T00:17:03.621Z,1362356223.621 [NAL9602](ERROR): Verify xmit timeout failure.
2013-03-04T00:17:15.176Z,1362356235.176 [NAL9602](INFO): SBD MO Status=2, MOMSN=6151, MT Status=2, MTMSN=0
2013-03-04T00:17:15.176Z,1362356235.176 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-03-04T00:17:20.427Z,1362356240.427 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-03-04T00:17:30.433Z,1362356250.433 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-03-04T00:17:35.324Z,1362356255.323 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-03-04T00:17:52.893Z,1362356272.893 [NAL9602](INFO): SBD MO Status=2, MOMSN=6151, MT Status=2, MTMSN=0
2013-03-04T00:17:52.894Z,1362356272.894 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-03-04T00:17:58.093Z,1362356278.093 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-03-04T00:18:04.125Z,1362356284.125 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-03-04T00:18:06.521Z,1362356286.521 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-03-04T00:18:10.538Z,1362356290.538 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-03-04T00:18:14.109Z,1362356294.109 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-03-04T00:18:22.510Z,1362356302.510 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-03-04T00:18:26.888Z,1362356306.888 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-03-04T00:18:29.709Z,1362356309.709 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-03-04T00:18:34.071Z,1362356314.071 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-03-04T00:18:43.664Z,1362356323.664 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-03-04T00:18:48.089Z,1362356328.089 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-03-04T00:18:51.333Z,1362356331.333 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-03-04T00:19:00.118Z,1362356340.118 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-03-04T00:19:04.522Z,1362356344.522 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-03-04T00:19:08.888Z,1362356348.888 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-03-04T00:19:13.288Z,1362356353.288 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-03-04T00:19:33.345Z,1362356373.345 [NAL9602](INFO): SBD MO Status=2, MOMSN=6151, MT Status=2, MTMSN=0
2013-03-04T00:19:33.345Z,1362356373.345 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-03-04T00:19:46.145Z,1362356386.145 [NAL9602](INFO): SBD MO Status=0, MOMSN=6151, MT Status=0, MTMSN=0
2013-03-04T00:20:02.929Z,1362356402.930 [NAL9602](INFO): SBD MO Status=2, MOMSN=6152, MT Status=2, MTMSN=0
2013-03-04T00:20:02.930Z,1362356402.930 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2