2013-04-04T20:35:37.865Z,1365107737.865 [Supervisor](DEBUG): Initializing supervisor.
2013-04-04T20:35:37.868Z,1365107737.868 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0
2013-04-04T20:35:37.869Z,1365107737.869 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2013-04-04T20:35:37.870Z,1365107737.870 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0
2013-04-04T20:35:37.875Z,1365107737.875 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2013-04-04T20:35:37.885Z,1365107737.885 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2013-04-04T20:35:37.886Z,1365107737.886 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0
2013-04-04T20:35:37.887Z,1365107737.887 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2013-04-04T20:35:37.888Z,1365107737.888 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0
2013-04-04T20:35:37.889Z,1365107737.889 [Supervisor](INFO): Looking for Config files in directory: Config/
2013-04-04T20:35:37.893Z,1365107737.894 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2013-04-04T20:35:38.431Z,1365107738.431 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2013-04-04T20:35:38.431Z,1365107738.431 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2013-04-04T20:35:38.620Z,1365107738.620 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2013-04-04T20:35:38.620Z,1365107738.620 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2013-04-04T20:35:38.707Z,1365107738.707 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2013-04-04T20:35:38.709Z,1365107738.709 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2013-04-04T20:35:38.889Z,1365107738.889 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2013-04-04T20:35:38.889Z,1365107738.889 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2013-04-04T20:35:39.029Z,1365107739.029 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2013-04-04T20:35:39.032Z,1365107739.032 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2013-04-04T20:35:39.263Z,1365107739.263 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2013-04-04T20:35:39.264Z,1365107739.264 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2013-04-04T20:35:39.433Z,1365107739.433 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2013-04-04T20:35:39.435Z,1365107739.435 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2013-04-04T20:35:39.688Z,1365107739.688 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2013-04-04T20:35:39.690Z,1365107739.690 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2013-04-04T20:35:39.791Z,1365107739.791 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2013-04-04T20:35:39.791Z,1365107739.791 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2013-04-04T20:35:40.187Z,1365107740.187 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2013-04-04T20:35:40.188Z,1365107740.188 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2013-04-04T20:35:40.303Z,1365107740.303 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2013-04-04T20:35:40.304Z,1365107740.304 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2013-04-04T20:35:40.390Z,1365107740.390 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2013-04-04T20:35:40.394Z,1365107740.395 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2013-04-04T20:35:40.498Z,1365107740.498 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2013-04-04T20:35:40.627Z,1365107740.627 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2013-04-04T20:35:40.714Z,1365107740.714 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2013-04-04T20:35:40.818Z,1365107740.818 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2013-04-04T20:35:40.920Z,1365107740.920 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2013-04-04T20:35:41.039Z,1365107741.039 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2013-04-04T20:35:41.135Z,1365107741.135 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2013-04-04T20:35:41.223Z,1365107741.223 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2013-04-04T20:35:41.254Z,1365107741.254 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2013-04-04T20:35:41.431Z,1365107741.431 [InternalSim] Loaded
2013-04-04T20:35:41.432Z,1365107741.432 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2013-04-04T20:35:41.433Z,1365107741.432 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2013-04-04T20:35:41.433Z,1365107741.433 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2013-04-04T20:35:41.508Z,1365107741.508 [SBIT](DEBUG): Construct Startup Built In Test.
2013-04-04T20:35:41.537Z,1365107741.537 [SBIT] Loaded
2013-04-04T20:35:41.537Z,1365107741.537 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2013-04-04T20:35:41.538Z,1365107741.538 [IBIT](DEBUG): Construct Initiated Built In Test.
2013-04-04T20:35:41.567Z,1365107741.567 [IBIT] Loaded
2013-04-04T20:35:41.567Z,1365107741.567 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2013-04-04T20:35:41.570Z,1365107741.570 [CBIT](DEBUG): Construct CBIT Built In Test.
2013-04-04T20:35:41.689Z,1365107741.689 [CBIT] Loaded
2013-04-04T20:35:41.689Z,1365107741.689 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2013-04-04T20:35:41.689Z,1365107741.689 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2013-04-04T20:35:41.690Z,1365107741.690 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2013-04-04T20:35:41.856Z,1365107741.856 [BuoyancyServo] Loaded
2013-04-04T20:35:41.856Z,1365107741.856 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2013-04-04T20:35:41.868Z,1365107741.868 [ElevatorServo] Loaded
2013-04-04T20:35:41.869Z,1365107741.869 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2013-04-04T20:35:41.881Z,1365107741.881 [MassServo] Loaded
2013-04-04T20:35:41.881Z,1365107741.881 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2013-04-04T20:35:41.893Z,1365107741.893 [RudderServo] Loaded
2013-04-04T20:35:41.893Z,1365107741.893 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2013-04-04T20:35:41.905Z,1365107741.905 [ThrusterServo] Loaded
2013-04-04T20:35:41.905Z,1365107741.905 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2013-04-04T20:35:41.906Z,1365107741.906 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2013-04-04T20:35:41.906Z,1365107741.906 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2013-04-04T20:35:41.935Z,1365107741.935 [DepthRateCalculator] Loaded
2013-04-04T20:35:41.935Z,1365107741.935 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2013-04-04T20:35:45.004Z,1365107745.004 [HFRadarModelCalc] Loaded
2013-04-04T20:35:45.005Z,1365107745.005 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2013-04-04T20:35:45.021Z,1365107745.021 [NavChart] Loaded
2013-04-04T20:35:45.021Z,1365107745.021 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2013-04-04T20:35:45.027Z,1365107745.027 [PitchRateCalculator] Loaded
2013-04-04T20:35:45.027Z,1365107745.027 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2013-04-04T20:35:45.033Z,1365107745.033 [SpeedCalculator] Loaded
2013-04-04T20:35:45.034Z,1365107745.034 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2013-04-04T20:35:45.048Z,1365107745.048 [TempGradientCalculator] Loaded
2013-04-04T20:35:45.049Z,1365107745.049 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2013-04-04T20:35:45.054Z,1365107745.055 [YawRateCalculator] Loaded
2013-04-04T20:35:45.055Z,1365107745.055 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2013-04-04T20:35:45.095Z,1365107745.095 [Navigation] Loaded
2013-04-04T20:35:45.096Z,1365107745.096 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread.
2013-04-04T20:35:45.096Z,1365107745.096 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2013-04-04T20:35:45.097Z,1365107745.097 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2013-04-04T20:35:45.338Z,1365107745.338 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2013-04-04T20:35:45.339Z,1365107745.339 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2013-04-04T20:35:45.372Z,1365107745.372 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2013-04-04T20:35:45.373Z,1365107745.373 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2013-04-04T20:35:45.423Z,1365107745.423 [VerticalControl](DEBUG): Construct VerticalControl.
2013-04-04T20:35:45.517Z,1365107745.517 [VerticalControl] Loaded
2013-04-04T20:35:45.517Z,1365107745.517 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2013-04-04T20:35:45.518Z,1365107745.518 [HorizontalControl](DEBUG): Construct HorizontalControl.
2013-04-04T20:35:45.574Z,1365107745.574 [HorizontalControl] Loaded
2013-04-04T20:35:45.575Z,1365107745.575 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2013-04-04T20:35:45.576Z,1365107745.576 [SpeedControl](DEBUG): Construct SpeedControl.
2013-04-04T20:35:45.577Z,1365107745.577 [SpeedControl] Loaded
2013-04-04T20:35:45.578Z,1365107745.578 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2013-04-04T20:35:45.578Z,1365107745.579 [LoopControl](DEBUG): Construct LoopControl.
2013-04-04T20:35:45.579Z,1365107745.579 [LoopControl] Loaded
2013-04-04T20:35:45.579Z,1365107745.579 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2013-04-04T20:35:45.580Z,1365107745.580 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2013-04-04T20:35:45.580Z,1365107745.580 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2013-04-04T20:35:45.592Z,1365107745.592 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator.
2013-04-04T20:35:45.597Z,1365107745.597 [AsyncPiEstimator] Loaded
2013-04-04T20:35:45.598Z,1365107745.598 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread.
2013-04-04T20:35:45.599Z,1365107745.599 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 4063B4E0
2013-04-04T20:35:45.600Z,1365107745.600 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2013-04-04T20:35:45.600Z,1365107745.600 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2013-04-04T20:35:45.757Z,1365107745.757 [AHRS_sp3003D] Loaded
2013-04-04T20:35:45.758Z,1365107745.758 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2013-04-04T20:35:46.015Z,1365107746.016 [Batt_Ocean_Server] Loaded
2013-04-04T20:35:46.016Z,1365107746.016 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2013-04-04T20:35:46.029Z,1365107746.029 [Depth_Keller] Loaded
2013-04-04T20:35:46.029Z,1365107746.029 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2013-04-04T20:35:46.035Z,1365107746.035 [DropWeight] Loaded
2013-04-04T20:35:46.036Z,1365107746.036 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2013-04-04T20:35:46.210Z,1365107746.210 [DVL_micro] Loaded
2013-04-04T20:35:46.210Z,1365107746.210 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread.
2013-04-04T20:35:46.211Z,1365107746.211 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 406BF4E0
2013-04-04T20:35:46.293Z,1365107746.293 [NAL9602] Loaded
2013-04-04T20:35:46.293Z,1365107746.293 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2013-04-04T20:35:46.344Z,1365107746.344 [Onboard] Loaded
2013-04-04T20:35:46.344Z,1365107746.344 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2013-04-04T20:35:46.351Z,1365107746.351 [Radio_Freewave] Loaded
2013-04-04T20:35:46.351Z,1365107746.351 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread.
2013-04-04T20:35:46.352Z,1365107746.352 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2013-04-04T20:35:46.353Z,1365107746.353 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2013-04-04T20:35:46.444Z,1365107746.444 [CTD_NeilBrown] Loaded
2013-04-04T20:35:46.444Z,1365107746.444 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2013-04-04T20:35:46.446Z,1365107746.446 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 407114E0
2013-04-04T20:35:46.463Z,1365107746.463 [PAR_Licor] Loaded
2013-04-04T20:35:46.463Z,1365107746.463 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2013-04-04T20:35:46.493Z,1365107746.493 [WetLabsBB2FL] Loaded
2013-04-04T20:35:46.493Z,1365107746.493 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2013-04-04T20:35:46.494Z,1365107746.494 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407414E0
2013-04-04T20:35:46.495Z,1365107746.495 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2013-04-04T20:35:46.497Z,1365107746.497 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2013-04-04T20:35:46.498Z,1365107746.498 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2013-04-04T20:35:46.504Z,1365107746.504 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2013-04-04T20:35:46.506Z,1365107746.506 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 407714E0
2013-04-04T20:35:46.510Z,1365107746.510 [Supervisor](DEBUG): Running supervisor.
2013-04-04T20:35:46.511Z,1365107746.511 [CommandLine](INFO): Thread ID is 3445
2013-04-04T20:35:46.514Z,1365107746.514 [controlThread](INFO): Thread ID is 3444
2013-04-04T20:35:46.514Z,1365107746.514 [controlThread](DEBUG): Initializing ControlThread
2013-04-04T20:35:46.514Z,1365107746.514 [CycleStarter](INFO): Thread ID is 3443
2013-04-04T20:35:46.515Z,1365107746.515 [InternalSim](DEBUG):  InternalSim initializing...
2013-04-04T20:35:46.544Z,1365107746.544 [logger](INFO): Thread ID is 3446
2013-04-04T20:35:46.583Z,1365107746.583 [AsyncPiEstimator](INFO): Thread ID is 3507
2013-04-04T20:35:46.583Z,1365107746.583 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator.
2013-04-04T20:35:46.592Z,1365107746.592 [SBIT](INFO): Initialize SBIT Component.
2013-04-04T20:35:46.593Z,1365107746.593 [SBIT](IMPORTANT): Tethys CM Info:
$Rev:10279
2013-04-04T20:35:46.593Z,1365107746.593 [SBIT](IMPORTANT): Kernel Release:2.6.27.8
2013-04-04T20:35:46.594Z,1365107746.594 [SBIT](FAULT): Kernel Reporting Different Version From Configuration.
Expected:#634 PREEMPT Wed Feb 13 10:21:48 PST 2013
Kernel Reported:#625 PREEMPT Mon Nov 5 10:42:26 PST 2012
2013-04-04T20:35:46.594Z,1365107746.594 [IBIT](INFO): Initialize IBIT Component.
2013-04-04T20:35:46.595Z,1365107746.595 [CBIT](DEBUG): Initialize CBIT Component.
2013-04-04T20:35:46.595Z,1365107746.595 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2013-04-04T20:35:46.599Z,1365107746.599 [DVL_micro](INFO): Thread ID is 3508
2013-04-04T20:35:46.609Z,1365107746.609 [DVL_micro](INFO): Initializing
2013-04-04T20:35:46.609Z,1365107746.609 [DVL_micro](INFO): start:Powering up
2013-04-04T20:35:46.610Z,1365107746.610 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-04-04T20:35:46.611Z,1365107746.611 [DVL_micro](INFO): Cycling power to configure device.
2013-04-04T20:35:46.620Z,1365107746.620 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2013-04-04T20:35:46.620Z,1365107746.620 [NavChart](DEBUG): Initialize NavChart Derivation.
2013-04-04T20:35:46.621Z,1365107746.621 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2013-04-04T20:35:46.621Z,1365107746.621 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2013-04-04T20:35:46.621Z,1365107746.621 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2013-04-04T20:35:46.623Z,1365107746.623 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2013-04-04T20:35:46.623Z,1365107746.623 [Navigation](DEBUG): Initializing Navigation.
2013-04-04T20:35:46.624Z,1365107746.624 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2013-04-04T20:35:46.626Z,1365107746.626 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2013-04-04T20:35:46.626Z,1365107746.626 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2013-04-04T20:35:46.627Z,1365107746.627 [LoopControl](DEBUG): Initialize LoopControlComponent.
2013-04-04T20:35:46.631Z,1365107746.631 [CTD_NeilBrown](INFO): Thread ID is 3509
2013-04-04T20:35:46.632Z,1365107746.632 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2013-04-04T20:35:46.635Z,1365107746.635 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2013-04-04T20:35:46.636Z,1365107746.636 [WetLabsBB2FL](INFO): Thread ID is 3510
2013-04-04T20:35:46.637Z,1365107746.637 [WetLabsBB2FL](INFO): Powering down
2013-04-04T20:35:46.687Z,1365107746.687 [NavChartDb](INFO): Thread ID is 3511
2013-04-04T20:35:46.693Z,1365107746.693 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2013-04-04T20:35:46.694Z,1365107746.694 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2013-04-04T20:35:46.695Z,1365107746.694 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2013-04-04T20:35:46.695Z,1365107746.695 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2013-04-04T20:35:46.695Z,1365107746.695 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2013-04-04T20:35:46.695Z,1365107746.695 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2013-04-04T20:35:46.696Z,1365107746.696 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2013-04-04T20:35:46.696Z,1365107746.696 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2013-04-04T20:35:46.696Z,1365107746.696 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2013-04-04T20:35:48.463Z,1365107748.463 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2013-04-04T20:35:48.494Z,1365107748.494 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2013-04-04T20:35:48.525Z,1365107748.525 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2013-04-04T20:35:48.559Z,1365107748.559 [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-04-04T20:35:48.560Z,1365107748.560 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2013-04-04T20:35:48.664Z,1365107748.664 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2013-04-04T20:35:48.666Z,1365107748.666 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2013-04-04T20:35:48.669Z,1365107748.669 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-04-04T20:35:48.693Z,1365107748.693 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2013-04-04T20:35:48.708Z,1365107748.708 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-04-04T20:35:48.715Z,1365107748.715 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2013-04-04T20:35:48.723Z,1365107748.723 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-04-04T20:35:48.735Z,1365107748.735 [DVL_micro](INFO): Querying output modes
2013-04-04T20:35:48.735Z,1365107748.735 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-04-04T20:35:48.737Z,1365107748.737 [Default:D.SetSpeed](DEBUG): Construct.
2013-04-04T20:35:48.740Z,1365107748.740 [Default:E.GoToSurface](DEBUG): Construct GoToSurface.
2013-04-04T20:35:48.745Z,1365107748.745 [Default:F.Wait](DEBUG): Construct Wait.
2013-04-04T20:35:48.751Z,1365107748.751 [DVL_micro](DEBUG): cmdResponse: 01
2013-04-04T20:35:48.751Z,1365107748.751 [DVL_micro](INFO): NQ1 output enabled
2013-04-04T20:35:48.751Z,1365107748.751 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-04-04T20:35:48.763Z,1365107748.763 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 
2013-04-04T20:35:48.768Z,1365107748.768 [DVL_micro](INFO): pause:Powering down
2013-04-04T20:35:48.792Z,1365107748.792 [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-04-04T20:35:48.797Z,1365107748.797 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,NAL9602,Onboard,Radio_Freewave,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-04-04T20:35:48.833Z,1365107748.833 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-04-04T20:35:48.901Z,1365107748.901 [Depth_Keller](ERROR): Pressure reading out of range: 1831.078247 decibar
2013-04-04T20:35:48.987Z,1365107748.987 [Radio_Freewave](INFO): Powering up
2013-04-04T20:35:49.245Z,1365107749.245 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2013-04-04T20:35:49.267Z,1365107749.267 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2013-04-04T20:35:49.295Z,1365107749.295 [ElevatorServo](DEBUG): Initializing EZServoServo.
2013-04-04T20:35:49.301Z,1365107749.300 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2013-04-04T20:35:49.307Z,1365107749.307 [MassServo](DEBUG): Initializing EZServoServo.
2013-04-04T20:35:49.315Z,1365107749.315 [MassServo](DEBUG): Initializing MassServo.
2013-04-04T20:35:49.321Z,1365107749.321 [RudderServo](DEBUG): Initializing EZServoServo.
2013-04-04T20:35:49.327Z,1365107749.327 [RudderServo](DEBUG): Initializing RudderServo.
2013-04-04T20:35:49.333Z,1365107749.332 [ThrusterServo](DEBUG): Initializing EZServoServo.
2013-04-04T20:35:49.339Z,1365107749.339 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2013-04-04T20:35:51.327Z,1365107751.327 [NAL9602](INFO): Powering up NAL9602
2013-04-04T20:36:01.807Z,1365107761.807 [NAL9602](INFO): NAL9602 initialized
2013-04-04T20:36:02.241Z,1365107762.241 [SBIT](IMPORTANT): Beginning Startup BIT
2013-04-04T20:36:02.243Z,1365107762.243 [CBIT](IMPORTANT): Beginning GF scan
2013-04-04T20:36:28.805Z,1365107788.805 [CBIT](FAULT): Chan 1 High side GF detected
mA:
CHAN 5 (24V): 0.085130
CHAN 4 (Batt): 0.051461
CHAN 2 (12V): 0.039409
CHAN 1 (5V): 0.017122
CHAN 0 (3.3V): 0.011765
OPEN: 0.000765
Full Scale Calc: 0.392
2013-04-04T20:36:33.084Z,1365107793.084 [NAL9602](IMPORTANT): GPS fix at: 1365108062.00
2013-04-04T20:36:40.324Z,1365107800.324 [NAL9602](INFO): Powering down
2013-04-04T20:36:55.965Z,1365107815.965 [SBIT](IMPORTANT): SBIT PASSED
2013-04-04T20:36:56.386Z,1365107816.386 [MissionManager](IMPORTANT): Started mission Startup
2013-04-04T20:36:56.386Z,1365107816.386 [Startup] Running Loop=1
2013-04-04T20:36:56.386Z,1365107816.386 [Startup](INFO): Aggregate::initialize Startup
2013-04-04T20:36:56.386Z,1365107816.386 [Startup:A.GoToSurface] Running Loop=1
2013-04-04T20:36:56.386Z,1365107816.386 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-04-04T20:36:56.392Z,1365107816.392 [Startup:StartupSatComms] Running Loop=1
2013-04-04T20:36:56.392Z,1365107816.392 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2013-04-04T20:36:56.392Z,1365107816.392 [Startup:StartupSatComms:A] Running Loop=1
2013-04-04T20:36:56.745Z,1365107816.745 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2013-04-04T20:36:57.136Z,1365107817.136 [NAL9602](INFO): Powering up
2013-04-04T20:37:07.963Z,1365107827.963 [NAL9602](INFO): NAL9602 initialized
2013-04-04T20:37:56.746Z,1365107876.746 [Startup:StartupSatComms:A](INFO): Timed out from 2013-04-04T20:36:56.4Z
2013-04-04T20:37:56.759Z,1365107876.759 [Startup:StartupSatComms:A:A_Timeout] Running Loop=1
2013-04-04T20:37:56.760Z,1365107876.760 [Startup:StartupSatComms:A:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:A:A_Timeout
2013-04-04T20:37:56.760Z,1365107876.760 [Startup:StartupSatComms:A:A_Timeout](INFO): Completed Startup:StartupSatComms:A:A_Timeout
2013-04-04T20:37:56.760Z,1365107876.760 [Startup:StartupSatComms:A] Stopped
2013-04-04T20:37:56.760Z,1365107876.760 [Startup:StartupSatComms:B] Running Loop=1
2013-04-04T20:37:57.157Z,1365107877.157 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2013-04-04T20:38:15.693Z,1365107895.693 [NAL9602](INFO): SBD MO Status=1, MOMSN=9719, MT Status=0, MTMSN=0
2013-04-04T20:38:15.743Z,1365107895.743 [NAL9602](INFO): Sent 204 bytes from file Logs/20130402T222152/shore0057.lzma
2013-04-04T20:38:15.743Z,1365107895.743 [NAL9602](INFO): Packets left to send: 0
2013-04-04T20:38:15.745Z,1365107895.745 [NAL9602](INFO): Stored copy of sent data in Logs/20130402T222152/shore0057.lzma.parts/0000.sbd
2013-04-04T20:38:37.958Z,1365107917.958 [NAL9602](INFO): SBD MO Status=2, MOMSN=9720, MT Status=2, MTMSN=0
2013-04-04T20:38:37.958Z,1365107917.958 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-04-04T20:38:56.966Z,1365107936.966 [Startup:StartupSatComms:B](INFO): Timed out from 2013-04-04T20:37:56.8Z
2013-04-04T20:38:56.966Z,1365107936.966 [Startup:StartupSatComms:B:A_Timeout] Running Loop=1
2013-04-04T20:38:56.966Z,1365107936.966 [Startup:StartupSatComms:B:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:B:A_Timeout
2013-04-04T20:38:56.966Z,1365107936.967 [Startup:StartupSatComms:B:A_Timeout](INFO): Completed Startup:StartupSatComms:B:A_Timeout
2013-04-04T20:38:56.967Z,1365107936.967 [Startup:StartupSatComms:B] Stopped
2013-04-04T20:38:56.967Z,1365107936.967 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2013-04-04T20:38:56.967Z,1365107936.967 [Startup:StartupSatComms] Stopped
2013-04-04T20:38:56.967Z,1365107936.967 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2013-04-04T20:38:56.968Z,1365107936.968 [Startup](INFO): Completed Startup
2013-04-04T20:38:56.968Z,1365107936.968 [Startup] Stopped
2013-04-04T20:38:56.968Z,1365107936.968 [Startup](INFO): Aggregate::uninitialize Startup
2013-04-04T20:38:56.968Z,1365107936.968 [Startup:A.GoToSurface] Stopped
2013-04-04T20:38:56.968Z,1365107936.968 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-04-04T20:38:57.391Z,1365107937.391 [MissionManager](IMPORTANT): Started mission Default
2013-04-04T20:38:57.391Z,1365107937.391 [Default] Running Loop=1
2013-04-04T20:38:57.391Z,1365107937.391 [Default](INFO): Aggregate::initialize Default
2013-04-04T20:38:57.391Z,1365107937.391 [Default:D.SetSpeed] Running Loop=1
2013-04-04T20:38:57.391Z,1365107937.391 [Default:D.SetSpeed](DEBUG): Initialize.
2013-04-04T20:38:57.392Z,1365107937.392 [Default:E.GoToSurface] Running Loop=1
2013-04-04T20:38:57.392Z,1365107937.392 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-04-04T20:38:57.392Z,1365107937.392 [Default:Iridium] Running Loop=1
2013-04-04T20:38:57.392Z,1365107937.392 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-04-04T20:38:57.392Z,1365107937.392 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-04-04T20:38:57.392Z,1365107937.392 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-04-04T20:38:57.393Z,1365107937.392 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-04-04T20:38:57.393Z,1365107937.393 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-04-04T20:38:57.393Z,1365107937.393 [Default:E.GoToSurface] Running Loop=1
2013-04-04T20:38:57.399Z,1365107937.399 [Default:D.SetSpeed] Running Loop=1
2013-04-04T20:38:57.404Z,1365107937.404 [Default:CallIridium] Running Loop=1
2013-04-04T20:38:57.404Z,1365107937.404 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-04-04T20:38:57.404Z,1365107937.404 [Default:CallIridium:A] Running Loop=1
2013-04-04T20:38:57.406Z,1365107937.406 [Default:CallIridium:A] Stopped
2013-04-04T20:38:57.406Z,1365107937.406 [Default:CallIridium:B] Running Loop=1
2013-04-04T20:38:57.406Z,1365107937.406 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-04-04T20:38:57.412Z,1365107937.411 [Default:Iridium:B.GoToSurface] Stopped
2013-04-04T20:38:57.412Z,1365107937.412 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-04-04T20:38:57.412Z,1365107937.412 [Default:Iridium:Read_Iridium] Running Loop=1
2013-04-04T20:38:57.412Z,1365107937.412 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-04-04T20:38:57.417Z,1365107937.417 [Default:GPS] Running Loop=1
2013-04-04T20:38:57.417Z,1365107937.417 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-04-04T20:38:57.417Z,1365107937.417 [Default:GPS:A.SetSpeed] Running Loop=1
2013-04-04T20:38:57.417Z,1365107937.417 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-04-04T20:38:57.417Z,1365107937.417 [Default:GPS:B.GoToSurface] Running Loop=1
2013-04-04T20:38:57.417Z,1365107937.417 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-04-04T20:38:57.423Z,1365107937.423 [Default:GPS:B.GoToSurface] Stopped
2013-04-04T20:38:57.423Z,1365107937.423 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-04-04T20:38:57.423Z,1365107937.423 [Default:GPS:Read_GPS] Running Loop=1
2013-04-04T20:38:57.423Z,1365107937.423 [Default:GPS:A.SetSpeed] Running Loop=1
2013-04-04T20:38:57.763Z,1365107937.763 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2013-04-04T20:38:57.766Z,1365107937.766 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2013-04-04T20:38:59.402Z,1365107939.402 [NAL9602](INFO): SBD MO Status=1, MOMSN=9720, MT Status=0, MTMSN=0
2013-04-04T20:38:59.459Z,1365107939.459 [NAL9602](INFO): Sent 332 bytes from file Logs/20130404T203537/shore0000.lzma
2013-04-04T20:38:59.459Z,1365107939.459 [NAL9602](INFO): Packets left to send: 2
2013-04-04T20:38:59.460Z,1365107939.460 [NAL9602](INFO): Stored copy of sent data in Logs/20130404T203537/shore0000.lzma.parts/0002.sbd
2013-04-04T20:39:12.421Z,1365107952.421 [NAL9602](INFO): SBD MO Status=1, MOMSN=9721, MT Status=0, MTMSN=0
2013-04-04T20:39:12.471Z,1365107952.471 [NAL9602](INFO): Sent 332 bytes from file Logs/20130404T203537/shore0000.lzma
2013-04-04T20:39:12.471Z,1365107952.471 [NAL9602](INFO): Packets left to send: 1
2013-04-04T20:39:12.472Z,1365107952.472 [NAL9602](INFO): Stored copy of sent data in Logs/20130404T203537/shore0000.lzma.parts/0001.sbd
2013-04-04T20:39:24.293Z,1365107964.293 [NAL9602](INFO): SBD MO Status=1, MOMSN=9722, MT Status=0, MTMSN=0
2013-04-04T20:39:24.343Z,1365107964.343 [NAL9602](INFO): Sent 243 bytes from file Logs/20130404T203537/shore0000.lzma
2013-04-04T20:39:24.343Z,1365107964.343 [NAL9602](INFO): Packets left to send: 0
2013-04-04T20:39:24.344Z,1365107964.344 [NAL9602](INFO): Stored copy of sent data in Logs/20130404T203537/shore0000.lzma.parts/0000.sbd
2013-04-04T20:39:33.493Z,1365107973.493 [NAL9602](INFO): SBD MO Status=0, MOMSN=9723, MT Status=0, MTMSN=0
2013-04-04T20:39:37.118Z,1365107977.118 [Default:Iridium:Read_Iridium] Stopped
2013-04-04T20:39:37.118Z,1365107977.118 [Default:Iridium](INFO): Completed Default:Iridium
2013-04-04T20:39:37.118Z,1365107977.118 [Default:Iridium] Stopped
2013-04-04T20:39:37.119Z,1365107977.119 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-04-04T20:39:37.119Z,1365107977.119 [Default:Iridium:A.SetSpeed] Stopped
2013-04-04T20:39:37.119Z,1365107977.119 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-04-04T20:39:37.119Z,1365107977.119 [Default:F.Wait] Running Loop=1
2013-04-04T20:39:37.119Z,1365107977.119 [Default:F.Wait](DEBUG): Initialize Wait Component.
2013-04-04T20:39:37.509Z,1365107977.509 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-04-04T20:39:37.509Z,1365107977.509 [Default:CallIridium:B] Stopped
2013-04-04T20:39:37.509Z,1365107977.509 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-04-04T20:39:37.509Z,1365107977.509 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-04-04T20:39:37.509Z,1365107977.509 [Default:CallIridium] Stopped
2013-04-04T20:39:37.509Z,1365107977.509 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-04-04T20:39:38.120Z,1365107978.120 [NAL9602](IMPORTANT): GPS fix at: 1365108247.00
2013-04-04T20:39:38.136Z,1365107978.136 [Default:GPS:Read_GPS] Stopped
2013-04-04T20:39:38.136Z,1365107978.136 [Default:GPS:D] Running Loop=1
2013-04-04T20:39:38.540Z,1365107978.540 [Default:GPS:D] Stopped
2013-04-04T20:39:38.541Z,1365107978.541 [Default:GPS](INFO): Completed Default:GPS
2013-04-04T20:39:38.541Z,1365107978.541 [Default:GPS] Stopped
2013-04-04T20:39:38.541Z,1365107978.541 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-04-04T20:39:38.541Z,1365107978.541 [Default:GPS:A.SetSpeed] Stopped
2013-04-04T20:39:38.541Z,1365107978.541 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-04-04T20:39:59.101Z,1365107999.101 [NAL9602](INFO): Powering down
2013-04-04T20:44:34.104Z,1365108274.104 [Default:CallIridium] Running Loop=1
2013-04-04T20:44:34.105Z,1365108274.105 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-04-04T20:44:34.105Z,1365108274.105 [Default:CallIridium:A] Running Loop=1
2013-04-04T20:44:34.105Z,1365108274.105 [Default:CallIridium:A] Stopped
2013-04-04T20:44:34.105Z,1365108274.105 [Default:CallIridium:B] Running Loop=1
2013-04-04T20:44:34.105Z,1365108274.105 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-04-04T20:44:39.116Z,1365108279.116 [Default:Iridium] Running Loop=1
2013-04-04T20:44:39.117Z,1365108279.117 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-04-04T20:44:39.117Z,1365108279.117 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-04-04T20:44:39.117Z,1365108279.117 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-04-04T20:44:39.117Z,1365108279.117 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-04-04T20:44:39.117Z,1365108279.117 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-04-04T20:44:39.118Z,1365108279.118 [Default:Iridium:B.GoToSurface] Stopped
2013-04-04T20:44:39.118Z,1365108279.118 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-04-04T20:44:39.118Z,1365108279.118 [Default:Iridium:Read_Iridium] Running Loop=1
2013-04-04T20:44:39.119Z,1365108279.119 [Default:GPS] Running Loop=1
2013-04-04T20:44:39.119Z,1365108279.119 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-04-04T20:44:39.119Z,1365108279.119 [Default:GPS:A.SetSpeed] Running Loop=1
2013-04-04T20:44:39.119Z,1365108279.119 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-04-04T20:44:39.119Z,1365108279.119 [Default:GPS:B.GoToSurface] Running Loop=1
2013-04-04T20:44:39.119Z,1365108279.119 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-04-04T20:44:39.120Z,1365108279.120 [Default:GPS:B.GoToSurface] Stopped
2013-04-04T20:44:39.120Z,1365108279.120 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-04-04T20:44:39.120Z,1365108279.120 [Default:GPS:Read_GPS] Running Loop=1
2013-04-04T20:44:39.720Z,1365108279.720 [NAL9602](INFO): Powering up
2013-04-04T20:44:50.151Z,1365108290.151 [NAL9602](INFO): NAL9602 initialized
2013-04-04T20:45:03.954Z,1365108303.954 [NAL9602](IMPORTANT): GPS fix at: 1365108574.00
2013-04-04T20:45:03.971Z,1365108303.971 [Default:GPS:Read_GPS] Stopped
2013-04-04T20:45:03.971Z,1365108303.971 [Default:GPS:D] Running Loop=1
2013-04-04T20:45:04.475Z,1365108304.475 [Default:GPS:D] Stopped
2013-04-04T20:45:04.476Z,1365108304.476 [Default:GPS](INFO): Completed Default:GPS
2013-04-04T20:45:04.476Z,1365108304.476 [Default:GPS] Stopped
2013-04-04T20:45:04.476Z,1365108304.476 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-04-04T20:45:04.476Z,1365108304.476 [Default:GPS:A.SetSpeed] Stopped
2013-04-04T20:45:04.476Z,1365108304.476 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-04-04T20:47:01.233Z,1365108421.233 [NAL9602](INFO): SBD MO Status=1, MOMSN=9724, MT Status=0, MTMSN=0
2013-04-04T20:47:01.291Z,1365108421.291 [NAL9602](INFO): Sent 186 bytes from file Logs/20130404T203537/shore0001.lzma
2013-04-04T20:47:01.291Z,1365108421.291 [NAL9602](INFO): Packets left to send: 0
2013-04-04T20:47:01.293Z,1365108421.293 [NAL9602](INFO): Stored copy of sent data in Logs/20130404T203537/shore0001.lzma.parts/0000.sbd
2013-04-04T20:47:10.033Z,1365108430.033 [NAL9602](INFO): SBD MO Status=0, MOMSN=9725, MT Status=0, MTMSN=0
2013-04-04T20:47:13.755Z,1365108433.755 [Default:Iridium:Read_Iridium] Stopped
2013-04-04T20:47:13.755Z,1365108433.755 [Default:Iridium](INFO): Completed Default:Iridium
2013-04-04T20:47:13.756Z,1365108433.756 [Default:Iridium] Stopped
2013-04-04T20:47:13.756Z,1365108433.756 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-04-04T20:47:13.756Z,1365108433.756 [Default:Iridium:A.SetSpeed] Stopped
2013-04-04T20:47:13.756Z,1365108433.756 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-04-04T20:47:14.200Z,1365108434.200 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-04-04T20:47:14.200Z,1365108434.201 [Default:CallIridium:B] Stopped
2013-04-04T20:47:14.201Z,1365108434.201 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-04-04T20:47:14.201Z,1365108434.201 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-04-04T20:47:14.201Z,1365108434.201 [Default:CallIridium] Stopped
2013-04-04T20:47:14.201Z,1365108434.201 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-04-04T20:47:24.129Z,1365108444.129 [NAL9602](INFO): Powering down
2013-04-04T20:52:14.128Z,1365108734.128 [Default:CallIridium] Running Loop=1
2013-04-04T20:52:14.129Z,1365108734.129 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-04-04T20:52:14.129Z,1365108734.129 [Default:CallIridium:A] Running Loop=1
2013-04-04T20:52:14.129Z,1365108734.129 [Default:CallIridium:A] Stopped
2013-04-04T20:52:14.129Z,1365108734.129 [Default:CallIridium:B] Running Loop=1
2013-04-04T20:52:14.130Z,1365108734.129 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-04-04T20:52:19.171Z,1365108739.171 [Default:Iridium] Running Loop=1
2013-04-04T20:52:19.171Z,1365108739.171 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-04-04T20:52:19.171Z,1365108739.171 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-04-04T20:52:19.171Z,1365108739.171 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-04-04T20:52:19.172Z,1365108739.172 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-04-04T20:52:19.172Z,1365108739.172 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-04-04T20:52:19.173Z,1365108739.173 [Default:Iridium:B.GoToSurface] Stopped
2013-04-04T20:52:19.173Z,1365108739.173 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-04-04T20:52:19.173Z,1365108739.173 [Default:Iridium:Read_Iridium] Running Loop=1
2013-04-04T20:52:19.173Z,1365108739.173 [Default:GPS] Running Loop=1
2013-04-04T20:52:19.173Z,1365108739.173 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-04-04T20:52:19.173Z,1365108739.173 [Default:GPS:A.SetSpeed] Running Loop=1
2013-04-04T20:52:19.173Z,1365108739.173 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-04-04T20:52:19.174Z,1365108739.174 [Default:GPS:B.GoToSurface] Running Loop=1
2013-04-04T20:52:19.174Z,1365108739.174 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-04-04T20:52:19.175Z,1365108739.175 [Default:GPS:B.GoToSurface] Stopped
2013-04-04T20:52:19.175Z,1365108739.175 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-04-04T20:52:19.175Z,1365108739.175 [Default:GPS:Read_GPS] Running Loop=1
2013-04-04T20:52:19.768Z,1365108739.768 [NAL9602](INFO): Powering up
2013-04-04T20:52:30.603Z,1365108750.603 [NAL9602](INFO): NAL9602 initialized
2013-04-04T20:53:07.905Z,1365108787.905 [NAL9602](INFO): SBD MO Status=2, MOMSN=9726, MT Status=2, MTMSN=0
2013-04-04T20:53:07.905Z,1365108787.905 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-04-04T20:53:09.107Z,1365108789.107 [NAL9602](IMPORTANT): GPS fix at: 1365109059.00
2013-04-04T20:53:09.124Z,1365108789.124 [Default:GPS:Read_GPS] Stopped
2013-04-04T20:53:09.124Z,1365108789.124 [Default:GPS:D] Running Loop=1
2013-04-04T20:53:09.527Z,1365108789.527 [Default:GPS:D] Stopped
2013-04-04T20:53:09.528Z,1365108789.528 [Default:GPS](INFO): Completed Default:GPS
2013-04-04T20:53:09.528Z,1365108789.528 [Default:GPS] Stopped
2013-04-04T20:53:09.528Z,1365108789.528 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-04-04T20:53:09.528Z,1365108789.528 [Default:GPS:A.SetSpeed] Stopped
2013-04-04T20:53:09.528Z,1365108789.528 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-04-04T20:54:18.056Z,1365108858.056 [NAL9602](INFO): SBD MO Status=2, MOMSN=9726, MT Status=2, MTMSN=0
2013-04-04T20:54:18.056Z,1365108858.056 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-04-04T20:54:37.455Z,1365108877.455 [NAL9602](INFO): SBD MO Status=2, MOMSN=9726, MT Status=2, MTMSN=0
2013-04-04T20:54:37.455Z,1365108877.455 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-04-04T20:54:55.616Z,1365108895.616 [NAL9602](INFO): SBD MO Status=1, MOMSN=9726, MT Status=0, MTMSN=0
2013-04-04T20:54:55.667Z,1365108895.667 [NAL9602](INFO): Sent 274 bytes from file Logs/20130404T203537/shore0002.lzma
2013-04-04T20:54:55.667Z,1365108895.667 [NAL9602](INFO): Packets left to send: 0
2013-04-04T20:54:55.669Z,1365108895.669 [NAL9602](INFO): Stored copy of sent data in Logs/20130404T203537/shore0002.lzma.parts/0000.sbd
2013-04-04T20:55:02.829Z,1365108902.829 [NAL9602](INFO): SBD MO Status=0, MOMSN=9727, MT Status=0, MTMSN=0
2013-04-04T20:55:06.496Z,1365108906.497 [Default:Iridium:Read_Iridium] Stopped
2013-04-04T20:55:06.497Z,1365108906.497 [Default:Iridium](INFO): Completed Default:Iridium
2013-04-04T20:55:06.497Z,1365108906.497 [Default:Iridium] Stopped
2013-04-04T20:55:06.497Z,1365108906.497 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-04-04T20:55:06.497Z,1365108906.497 [Default:Iridium:A.SetSpeed] Stopped
2013-04-04T20:55:06.497Z,1365108906.497 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-04-04T20:55:06.877Z,1365108906.877 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-04-04T20:55:06.877Z,1365108906.877 [Default:CallIridium:B] Stopped
2013-04-04T20:55:06.877Z,1365108906.877 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-04-04T20:55:06.877Z,1365108906.877 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-04-04T20:55:06.877Z,1365108906.877 [Default:CallIridium] Stopped
2013-04-04T20:55:06.877Z,1365108906.877 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-04-04T20:55:16.889Z,1365108916.889 [NAL9602](INFO): Powering down
2013-04-04T21:00:06.976Z,1365109206.976 [Default:CallIridium] Running Loop=1
2013-04-04T21:00:06.976Z,1365109206.976 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-04-04T21:00:06.976Z,1365109206.976 [Default:CallIridium:A] Running Loop=1
2013-04-04T21:00:06.976Z,1365109206.977 [Default:CallIridium:A] Stopped
2013-04-04T21:00:06.977Z,1365109206.977 [Default:CallIridium:B] Running Loop=1
2013-04-04T21:00:06.977Z,1365109206.977 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-04-04T21:00:11.927Z,1365109211.927 [Default:Iridium] Running Loop=1
2013-04-04T21:00:11.927Z,1365109211.927 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-04-04T21:00:11.927Z,1365109211.927 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-04-04T21:00:11.927Z,1365109211.927 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-04-04T21:00:11.928Z,1365109211.928 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-04-04T21:00:11.928Z,1365109211.928 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-04-04T21:00:11.928Z,1365109211.928 [Default:Iridium:B.GoToSurface] Stopped
2013-04-04T21:00:11.928Z,1365109211.928 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-04-04T21:00:11.929Z,1365109211.929 [Default:Iridium:Read_Iridium] Running Loop=1
2013-04-04T21:00:11.929Z,1365109211.929 [Default:GPS] Running Loop=1
2013-04-04T21:00:11.929Z,1365109211.929 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-04-04T21:00:11.929Z,1365109211.929 [Default:GPS:A.SetSpeed] Running Loop=1
2013-04-04T21:00:11.929Z,1365109211.929 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-04-04T21:00:11.929Z,1365109211.930 [Default:GPS:B.GoToSurface] Running Loop=1
2013-04-04T21:00:11.929Z,1365109211.930 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-04-04T21:00:11.930Z,1365109211.930 [Default:GPS:B.GoToSurface] Stopped
2013-04-04T21:00:11.930Z,1365109211.930 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-04-04T21:00:11.931Z,1365109211.931 [Default:GPS:Read_GPS] Running Loop=1
2013-04-04T21:00:12.532Z,1365109212.532 [NAL9602](INFO): Powering up
2013-04-04T21:00:23.375Z,1365109223.375 [NAL9602](INFO): NAL9602 initialized
2013-04-04T21:00:55.524Z,1365109255.523 [NAL9602](IMPORTANT): GPS fix at: 1365109527.00
2013-04-04T21:00:55.541Z,1365109255.541 [Default:GPS:Read_GPS] Stopped
2013-04-04T21:00:55.541Z,1365109255.541 [Default:GPS:D] Running Loop=1
2013-04-04T21:00:55.960Z,1365109255.960 [Default:GPS:D] Stopped
2013-04-04T21:00:55.961Z,1365109255.961 [Default:GPS](INFO): Completed Default:GPS
2013-04-04T21:00:55.961Z,1365109255.961 [Default:GPS] Stopped
2013-04-04T21:00:55.961Z,1365109255.961 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-04-04T21:00:55.961Z,1365109255.961 [Default:GPS:A.SetSpeed] Stopped
2013-04-04T21:00:55.961Z,1365109255.961 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-04-04T21:01:30.109Z,1365109290.109 [NAL9602](INFO): SBD MO Status=2, MOMSN=9728, MT Status=0, MTMSN=0
2013-04-04T21:01:30.110Z,1365109290.110 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-04-04T21:02:08.706Z,1365109328.706 [NAL9602](INFO): SBD MO Status=2, MOMSN=9728, MT Status=0, MTMSN=0
2013-04-04T21:02:08.706Z,1365109328.706 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-04-04T21:02:58.493Z,1365109378.493 [NAL9602](INFO): SBD MO Status=1, MOMSN=9728, MT Status=0, MTMSN=0
2013-04-04T21:02:58.543Z,1365109378.543 [NAL9602](INFO): Sent 161 bytes from file Logs/20130404T203537/shore0003.lzma
2013-04-04T21:02:58.543Z,1365109378.543 [NAL9602](INFO): Packets left to send: 0
2013-04-04T21:02:58.544Z,1365109378.545 [NAL9602](INFO): Stored copy of sent data in Logs/20130404T203537/shore0003.lzma.parts/0000.sbd
2013-04-04T21:03:05.359Z,1365109385.359 [NAL9602](INFO): SBD MO Status=0, MOMSN=9729, MT Status=0, MTMSN=0
2013-04-04T21:03:09.043Z,1365109389.043 [Default:Iridium:Read_Iridium] Stopped
2013-04-04T21:03:09.044Z,1365109389.044 [Default:Iridium](INFO): Completed Default:Iridium
2013-04-04T21:03:09.044Z,1365109389.044 [Default:Iridium] Stopped
2013-04-04T21:03:09.044Z,1365109389.044 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-04-04T21:03:09.044Z,1365109389.044 [Default:Iridium:A.SetSpeed] Stopped
2013-04-04T21:03:09.044Z,1365109389.044 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-04-04T21:03:09.366Z,1365109389.366 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-04-04T21:03:09.366Z,1365109389.366 [Default:CallIridium:B] Stopped
2013-04-04T21:03:09.366Z,1365109389.366 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-04-04T21:03:09.367Z,1365109389.367 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-04-04T21:03:09.367Z,1365109389.367 [Default:CallIridium] Stopped
2013-04-04T21:03:09.367Z,1365109389.367 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-04-04T21:03:19.408Z,1365109399.408 [NAL9602](INFO): Powering down
2013-04-04T21:08:09.465Z,1365109689.465 [Default:CallIridium] Running Loop=1
2013-04-04T21:08:09.465Z,1365109689.465 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-04-04T21:08:09.465Z,1365109689.465 [Default:CallIridium:A] Running Loop=1
2013-04-04T21:08:09.465Z,1365109689.466 [Default:CallIridium:A] Stopped
2013-04-04T21:08:09.466Z,1365109689.466 [Default:CallIridium:B] Running Loop=1
2013-04-04T21:08:09.466Z,1365109689.466 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-04-04T21:08:14.467Z,1365109694.467 [Default:Iridium] Running Loop=1
2013-04-04T21:08:14.467Z,1365109694.467 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-04-04T21:08:14.467Z,1365109694.467 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-04-04T21:08:14.467Z,1365109694.467 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-04-04T21:08:14.467Z,1365109694.467 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-04-04T21:08:14.467Z,1365109694.467 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-04-04T21:08:14.468Z,1365109694.468 [Default:Iridium:B.GoToSurface] Stopped
2013-04-04T21:08:14.468Z,1365109694.468 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-04-04T21:08:14.468Z,1365109694.468 [Default:Iridium:Read_Iridium] Running Loop=1
2013-04-04T21:08:14.468Z,1365109694.468 [Default:GPS] Running Loop=1
2013-04-04T21:08:14.469Z,1365109694.469 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-04-04T21:08:14.469Z,1365109694.469 [Default:GPS:A.SetSpeed] Running Loop=1
2013-04-04T21:08:14.469Z,1365109694.469 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-04-04T21:08:14.469Z,1365109694.469 [Default:GPS:B.GoToSurface] Running Loop=1
2013-04-04T21:08:14.469Z,1365109694.469 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-04-04T21:08:14.470Z,1365109694.470 [Default:GPS:B.GoToSurface] Stopped
2013-04-04T21:08:14.470Z,1365109694.470 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-04-04T21:08:14.470Z,1365109694.470 [Default:GPS:Read_GPS] Running Loop=1
2013-04-04T21:08:15.064Z,1365109695.064 [NAL9602](INFO): Powering up
2013-04-04T21:08:25.503Z,1365109705.503 [NAL9602](INFO): NAL9602 initialized
2013-04-04T21:08:51.233Z,1365109731.233 [NAL9602](INFO): SBD MO Status=1, MOMSN=9730, MT Status=0, MTMSN=0
2013-04-04T21:08:51.291Z,1365109731.291 [NAL9602](INFO): Sent 137 bytes from file Logs/20130404T203537/shore0004.lzma
2013-04-04T21:08:51.291Z,1365109731.291 [NAL9602](INFO): Packets left to send: 0
2013-04-04T21:08:51.293Z,1365109731.293 [NAL9602](INFO): Stored copy of sent data in Logs/20130404T203537/shore0004.lzma.parts/0000.sbd
2013-04-04T21:09:00.437Z,1365109740.437 [NAL9602](INFO): SBD MO Status=0, MOMSN=9731, MT Status=0, MTMSN=0
2013-04-04T21:09:04.187Z,1365109744.187 [Default:Iridium:Read_Iridium] Stopped
2013-04-04T21:09:04.188Z,1365109744.188 [Default:Iridium](INFO): Completed Default:Iridium
2013-04-04T21:09:04.188Z,1365109744.188 [Default:Iridium] Stopped
2013-04-04T21:09:04.188Z,1365109744.188 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-04-04T21:09:04.188Z,1365109744.188 [Default:Iridium:A.SetSpeed] Stopped
2013-04-04T21:09:04.188Z,1365109744.188 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-04-04T21:09:04.508Z,1365109744.508 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-04-04T21:09:04.508Z,1365109744.508 [Default:CallIridium:B] Stopped
2013-04-04T21:09:04.508Z,1365109744.508 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-04-04T21:09:04.508Z,1365109744.509 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-04-04T21:09:04.509Z,1365109744.509 [Default:CallIridium] Stopped
2013-04-04T21:09:04.509Z,1365109744.509 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-04-04T21:09:19.987Z,1365109759.987 [NAL9602](IMPORTANT): GPS fix at: 1365110033.00
2013-04-04T21:09:20.006Z,1365109760.006 [Default:GPS:Read_GPS] Stopped
2013-04-04T21:09:20.006Z,1365109760.006 [Default:GPS:D] Running Loop=1
2013-04-04T21:09:20.484Z,1365109760.484 [Default:GPS:D] Stopped
2013-04-04T21:09:20.485Z,1365109760.485 [Default:GPS](INFO): Completed Default:GPS
2013-04-04T21:09:20.485Z,1365109760.485 [Default:GPS] Stopped
2013-04-04T21:09:20.485Z,1365109760.485 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-04-04T21:09:20.485Z,1365109760.485 [Default:GPS:A.SetSpeed] Stopped
2013-04-04T21:09:20.485Z,1365109760.485 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-04-04T21:09:40.945Z,1365109780.945 [NAL9602](INFO): Powering down
2013-04-04T21:10:10.945Z,1365109810.945 [Radio_Freewave](INFO): Powering down
2013-04-04T21:10:20.965Z,1365109820.964 [Radio_Freewave](INFO): Powering up
2013-04-04T21:14:00.989Z,1365110040.989 [Default:CallIridium] Running Loop=1
2013-04-04T21:14:00.989Z,1365110040.989 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-04-04T21:14:00.989Z,1365110040.989 [Default:CallIridium:A] Running Loop=1
2013-04-04T21:14:00.990Z,1365110040.990 [Default:CallIridium:A] Stopped
2013-04-04T21:14:00.990Z,1365110040.990 [Default:CallIridium:B] Running Loop=1
2013-04-04T21:14:00.990Z,1365110040.990 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-04-04T21:14:05.969Z,1365110045.969 [Default:Iridium] Running Loop=1
2013-04-04T21:14:05.970Z,1365110045.970 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-04-04T21:14:05.970Z,1365110045.970 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-04-04T21:14:05.970Z,1365110045.970 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-04-04T21:14:05.970Z,1365110045.970 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-04-04T21:14:05.970Z,1365110045.970 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-04-04T21:14:05.971Z,1365110045.971 [Default:Iridium:B.GoToSurface] Stopped
2013-04-04T21:14:05.971Z,1365110045.971 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-04-04T21:14:05.971Z,1365110045.971 [Default:Iridium:Read_Iridium] Running Loop=1
2013-04-04T21:14:05.971Z,1365110045.971 [Default:GPS] Running Loop=1
2013-04-04T21:14:05.972Z,1365110045.972 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-04-04T21:14:05.972Z,1365110045.972 [Default:GPS:A.SetSpeed] Running Loop=1
2013-04-04T21:14:05.972Z,1365110045.972 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-04-04T21:14:05.972Z,1365110045.972 [Default:GPS:B.GoToSurface] Running Loop=1
2013-04-04T21:14:05.972Z,1365110045.972 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-04-04T21:14:05.973Z,1365110045.973 [Default:GPS:B.GoToSurface] Stopped
2013-04-04T21:14:05.973Z,1365110045.973 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-04-04T21:14:05.973Z,1365110045.973 [Default:GPS:Read_GPS] Running Loop=1
2013-04-04T21:14:06.586Z,1365110046.586 [NAL9602](INFO): Powering up
2013-04-04T21:14:17.019Z,1365110057.019 [NAL9602](INFO): NAL9602 initialized
2013-04-04T21:14:33.193Z,1365110073.193 [NAL9602](INFO): SBD MO Status=1, MOMSN=9732, MT Status=0, MTMSN=0
2013-04-04T21:14:33.243Z,1365110073.243 [NAL9602](INFO): Sent 137 bytes from file Logs/20130404T203537/shore0005.lzma
2013-04-04T21:14:33.243Z,1365110073.243 [NAL9602](INFO): Packets left to send: 0
2013-04-04T21:14:33.245Z,1365110073.245 [NAL9602](INFO): Stored copy of sent data in Logs/20130404T203537/shore0005.lzma.parts/0000.sbd
2013-04-04T21:14:42.361Z,1365110082.361 [NAL9602](INFO): SBD MO Status=0, MOMSN=9733, MT Status=0, MTMSN=0
2013-04-04T21:14:46.060Z,1365110086.060 [Default:Iridium:Read_Iridium] Stopped
2013-04-04T21:14:46.060Z,1365110086.060 [Default:Iridium](INFO): Completed Default:Iridium
2013-04-04T21:14:46.060Z,1365110086.060 [Default:Iridium] Stopped
2013-04-04T21:14:46.061Z,1365110086.061 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-04-04T21:14:46.061Z,1365110086.061 [Default:Iridium:A.SetSpeed] Stopped
2013-04-04T21:14:46.061Z,1365110086.061 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-04-04T21:14:46.445Z,1365110086.445 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-04-04T21:14:46.445Z,1365110086.445 [Default:CallIridium:B] Stopped
2013-04-04T21:14:46.446Z,1365110086.446 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-04-04T21:14:46.446Z,1365110086.446 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-04-04T21:14:46.446Z,1365110086.446 [Default:CallIridium] Stopped
2013-04-04T21:14:46.446Z,1365110086.446 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-04-04T21:15:01.071Z,1365110101.071 [NAL9602](IMPORTANT): GPS fix at: 1365110373.00
2013-04-04T21:15:01.088Z,1365110101.088 [Default:GPS:Read_GPS] Stopped
2013-04-04T21:15:01.088Z,1365110101.088 [Default:GPS:D] Running Loop=1
2013-04-04T21:15:01.495Z,1365110101.495 [Default:GPS:D] Stopped
2013-04-04T21:15:01.495Z,1365110101.495 [Default:GPS](INFO): Completed Default:GPS
2013-04-04T21:15:01.495Z,1365110101.495 [Default:GPS] Stopped
2013-04-04T21:15:01.495Z,1365110101.496 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-04-04T21:15:01.495Z,1365110101.496 [Default:GPS:A.SetSpeed] Stopped
2013-04-04T21:15:01.496Z,1365110101.496 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-04-04T21:15:22.045Z,1365110122.045 [NAL9602](INFO): Powering down
2013-04-04T21:19:47.012Z,1365110387.012 [Default:CallIridium] Running Loop=1
2013-04-04T21:19:47.012Z,1365110387.012 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-04-04T21:19:47.013Z,1365110387.013 [Default:CallIridium:A] Running Loop=1
2013-04-04T21:19:47.013Z,1365110387.013 [Default:CallIridium:A] Stopped
2013-04-04T21:19:47.013Z,1365110387.013 [Default:CallIridium:B] Running Loop=1
2013-04-04T21:19:47.013Z,1365110387.013 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-04-04T21:19:52.076Z,1365110392.076 [Default:Iridium] Running Loop=1
2013-04-04T21:19:52.076Z,1365110392.076 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-04-04T21:19:52.076Z,1365110392.076 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-04-04T21:19:52.076Z,1365110392.076 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-04-04T21:19:52.076Z,1365110392.076 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-04-04T21:19:52.076Z,1365110392.076 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-04-04T21:19:52.077Z,1365110392.077 [Default:Iridium:B.GoToSurface] Stopped
2013-04-04T21:19:52.077Z,1365110392.077 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-04-04T21:19:52.078Z,1365110392.078 [Default:Iridium:Read_Iridium] Running Loop=1
2013-04-04T21:19:52.078Z,1365110392.078 [Default:GPS] Running Loop=1
2013-04-04T21:19:52.078Z,1365110392.078 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-04-04T21:19:52.078Z,1365110392.078 [Default:GPS:A.SetSpeed] Running Loop=1
2013-04-04T21:19:52.078Z,1365110392.078 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-04-04T21:19:52.079Z,1365110392.079 [Default:GPS:B.GoToSurface] Running Loop=1
2013-04-04T21:19:52.079Z,1365110392.079 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-04-04T21:19:52.079Z,1365110392.079 [Default:GPS:B.GoToSurface] Stopped
2013-04-04T21:19:52.079Z,1365110392.079 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-04-04T21:19:52.080Z,1365110392.080 [Default:GPS:Read_GPS] Running Loop=1
2013-04-04T21:19:52.700Z,1365110392.700 [NAL9602](INFO): Powering up
2013-04-04T21:20:03.111Z,1365110403.111 [NAL9602](INFO): NAL9602 initialized
2013-04-04T21:20:29.228Z,1365110429.228 [NAL9602](INFO): SBD MO Status=1, MOMSN=9734, MT Status=0, MTMSN=0
2013-04-04T21:20:29.283Z,1365110429.283 [NAL9602](INFO): Sent 163 bytes from file Logs/20130404T203537/shore0006.lzma
2013-04-04T21:20:29.283Z,1365110429.283 [NAL9602](INFO): Packets left to send: 0
2013-04-04T21:20:29.285Z,1365110429.285 [NAL9602](INFO): Stored copy of sent data in Logs/20130404T203537/shore0006.lzma.parts/0000.sbd
2013-04-04T21:20:38.451Z,1365110438.451 [NAL9602](INFO): SBD MO Status=0, MOMSN=9735, MT Status=0, MTMSN=0
2013-04-04T21:20:42.104Z,1365110442.104 [Default:Iridium:Read_Iridium] Stopped
2013-04-04T21:20:42.105Z,1365110442.105 [Default:Iridium](INFO): Completed Default:Iridium
2013-04-04T21:20:42.105Z,1365110442.105 [Default:Iridium] Stopped
2013-04-04T21:20:42.105Z,1365110442.105 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-04-04T21:20:42.105Z,1365110442.105 [Default:Iridium:A.SetSpeed] Stopped
2013-04-04T21:20:42.105Z,1365110442.105 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-04-04T21:20:42.493Z,1365110442.493 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-04-04T21:20:42.493Z,1365110442.493 [Default:CallIridium:B] Stopped
2013-04-04T21:20:42.493Z,1365110442.493 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-04-04T21:20:42.493Z,1365110442.493 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-04-04T21:20:42.493Z,1365110442.493 [Default:CallIridium] Stopped
2013-04-04T21:20:42.494Z,1365110442.494 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-04-04T21:20:43.103Z,1365110443.103 [NAL9602](IMPORTANT): GPS fix at: 1365110716.00
2013-04-04T21:20:43.120Z,1365110443.120 [Default:GPS:Read_GPS] Stopped
2013-04-04T21:20:43.120Z,1365110443.120 [Default:GPS:D] Running Loop=1
2013-04-04T21:20:43.533Z,1365110443.533 [Default:GPS:D] Stopped
2013-04-04T21:20:43.533Z,1365110443.533 [Default:GPS](INFO): Completed Default:GPS
2013-04-04T21:20:43.533Z,1365110443.533 [Default:GPS] Stopped
2013-04-04T21:20:43.533Z,1365110443.533 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-04-04T21:20:43.533Z,1365110443.533 [Default:GPS:A.SetSpeed] Stopped
2013-04-04T21:20:43.533Z,1365110443.533 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-04-04T21:21:04.100Z,1365110464.100 [NAL9602](INFO): Powering down
2013-04-04T21:25:39.101Z,1365110739.101 [Default:CallIridium] Running Loop=1
2013-04-04T21:25:39.101Z,1365110739.101 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-04-04T21:25:39.101Z,1365110739.101 [Default:CallIridium:A] Running Loop=1
2013-04-04T21:25:39.101Z,1365110739.101 [Default:CallIridium:A] Stopped
2013-04-04T21:25:39.101Z,1365110739.101 [Default:CallIridium:B] Running Loop=1
2013-04-04T21:25:39.101Z,1365110739.102 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-04-04T21:25:44.081Z,1365110744.081 [Default:Iridium] Running Loop=1
2013-04-04T21:25:44.081Z,1365110744.081 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-04-04T21:25:44.081Z,1365110744.081 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-04-04T21:25:44.082Z,1365110744.082 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-04-04T21:25:44.082Z,1365110744.082 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-04-04T21:25:44.082Z,1365110744.082 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-04-04T21:25:44.083Z,1365110744.083 [Default:Iridium:B.GoToSurface] Stopped
2013-04-04T21:25:44.083Z,1365110744.083 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-04-04T21:25:44.083Z,1365110744.083 [Default:Iridium:Read_Iridium] Running Loop=1
2013-04-04T21:25:44.083Z,1365110744.083 [Default:GPS] Running Loop=1
2013-04-04T21:25:44.083Z,1365110744.083 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-04-04T21:25:44.083Z,1365110744.083 [Default:GPS:A.SetSpeed] Running Loop=1
2013-04-04T21:25:44.084Z,1365110744.084 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-04-04T21:25:44.084Z,1365110744.084 [Default:GPS:B.GoToSurface] Running Loop=1
2013-04-04T21:25:44.084Z,1365110744.084 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-04-04T21:25:44.085Z,1365110744.085 [Default:GPS:B.GoToSurface] Stopped
2013-04-04T21:25:44.085Z,1365110744.085 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-04-04T21:25:44.085Z,1365110744.085 [Default:GPS:Read_GPS] Running Loop=1
2013-04-04T21:25:44.704Z,1365110744.704 [NAL9602](INFO): Powering up
2013-04-04T21:25:55.539Z,1365110755.539 [NAL9602](INFO): NAL9602 initialized
2013-04-04T21:26:22.881Z,1365110782.881 [NAL9602](INFO): SBD MO Status=2, MOMSN=9736, MT Status=2, MTMSN=0
2013-04-04T21:26:22.881Z,1365110782.881 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-04-04T21:26:24.091Z,1365110784.091 [NAL9602](IMPORTANT): GPS fix at: 1365111058.00
2013-04-04T21:26:24.108Z,1365110784.108 [Default:GPS:Read_GPS] Stopped
2013-04-04T21:26:24.108Z,1365110784.108 [Default:GPS:D] Running Loop=1
2013-04-04T21:26:24.519Z,1365110784.519 [Default:GPS:D] Stopped
2013-04-04T21:26:24.519Z,1365110784.519 [Default:GPS](INFO): Completed Default:GPS
2013-04-04T21:26:24.519Z,1365110784.519 [Default:GPS] Stopped
2013-04-04T21:26:24.520Z,1365110784.520 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-04-04T21:26:24.520Z,1365110784.520 [Default:GPS:A.SetSpeed] Stopped
2013-04-04T21:26:24.520Z,1365110784.520 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-04-04T21:26:49.461Z,1365110809.461 [NAL9602](INFO): SBD MO Status=1, MOMSN=9736, MT Status=0, MTMSN=0
2013-04-04T21:26:49.511Z,1365110809.511 [NAL9602](INFO): Sent 162 bytes from file Logs/20130404T203537/shore0007.lzma
2013-04-04T21:26:49.511Z,1365110809.511 [NAL9602](INFO): Packets left to send: 0
2013-04-04T21:26:49.513Z,1365110809.513 [NAL9602](INFO): Stored copy of sent data in Logs/20130404T203537/shore0007.lzma.parts/0000.sbd
2013-04-04T21:27:01.413Z,1365110821.413 [NAL9602](INFO): SBD MO Status=0, MOMSN=9737, MT Status=0, MTMSN=0
2013-04-04T21:27:05.104Z,1365110825.104 [Default:Iridium:Read_Iridium] Stopped
2013-04-04T21:27:05.105Z,1365110825.105 [Default:Iridium](INFO): Completed Default:Iridium
2013-04-04T21:27:05.105Z,1365110825.105 [Default:Iridium] Stopped
2013-04-04T21:27:05.105Z,1365110825.105 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-04-04T21:27:05.105Z,1365110825.105 [Default:Iridium:A.SetSpeed] Stopped
2013-04-04T21:27:05.105Z,1365110825.105 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-04-04T21:27:05.481Z,1365110825.481 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-04-04T21:27:05.481Z,1365110825.481 [Default:CallIridium:B] Stopped
2013-04-04T21:27:05.481Z,1365110825.481 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-04-04T21:27:05.482Z,1365110825.482 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-04-04T21:27:05.482Z,1365110825.482 [Default:CallIridium] Stopped
2013-04-04T21:27:05.482Z,1365110825.482 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-04-04T21:27:15.488Z,1365110835.488 [NAL9602](INFO): Powering down
2013-04-04T21:32:05.504Z,1365111125.504 [Default:CallIridium] Running Loop=1
2013-04-04T21:32:05.504Z,1365111125.504 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-04-04T21:32:05.504Z,1365111125.504 [Default:CallIridium:A] Running Loop=1
2013-04-04T21:32:05.505Z,1365111125.505 [Default:CallIridium:A] Stopped
2013-04-04T21:32:05.505Z,1365111125.505 [Default:CallIridium:B] Running Loop=1
2013-04-04T21:32:05.505Z,1365111125.505 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-04-04T21:32:10.480Z,1365111130.480 [Default:Iridium] Running Loop=1
2013-04-04T21:32:10.480Z,1365111130.480 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-04-04T21:32:10.480Z,1365111130.480 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-04-04T21:32:10.480Z,1365111130.480 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-04-04T21:32:10.481Z,1365111130.481 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-04-04T21:32:10.481Z,1365111130.481 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-04-04T21:32:10.481Z,1365111130.481 [Default:Iridium:B.GoToSurface] Stopped
2013-04-04T21:32:10.481Z,1365111130.481 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-04-04T21:32:10.482Z,1365111130.482 [Default:Iridium:Read_Iridium] Running Loop=1
2013-04-04T21:32:10.482Z,1365111130.482 [Default:GPS] Running Loop=1
2013-04-04T21:32:10.482Z,1365111130.483 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-04-04T21:32:10.483Z,1365111130.483 [Default:GPS:A.SetSpeed] Running Loop=1
2013-04-04T21:32:10.483Z,1365111130.483 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-04-04T21:32:10.483Z,1365111130.483 [Default:GPS:B.GoToSurface] Running Loop=1
2013-04-04T21:32:10.483Z,1365111130.483 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-04-04T21:32:10.484Z,1365111130.484 [Default:GPS:B.GoToSurface] Stopped
2013-04-04T21:32:10.484Z,1365111130.484 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-04-04T21:32:10.484Z,1365111130.484 [Default:GPS:Read_GPS] Running Loop=1
2013-04-04T21:32:10.721Z,1365111130.721 [Radio_Freewave](INFO): Powering down
2013-04-04T21:32:11.104Z,1365111131.104 [NAL9602](INFO): Powering up
2013-04-04T21:32:14.271Z,1365111134.270 [ThrusterServo](FAULT): Overload Error
2013-04-04T21:32:14.271Z,1365111134.271 [ThrusterServo] Hardware Fault, FailCount= 1
2013-04-04T21:32:14.271Z,1365111134.271 [ThrusterServo](ERROR): Hardware Fault
2013-04-04T21:32:14.273Z,1365111134.273 [CBIT](ERROR): Hardware Fault in component: ThrusterServo
2013-04-04T21:32:14.604Z,1365111134.604 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2013-04-04T21:32:14.604Z,1365111134.604 [ThrusterServo](INFO): Powering down
2013-04-04T21:32:15.269Z,1365111135.269 [Radio_Freewave](INFO): Powering up
2013-04-04T21:32:15.553Z,1365111135.553 [CBIT](INFO): Clearing failed state for component ThrusterServo
2013-04-04T21:32:15.553Z,1365111135.553 [ThrusterServo] No Fault, FailCount= 1
2013-04-04T21:32:15.900Z,1365111135.900 [ThrusterServo](DEBUG): Initializing EZServoServo.
2013-04-04T21:32:15.901Z,1365111135.901 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2013-04-04T21:32:21.879Z,1365111141.879 [NAL9602](INFO): NAL9602 initialized
2013-04-04T21:33:01.025Z,1365111181.025 [NAL9602](INFO): SBD MO Status=2, MOMSN=9738, MT Status=2, MTMSN=0
2013-04-04T21:33:01.026Z,1365111181.026 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-04-04T21:33:35.526Z,1365111215.526 [NAL9602](INFO): SBD MO Status=2, MOMSN=9738, MT Status=2, MTMSN=0
2013-04-04T21:33:35.526Z,1365111215.526 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-04-04T21:34:00.897Z,1365111240.897 [NAL9602](INFO): SBD MO Status=2, MOMSN=9738, MT Status=2, MTMSN=0
2013-04-04T21:34:00.897Z,1365111240.898 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-04-04T21:34:19.893Z,1365111259.893 [NAL9602](INFO): SBD MO Status=1, MOMSN=9738, MT Status=0, MTMSN=0
2013-04-04T21:34:19.943Z,1365111259.943 [NAL9602](INFO): Sent 197 bytes from file Logs/20130404T203537/shore0008.lzma
2013-04-04T21:34:19.943Z,1365111259.943 [NAL9602](INFO): Packets left to send: 0
2013-04-04T21:34:19.945Z,1365111259.945 [NAL9602](INFO): Stored copy of sent data in Logs/20130404T203537/shore0008.lzma.parts/0000.sbd
2013-04-04T21:34:28.358Z,1365111268.358 [NAL9602](INFO): SBD MO Status=0, MOMSN=9739, MT Status=0, MTMSN=0
2013-04-04T21:34:32.095Z,1365111272.095 [Default:Iridium:Read_Iridium] Stopped
2013-04-04T21:34:32.096Z,1365111272.096 [Default:Iridium](INFO): Completed Default:Iridium
2013-04-04T21:34:32.096Z,1365111272.096 [Default:Iridium] Stopped
2013-04-04T21:34:32.096Z,1365111272.096 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-04-04T21:34:32.096Z,1365111272.096 [Default:Iridium:A.SetSpeed] Stopped
2013-04-04T21:34:32.096Z,1365111272.096 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-04-04T21:34:32.429Z,1365111272.429 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-04-04T21:34:32.429Z,1365111272.429 [Default:CallIridium:B] Stopped
2013-04-04T21:34:32.429Z,1365111272.429 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-04-04T21:34:32.429Z,1365111272.429 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-04-04T21:34:32.429Z,1365111272.429 [Default:CallIridium] Stopped
2013-04-04T21:34:32.429Z,1365111272.429 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-04-04T21:34:33.099Z,1365111273.099 [NAL9602](IMPORTANT): GPS fix at: 1365111548.00
2013-04-04T21:34:33.116Z,1365111273.116 [Default:GPS:Read_GPS] Stopped
2013-04-04T21:34:33.116Z,1365111273.116 [Default:GPS:D] Running Loop=1
2013-04-04T21:34:33.573Z,1365111273.573 [Default:GPS:D] Stopped
2013-04-04T21:34:33.573Z,1365111273.573 [Default:GPS](INFO): Completed Default:GPS
2013-04-04T21:34:33.573Z,1365111273.573 [Default:GPS] Stopped
2013-04-04T21:34:33.574Z,1365111273.574 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-04-04T21:34:33.574Z,1365111273.574 [Default:GPS:A.SetSpeed] Stopped
2013-04-04T21:34:33.574Z,1365111273.574 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-04-04T21:34:54.073Z,1365111294.073 [NAL9602](INFO): Powering down
2013-04-04T21:39:29.088Z,1365111569.088 [Default:CallIridium] Running Loop=1
2013-04-04T21:39:29.089Z,1365111569.089 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-04-04T21:39:29.089Z,1365111569.089 [Default:CallIridium:A] Running Loop=1
2013-04-04T21:39:29.089Z,1365111569.089 [Default:CallIridium:A] Stopped
2013-04-04T21:39:29.089Z,1365111569.089 [Default:CallIridium:B] Running Loop=1
2013-04-04T21:39:29.089Z,1365111569.089 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-04-04T21:39:34.076Z,1365111574.076 [Default:Iridium] Running Loop=1
2013-04-04T21:39:34.077Z,1365111574.077 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-04-04T21:39:34.077Z,1365111574.077 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-04-04T21:39:34.077Z,1365111574.077 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-04-04T21:39:34.077Z,1365111574.077 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-04-04T21:39:34.077Z,1365111574.077 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-04-04T21:39:34.078Z,1365111574.078 [Default:Iridium:B.GoToSurface] Stopped
2013-04-04T21:39:34.078Z,1365111574.078 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-04-04T21:39:34.078Z,1365111574.078 [Default:Iridium:Read_Iridium] Running Loop=1
2013-04-04T21:39:34.079Z,1365111574.079 [Default:GPS] Running Loop=1
2013-04-04T21:39:34.079Z,1365111574.079 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-04-04T21:39:34.079Z,1365111574.079 [Default:GPS:A.SetSpeed] Running Loop=1
2013-04-04T21:39:34.079Z,1365111574.079 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-04-04T21:39:34.079Z,1365111574.079 [Default:GPS:B.GoToSurface] Running Loop=1
2013-04-04T21:39:34.079Z,1365111574.079 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-04-04T21:39:34.080Z,1365111574.080 [Default:GPS:B.GoToSurface] Stopped
2013-04-04T21:39:34.080Z,1365111574.080 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-04-04T21:39:34.080Z,1365111574.080 [Default:GPS:Read_GPS] Running Loop=1
2013-04-04T21:39:34.716Z,1365111574.716 [NAL9602](INFO): Powering up
2013-04-04T21:39:45.527Z,1365111585.527 [NAL9602](INFO): NAL9602 initialized
2013-04-04T21:40:17.621Z,1365111617.621 [NAL9602](INFO): SBD MO Status=1, MOMSN=9740, MT Status=0, MTMSN=0
2013-04-04T21:40:17.671Z,1365111617.671 [NAL9602](INFO): Sent 139 bytes from file Logs/20130404T203537/shore0009.lzma
2013-04-04T21:40:17.671Z,1365111617.671 [NAL9602](INFO): Packets left to send: 0
2013-04-04T21:40:17.673Z,1365111617.673 [NAL9602](INFO): Stored copy of sent data in Logs/20130404T203537/shore0009.lzma.parts/0000.sbd
2013-04-04T21:40:29.220Z,1365111629.220 [NAL9602](INFO): SBD MO Status=2, MOMSN=9741, MT Status=2, MTMSN=0
2013-04-04T21:40:29.220Z,1365111629.220 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-04-04T21:40:30.422Z,1365111630.422 [NAL9602](IMPORTANT): GPS fix at: 1365111905.00
2013-04-04T21:40:30.439Z,1365111630.439 [Default:GPS:Read_GPS] Stopped
2013-04-04T21:40:30.439Z,1365111630.439 [Default:GPS:D] Running Loop=1
2013-04-04T21:40:30.863Z,1365111630.863 [Default:GPS:D] Stopped
2013-04-04T21:40:30.864Z,1365111630.864 [Default:GPS](INFO): Completed Default:GPS
2013-04-04T21:40:30.864Z,1365111630.864 [Default:GPS] Stopped
2013-04-04T21:40:30.864Z,1365111630.864 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-04-04T21:40:30.864Z,1365111630.864 [Default:GPS:A.SetSpeed] Stopped
2013-04-04T21:40:30.864Z,1365111630.864 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-04-04T21:40:38.393Z,1365111638.393 [NAL9602](INFO): SBD MO Status=0, MOMSN=9741, MT Status=0, MTMSN=0
2013-04-04T21:40:42.010Z,1365111642.010 [Default:Iridium:Read_Iridium] Stopped
2013-04-04T21:40:42.011Z,1365111642.011 [Default:Iridium](INFO): Completed Default:Iridium
2013-04-04T21:40:42.011Z,1365111642.011 [Default:Iridium] Stopped
2013-04-04T21:40:42.011Z,1365111642.011 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-04-04T21:40:42.011Z,1365111642.011 [Default:Iridium:A.SetSpeed] Stopped
2013-04-04T21:40:42.011Z,1365111642.011 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-04-04T21:40:42.377Z,1365111642.377 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-04-04T21:40:42.377Z,1365111642.377 [Default:CallIridium:B] Stopped
2013-04-04T21:40:42.377Z,1365111642.378 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-04-04T21:40:42.378Z,1365111642.378 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-04-04T21:40:42.378Z,1365111642.378 [Default:CallIridium] Stopped
2013-04-04T21:40:42.378Z,1365111642.378 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-04-04T21:40:52.384Z,1365111652.384 [NAL9602](INFO): Powering down
2013-04-04T21:45:42.377Z,1365111942.377 [Default:CallIridium] Running Loop=1
2013-04-04T21:45:42.377Z,1365111942.377 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-04-04T21:45:42.377Z,1365111942.377 [Default:CallIridium:A] Running Loop=1
2013-04-04T21:45:42.378Z,1365111942.378 [Default:CallIridium:A] Stopped
2013-04-04T21:45:42.378Z,1365111942.378 [Default:CallIridium:B] Running Loop=1
2013-04-04T21:45:42.378Z,1365111942.378 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-04-04T21:45:47.405Z,1365111947.405 [Default:Iridium] Running Loop=1
2013-04-04T21:45:47.405Z,1365111947.405 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-04-04T21:45:47.405Z,1365111947.405 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-04-04T21:45:47.406Z,1365111947.406 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-04-04T21:45:47.406Z,1365111947.406 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-04-04T21:45:47.406Z,1365111947.406 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-04-04T21:45:47.407Z,1365111947.407 [Default:Iridium:B.GoToSurface] Stopped
2013-04-04T21:45:47.407Z,1365111947.407 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-04-04T21:45:47.407Z,1365111947.407 [Default:Iridium:Read_Iridium] Running Loop=1
2013-04-04T21:45:47.407Z,1365111947.407 [Default:GPS] Running Loop=1
2013-04-04T21:45:47.408Z,1365111947.408 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-04-04T21:45:47.408Z,1365111947.408 [Default:GPS:A.SetSpeed] Running Loop=1
2013-04-04T21:45:47.408Z,1365111947.408 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-04-04T21:45:47.408Z,1365111947.408 [Default:GPS:B.GoToSurface] Running Loop=1
2013-04-04T21:45:47.408Z,1365111947.408 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-04-04T21:45:47.409Z,1365111947.409 [Default:GPS:B.GoToSurface] Stopped
2013-04-04T21:45:47.409Z,1365111947.409 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-04-04T21:45:47.409Z,1365111947.409 [Default:GPS:Read_GPS] Running Loop=1
2013-04-04T21:45:48.008Z,1365111948.008 [NAL9602](INFO): Powering up
2013-04-04T21:45:58.855Z,1365111958.855 [NAL9602](ERROR): NAL9602 initialize error - Can't enter command mode:
+CIEV:0,3
2013-04-04T21:45:58.855Z,1365111958.855 [NAL9602] Communications Fault, FailCount= 1
2013-04-04T21:45:58.855Z,1365111958.855 [NAL9602](ERROR): Communications Fault
2013-04-04T21:45:58.885Z,1365111958.885 [CBIT](ERROR): Communications Fault in component: NAL9602
2013-04-04T21:45:59.244Z,1365111959.244 [NAL9602](INFO): Powering down
2013-04-04T21:46:00.032Z,1365111960.032 [CBIT](INFO): Clearing failed state for component NAL9602
2013-04-04T21:46:00.032Z,1365111960.033 [NAL9602] No Fault, FailCount= 1
2013-04-04T21:46:04.409Z,1365111964.409 [NAL9602](INFO): Powering up NAL9602
2013-04-04T21:46:15.243Z,1365111975.243 [NAL9602](INFO): NAL9602 initialized
2013-04-04T21:46:33.785Z,1365111993.785 [NAL9602](INFO): SBD MO Status=1, MOMSN=9742, MT Status=0, MTMSN=0
2013-04-04T21:46:33.835Z,1365111993.835 [NAL9602](INFO): Sent 138 bytes from file Logs/20130404T203537/shore0010.lzma
2013-04-04T21:46:33.835Z,1365111993.835 [NAL9602](INFO): Packets left to send: 0
2013-04-04T21:46:33.837Z,1365111993.837 [NAL9602](INFO): Stored copy of sent data in Logs/20130404T203537/shore0010.lzma.parts/0000.sbd
2013-04-04T21:46:41.829Z,1365112001.829 [NAL9602](INFO): SBD MO Status=0, MOMSN=9743, MT Status=0, MTMSN=0
2013-04-04T21:46:45.511Z,1365112005.511 [Default:Iridium:Read_Iridium] Stopped
2013-04-04T21:46:45.512Z,1365112005.512 [Default:Iridium](INFO): Completed Default:Iridium
2013-04-04T21:46:45.512Z,1365112005.512 [Default:Iridium] Stopped
2013-04-04T21:46:45.512Z,1365112005.512 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-04-04T21:46:45.512Z,1365112005.512 [Default:Iridium:A.SetSpeed] Stopped
2013-04-04T21:46:45.512Z,1365112005.512 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-04-04T21:46:45.901Z,1365112005.901 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-04-04T21:46:45.901Z,1365112005.901 [Default:CallIridium:B] Stopped
2013-04-04T21:46:45.901Z,1365112005.901 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-04-04T21:46:45.901Z,1365112005.901 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-04-04T21:46:45.901Z,1365112005.901 [Default:CallIridium] Stopped
2013-04-04T21:46:45.901Z,1365112005.901 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-04-04T21:46:46.523Z,1365112006.523 [NAL9602](IMPORTANT): GPS fix at: 1365112283.00
2013-04-04T21:46:46.539Z,1365112006.539 [Default:GPS:Read_GPS] Stopped
2013-04-04T21:46:46.539Z,1365112006.539 [Default:GPS:D] Running Loop=1
2013-04-04T21:46:46.940Z,1365112006.940 [Default:GPS:D] Stopped
2013-04-04T21:46:46.941Z,1365112006.941 [Default:GPS](INFO): Completed Default:GPS
2013-04-04T21:46:46.941Z,1365112006.941 [Default:GPS] Stopped
2013-04-04T21:46:46.941Z,1365112006.941 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-04-04T21:46:46.941Z,1365112006.941 [Default:GPS:A.SetSpeed] Stopped
2013-04-04T21:46:46.941Z,1365112006.941 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-04-04T21:47:07.520Z,1365112027.520 [NAL9602](INFO): Powering down
2013-04-04T21:48:42.414Z,1365112122.414 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#0 STATUS: 65535
2013-04-04T21:51:42.560Z,1365112302.560 [Default:CallIridium] Running Loop=1
2013-04-04T21:51:42.560Z,1365112302.560 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-04-04T21:51:42.560Z,1365112302.560 [Default:CallIridium:A] Running Loop=1
2013-04-04T21:51:42.561Z,1365112302.560 [Default:CallIridium:A] Stopped
2013-04-04T21:51:42.561Z,1365112302.561 [Default:CallIridium:B] Running Loop=1
2013-04-04T21:51:42.561Z,1365112302.561 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-04-04T21:51:47.466Z,1365112307.466 [Default:Iridium] Running Loop=1
2013-04-04T21:51:47.466Z,1365112307.466 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-04-04T21:51:47.467Z,1365112307.467 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-04-04T21:51:47.467Z,1365112307.467 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-04-04T21:51:47.467Z,1365112307.467 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-04-04T21:51:47.467Z,1365112307.467 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-04-04T21:51:47.468Z,1365112307.468 [Default:Iridium:B.GoToSurface] Stopped
2013-04-04T21:51:47.468Z,1365112307.468 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-04-04T21:51:47.468Z,1365112307.468 [Default:Iridium:Read_Iridium] Running Loop=1
2013-04-04T21:51:47.468Z,1365112307.468 [Default:GPS] Running Loop=1
2013-04-04T21:51:47.468Z,1365112307.468 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-04-04T21:51:47.468Z,1365112307.468 [Default:GPS:A.SetSpeed] Running Loop=1
2013-04-04T21:51:47.469Z,1365112307.469 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-04-04T21:51:47.469Z,1365112307.469 [Default:GPS:B.GoToSurface] Running Loop=1
2013-04-04T21:51:47.469Z,1365112307.469 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-04-04T21:51:47.470Z,1365112307.470 [Default:GPS:B.GoToSurface] Stopped
2013-04-04T21:51:47.470Z,1365112307.470 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-04-04T21:51:47.470Z,1365112307.470 [Default:GPS:Read_GPS] Running Loop=1
2013-04-04T21:51:48.108Z,1365112308.108 [NAL9602](INFO): Powering up
2013-04-04T21:51:58.579Z,1365112318.579 [NAL9602](INFO): NAL9602 initialized
2013-04-04T21:52:13.889Z,1365112333.889 [NAL9602](INFO): SBD MO Status=1, MOMSN=9744, MT Status=0, MTMSN=0
2013-04-04T21:52:13.939Z,1365112333.939 [NAL9602](INFO): Sent 137 bytes from file Logs/20130404T203537/shore0011.lzma
2013-04-04T21:52:13.939Z,1365112333.939 [NAL9602](INFO): Packets left to send: 0
2013-04-04T21:52:13.941Z,1365112333.941 [NAL9602](INFO): Stored copy of sent data in Logs/20130404T203537/shore0011.lzma.parts/0000.sbd
2013-04-04T21:52:23.090Z,1365112343.090 [NAL9602](INFO): SBD MO Status=0, MOMSN=9745, MT Status=0, MTMSN=0
2013-04-04T21:52:26.887Z,1365112346.887 [Default:Iridium:Read_Iridium] Stopped
2013-04-04T21:52:26.887Z,1365112346.887 [Default:Iridium](INFO): Completed Default:Iridium
2013-04-04T21:52:26.887Z,1365112346.887 [Default:Iridium] Stopped
2013-04-04T21:52:26.887Z,1365112346.887 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-04-04T21:52:26.887Z,1365112346.887 [Default:Iridium:A.SetSpeed] Stopped
2013-04-04T21:52:26.887Z,1365112346.887 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-04-04T21:52:27.273Z,1365112347.273 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-04-04T21:52:27.273Z,1365112347.273 [Default:CallIridium:B] Stopped
2013-04-04T21:52:27.273Z,1365112347.273 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-04-04T21:52:27.274Z,1365112347.274 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-04-04T21:52:27.274Z,1365112347.274 [Default:CallIridium] Stopped
2013-04-04T21:52:27.274Z,1365112347.274 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-04-04T21:52:57.887Z,1365112377.887 [NAL9602](IMPORTANT): GPS fix at: 1365112654.00
2013-04-04T21:52:57.904Z,1365112377.904 [Default:GPS:Read_GPS] Stopped
2013-04-04T21:52:57.904Z,1365112377.904 [Default:GPS:D] Running Loop=1
2013-04-04T21:52:58.320Z,1365112378.320 [Default:GPS:D] Stopped
2013-04-04T21:52:58.321Z,1365112378.321 [Default:GPS](INFO): Completed Default:GPS
2013-04-04T21:52:58.321Z,1365112378.321 [Default:GPS] Stopped
2013-04-04T21:52:58.321Z,1365112378.321 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-04-04T21:52:58.321Z,1365112378.321 [Default:GPS:A.SetSpeed] Stopped
2013-04-04T21:52:58.321Z,1365112378.321 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-04-04T21:53:18.836Z,1365112398.836 [NAL9602](INFO): Powering down
2013-04-04T21:57:23.868Z,1365112643.868 [Default:CallIridium] Running Loop=1
2013-04-04T21:57:23.869Z,1365112643.869 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-04-04T21:57:23.869Z,1365112643.869 [Default:CallIridium:A] Running Loop=1
2013-04-04T21:57:23.869Z,1365112643.869 [Default:CallIridium:A] Stopped
2013-04-04T21:57:23.869Z,1365112643.869 [Default:CallIridium:B] Running Loop=1
2013-04-04T21:57:23.869Z,1365112643.869 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-04-04T21:57:28.875Z,1365112648.875 [Default:Iridium] Running Loop=1
2013-04-04T21:57:28.876Z,1365112648.875 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-04-04T21:57:28.876Z,1365112648.876 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-04-04T21:57:28.876Z,1365112648.876 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-04-04T21:57:28.876Z,1365112648.876 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-04-04T21:57:28.876Z,1365112648.876 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-04-04T21:57:28.877Z,1365112648.877 [Default:Iridium:B.GoToSurface] Stopped
2013-04-04T21:57:28.877Z,1365112648.877 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-04-04T21:57:28.877Z,1365112648.877 [Default:Iridium:Read_Iridium] Running Loop=1
2013-04-04T21:57:28.877Z,1365112648.877 [Default:GPS] Running Loop=1
2013-04-04T21:57:28.877Z,1365112648.877 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-04-04T21:57:28.877Z,1365112648.878 [Default:GPS:A.SetSpeed] Running Loop=1
2013-04-04T21:57:28.877Z,1365112648.878 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-04-04T21:57:28.878Z,1365112648.878 [Default:GPS:B.GoToSurface] Running Loop=1
2013-04-04T21:57:28.878Z,1365112648.878 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-04-04T21:57:28.879Z,1365112648.879 [Default:GPS:B.GoToSurface] Stopped
2013-04-04T21:57:28.879Z,1365112648.879 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-04-04T21:57:28.879Z,1365112648.879 [Default:GPS:Read_GPS] Running Loop=1
2013-04-04T21:57:29.475Z,1365112649.474 [NAL9602](INFO): Powering up
2013-04-04T21:57:39.915Z,1365112659.915 [NAL9602](INFO): NAL9602 initialized
2013-04-04T21:58:00.920Z,1365112680.920 [NAL9602](INFO): SBD MO Status=1, MOMSN=9746, MT Status=0, MTMSN=0
2013-04-04T21:58:00.971Z,1365112680.971 [NAL9602](INFO): Sent 134 bytes from file Logs/20130404T203537/shore0012.lzma
2013-04-04T21:58:00.971Z,1365112680.971 [NAL9602](INFO): Packets left to send: 0
2013-04-04T21:58:00.973Z,1365112680.973 [NAL9602](INFO): Stored copy of sent data in Logs/20130404T203537/shore0012.lzma.parts/0000.sbd
2013-04-04T21:58:07.688Z,1365112687.688 [NAL9602](INFO): SBD MO Status=0, MOMSN=9747, MT Status=0, MTMSN=0
2013-04-04T21:58:11.322Z,1365112691.322 [Default:Iridium:Read_Iridium] Stopped
2013-04-04T21:58:11.322Z,1365112691.322 [Default:Iridium](INFO): Completed Default:Iridium
2013-04-04T21:58:11.322Z,1365112691.322 [Default:Iridium] Stopped
2013-04-04T21:58:11.322Z,1365112691.322 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-04-04T21:58:11.322Z,1365112691.322 [Default:Iridium:A.SetSpeed] Stopped
2013-04-04T21:58:11.323Z,1365112691.323 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-04-04T21:58:11.701Z,1365112691.701 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-04-04T21:58:11.701Z,1365112691.701 [Default:CallIridium:B] Stopped
2013-04-04T21:58:11.701Z,1365112691.701 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-04-04T21:58:11.701Z,1365112691.701 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-04-04T21:58:11.701Z,1365112691.701 [Default:CallIridium] Stopped
2013-04-04T21:58:11.702Z,1365112691.702 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-04-04T21:58:12.318Z,1365112692.318 [NAL9602](IMPORTANT): GPS fix at: 1365112969.00
2013-04-04T21:58:12.334Z,1365112692.334 [Default:GPS:Read_GPS] Stopped
2013-04-04T21:58:12.334Z,1365112692.334 [Default:GPS:D] Running Loop=1
2013-04-04T21:58:12.760Z,1365112692.760 [Default:GPS:D] Stopped
2013-04-04T21:58:12.761Z,1365112692.761 [Default:GPS](INFO): Completed Default:GPS
2013-04-04T21:58:12.761Z,1365112692.761 [Default:GPS] Stopped
2013-04-04T21:58:12.761Z,1365112692.761 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-04-04T21:58:12.761Z,1365112692.761 [Default:GPS:A.SetSpeed] Stopped
2013-04-04T21:58:12.761Z,1365112692.761 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-04-04T21:58:33.313Z,1365112713.313 [NAL9602](INFO): Powering down
2013-04-04T21:59:28.303Z,1365112768.303 [Depth_Keller](ERROR): Pressure reading out of range: 1830.604248 decibar
2013-04-04T21:59:48.296Z,1365112788.296 [Depth_Keller](ERROR): Pressure reading out of range: 1830.598999 decibar
2013-04-04T21:59:58.300Z,1365112798.300 [Depth_Keller](ERROR): Pressure reading out of range: 1830.636475 decibar
2013-04-04T22:00:08.316Z,1365112808.316 [Depth_Keller](ERROR): Pressure reading out of range: 1830.632935 decibar
2013-04-04T22:00:18.296Z,1365112818.296 [Depth_Keller](ERROR): Pressure reading out of range: 1830.642578 decibar
2013-04-04T22:00:28.296Z,1365112828.296 [Depth_Keller](ERROR): Pressure reading out of range: 1830.617310 decibar
2013-04-04T22:00:38.288Z,1365112838.288 [Depth_Keller](ERROR): Pressure reading out of range: 1830.602539 decibar
2013-04-04T22:00:48.284Z,1365112848.284 [Depth_Keller](ERROR): Pressure reading out of range: 1830.629517 decibar
2013-04-04T22:00:58.336Z,1365112858.336 [Depth_Keller](ERROR): Pressure reading out of range: 1830.647095 decibar
2013-04-04T22:01:28.272Z,1365112888.272 [Depth_Keller](ERROR): Pressure reading out of range: 1830.636475 decibar
2013-04-04T22:01:38.295Z,1365112898.295 [Depth_Keller](ERROR): Pressure reading out of range: 1830.637451 decibar
2013-04-04T22:01:48.296Z,1365112908.296 [Depth_Keller](ERROR): Pressure reading out of range: 1830.630493 decibar
2013-04-04T22:02:08.296Z,1365112928.296 [Depth_Keller](ERROR): Pressure reading out of range: 1830.610352 decibar
2013-04-04T22:02:18.340Z,1365112938.340 [Depth_Keller](ERROR): Pressure reading out of range: 1830.619141 decibar
2013-04-04T22:02:58.284Z,1365112978.284 [Depth_Keller](ERROR): Pressure reading out of range: 1830.647095 decibar
2013-04-04T22:03:08.260Z,1365112988.260 [Depth_Keller](ERROR): Pressure reading out of range: 1830.640747 decibar
2013-04-04T22:03:08.277Z,1365112988.277 [Default:CallIridium] Running Loop=1
2013-04-04T22:03:08.277Z,1365112988.277 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-04-04T22:03:08.277Z,1365112988.277 [Default:CallIridium:A] Running Loop=1
2013-04-04T22:03:08.278Z,1365112988.277 [Default:CallIridium:A] Stopped
2013-04-04T22:03:08.278Z,1365112988.278 [Default:CallIridium:B] Running Loop=1
2013-04-04T22:03:08.278Z,1365112988.278 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-04-04T22:03:13.321Z,1365112993.321 [Default:Iridium] Running Loop=1
2013-04-04T22:03:13.321Z,1365112993.321 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-04-04T22:03:13.321Z,1365112993.321 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-04-04T22:03:13.321Z,1365112993.321 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-04-04T22:03:13.322Z,1365112993.322 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-04-04T22:03:13.322Z,1365112993.322 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-04-04T22:03:13.323Z,1365112993.323 [Default:Iridium:B.GoToSurface] Stopped
2013-04-04T22:03:13.323Z,1365112993.323 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-04-04T22:03:13.323Z,1365112993.323 [Default:Iridium:Read_Iridium] Running Loop=1
2013-04-04T22:03:13.323Z,1365112993.323 [Default:GPS] Running Loop=1
2013-04-04T22:03:13.323Z,1365112993.323 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-04-04T22:03:13.324Z,1365112993.323 [Default:GPS:A.SetSpeed] Running Loop=1
2013-04-04T22:03:13.324Z,1365112993.324 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-04-04T22:03:13.324Z,1365112993.324 [Default:GPS:B.GoToSurface] Running Loop=1
2013-04-04T22:03:13.324Z,1365112993.324 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-04-04T22:03:13.325Z,1365112993.325 [Default:GPS:B.GoToSurface] Stopped
2013-04-04T22:03:13.325Z,1365112993.325 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-04-04T22:03:13.325Z,1365112993.325 [Default:GPS:Read_GPS] Running Loop=1
2013-04-04T22:03:13.928Z,1365112993.928 [NAL9602](INFO): Powering up
2013-04-04T22:03:24.759Z,1365113004.759 [NAL9602](INFO): NAL9602 initialized
2013-04-04T22:07:49.994Z,1365113269.994 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535
2013-04-04T22:07:52.319Z,1365113272.319 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535
2013-04-04T22:07:55.114Z,1365113275.114 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535
2013-04-04T22:07:57.102Z,1365113277.102 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535
2013-04-04T22:07:59.418Z,1365113279.418 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535
2013-04-04T22:08:01.814Z,1365113281.814 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535
2013-04-04T22:08:04.164Z,1365113284.164 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535
2013-04-04T22:08:06.556Z,1365113286.556 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535
2013-04-04T22:08:08.878Z,1365113288.878 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535
2013-04-04T22:08:11.294Z,1365113291.294 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535
2013-04-04T22:08:13.598Z,1365113293.598 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535
2013-04-04T22:08:15.994Z,1365113295.994 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535
2013-04-04T22:08:18.330Z,1365113298.330 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535
2013-04-04T22:08:21.118Z,1365113301.118 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535
2013-04-04T22:08:23.114Z,1365113303.114 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535
2013-04-04T22:12:25.850Z,1365113545.850 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2013-04-04T22:12:25.850Z,1365113545.850 [DropWeight] Hardware Fault, FailCount= 1
2013-04-04T22:12:25.850Z,1365113545.850 [DropWeight](ERROR): Hardware Fault
2013-04-04T22:12:25.888Z,1365113545.888 [CBIT](ERROR): Hardware Fault in component: DropWeight
2013-04-04T22:12:25.889Z,1365113545.889 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2013-04-04T22:13:25.779Z,1365113605.779 [NAL9602](FAULT): GPS failed to acquire within timeout.
2013-04-04T22:13:25.779Z,1365113605.779 [NAL9602] Data Fault, FailCount= 2
2013-04-04T22:13:25.779Z,1365113605.779 [NAL9602](ERROR): Data Fault
2013-04-04T22:13:25.806Z,1365113605.806 [CBIT](ERROR): Data Fault in component: NAL9602
2013-04-04T22:13:25.806Z,1365113605.806 [CBIT](CRITICAL): Data Fault in component: NAL9602
2013-04-04T22:13:26.204Z,1365113606.204 [NAL9602](INFO): Powering down
2013-04-04T22:13:26.582Z,1365113606.582 [NAL9602](FAULT): LCB fault:  Current Limiter Activated.
2013-04-04T22:13:26.582Z,1365113606.582 [NAL9602] Hardware Fault, FailCount= 2
2013-04-04T22:13:26.582Z,1365113606.582 [NAL9602](ERROR): Hardware Fault
2013-04-04T22:15:25.807Z,1365113725.807 [CBIT](INFO): Clearing failed count for component NAL9602
2013-04-04T22:15:25.808Z,1365113725.807 [NAL9602] No Fault, FailCount= 2
2013-04-04T22:15:26.208Z,1365113726.208 [NAL9602](INFO): Powering up NAL9602
2013-04-04T22:15:39.038Z,1365113739.039 [NAL9602](ERROR): NAL9602 initialize uart error: serial timeout
2013-04-04T22:15:39.039Z,1365113739.039 [NAL9602] Communications Fault, FailCount= 1
2013-04-04T22:15:39.039Z,1365113739.039 [NAL9602](ERROR): Communications Fault
2013-04-04T22:15:39.082Z,1365113739.082 [CBIT](ERROR): Communications Fault in component: NAL9602
2013-04-04T22:15:39.319Z,1365113739.319 [NAL9602](INFO): Powering down
2013-04-04T22:15:40.094Z,1365113740.094 [CBIT](INFO): Clearing failed state for component NAL9602
2013-04-04T22:15:40.094Z,1365113740.094 [NAL9602] No Fault, FailCount= 1
2013-04-04T22:15:44.468Z,1365113744.468 [NAL9602](INFO): Powering up NAL9602
2013-04-04T22:15:55.307Z,1365113755.307 [NAL9602](INFO): NAL9602 initialized
2013-04-04T22:17:25.941Z,1365113845.941 [CBIT](INFO): Clearing failed count for component DropWeight
2013-04-04T22:17:25.941Z,1365113845.941 [DropWeight] No Fault, FailCount= 1
2013-04-04T22:17:26.279Z,1365113846.279 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2013-04-04T22:17:26.279Z,1365113846.279 [DropWeight] Hardware Fault, FailCount= 1
2013-04-04T22:17:26.280Z,1365113846.280 [DropWeight](ERROR): Hardware Fault
2013-04-04T22:17:26.305Z,1365113846.305 [CBIT](ERROR): Hardware Fault in component: DropWeight
2013-04-04T22:17:26.305Z,1365113846.305 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2013-04-04T22:22:26.314Z,1365114146.314 [CBIT](INFO): Clearing failed count for component DropWeight
2013-04-04T22:22:26.314Z,1365114146.314 [DropWeight] No Fault, FailCount= 1
2013-04-04T22:22:26.667Z,1365114146.667 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2013-04-04T22:22:26.667Z,1365114146.667 [DropWeight] Hardware Fault, FailCount= 1
2013-04-04T22:22:26.668Z,1365114146.668 [DropWeight](ERROR): Hardware Fault
2013-04-04T22:22:26.704Z,1365114146.704 [CBIT](ERROR): Hardware Fault in component: DropWeight
2013-04-04T22:22:26.704Z,1365114146.704 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2013-04-04T22:25:56.203Z,1365114356.203 [NAL9602](FAULT): GPS failed to acquire within timeout.
2013-04-04T22:25:56.203Z,1365114356.203 [NAL9602] Data Fault, FailCount= 2
2013-04-04T22:25:56.203Z,1365114356.203 [NAL9602](ERROR): Data Fault
2013-04-04T22:25:56.230Z,1365114356.230 [CBIT](ERROR): Data Fault in component: NAL9602
2013-04-04T22:25:56.230Z,1365114356.230 [CBIT](CRITICAL): Data Fault in component: NAL9602
2013-04-04T22:25:56.604Z,1365114356.604 [NAL9602](INFO): Powering down
2013-04-04T22:27:26.672Z,1365114446.672 [CBIT](INFO): Clearing failed count for component DropWeight
2013-04-04T22:27:26.672Z,1365114446.672 [DropWeight] No Fault, FailCount= 1
2013-04-04T22:27:27.018Z,1365114447.018 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2013-04-04T22:27:27.018Z,1365114447.018 [DropWeight] Hardware Fault, FailCount= 1
2013-04-04T22:27:27.018Z,1365114447.018 [DropWeight](ERROR): Hardware Fault
2013-04-04T22:27:27.063Z,1365114447.063 [CBIT](ERROR): Hardware Fault in component: DropWeight
2013-04-04T22:27:27.064Z,1365114447.064 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2013-04-04T22:27:56.267Z,1365114476.267 [CBIT](INFO): Clearing failed count for component NAL9602
2013-04-04T22:27:56.267Z,1365114476.267 [NAL9602] No Fault, FailCount= 2
2013-04-04T22:27:56.608Z,1365114476.608 [NAL9602](INFO): Powering up NAL9602
2013-04-04T22:28:07.443Z,1365114487.443 [NAL9602](INFO): NAL9602 initialized