2013-03-13T17:03:30.395Z,1363194210.395 [Supervisor](DEBUG): Initializing supervisor.
2013-03-13T17:03:30.398Z,1363194210.398 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0
2013-03-13T17:03:30.399Z,1363194210.399 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2013-03-13T17:03:30.402Z,1363194210.402 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0
2013-03-13T17:03:30.406Z,1363194210.406 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2013-03-13T17:03:30.417Z,1363194210.417 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2013-03-13T17:03:30.418Z,1363194210.418 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0
2013-03-13T17:03:30.419Z,1363194210.419 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2013-03-13T17:03:30.422Z,1363194210.422 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0
2013-03-13T17:03:30.423Z,1363194210.423 [Supervisor](INFO): Looking for Config files in directory: Config/
2013-03-13T17:03:30.427Z,1363194210.427 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2013-03-13T17:03:30.742Z,1363194210.742 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2013-03-13T17:03:30.742Z,1363194210.742 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2013-03-13T17:03:30.950Z,1363194210.950 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2013-03-13T17:03:30.950Z,1363194210.950 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2013-03-13T17:03:31.046Z,1363194211.046 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2013-03-13T17:03:31.048Z,1363194211.048 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2013-03-13T17:03:31.251Z,1363194211.251 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2013-03-13T17:03:31.252Z,1363194211.252 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2013-03-13T17:03:31.399Z,1363194211.399 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2013-03-13T17:03:31.401Z,1363194211.401 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2013-03-13T17:03:31.651Z,1363194211.651 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2013-03-13T17:03:31.652Z,1363194211.652 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2013-03-13T17:03:31.839Z,1363194211.839 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2013-03-13T17:03:31.841Z,1363194211.841 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2013-03-13T17:03:32.123Z,1363194212.124 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2013-03-13T17:03:32.126Z,1363194212.126 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2013-03-13T17:03:32.239Z,1363194212.239 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2013-03-13T17:03:32.240Z,1363194212.240 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2013-03-13T17:03:32.683Z,1363194212.684 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2013-03-13T17:03:32.684Z,1363194212.684 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2013-03-13T17:03:32.812Z,1363194212.812 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2013-03-13T17:03:32.812Z,1363194212.812 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2013-03-13T17:03:32.928Z,1363194212.928 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2013-03-13T17:03:32.949Z,1363194212.949 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2013-03-13T17:03:33.065Z,1363194213.065 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2013-03-13T17:03:33.208Z,1363194213.208 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2013-03-13T17:03:33.302Z,1363194213.302 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2013-03-13T17:03:33.415Z,1363194213.415 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2013-03-13T17:03:33.526Z,1363194213.526 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2013-03-13T17:03:33.660Z,1363194213.659 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2013-03-13T17:03:33.762Z,1363194213.762 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2013-03-13T17:03:33.858Z,1363194213.858 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2013-03-13T17:03:33.887Z,1363194213.887 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2013-03-13T17:03:34.089Z,1363194214.089 [InternalSim] Loaded
2013-03-13T17:03:34.089Z,1363194214.089 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2013-03-13T17:03:34.090Z,1363194214.090 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2013-03-13T17:03:34.090Z,1363194214.090 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2013-03-13T17:03:34.173Z,1363194214.173 [SBIT](DEBUG): Construct Startup Built In Test.
2013-03-13T17:03:34.205Z,1363194214.205 [SBIT] Loaded
2013-03-13T17:03:34.206Z,1363194214.205 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2013-03-13T17:03:34.207Z,1363194214.207 [IBIT](DEBUG): Construct Initiated Built In Test.
2013-03-13T17:03:34.235Z,1363194214.235 [IBIT] Loaded
2013-03-13T17:03:34.235Z,1363194214.236 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2013-03-13T17:03:34.243Z,1363194214.243 [CBIT](DEBUG): Construct CBIT Built In Test.
2013-03-13T17:03:34.375Z,1363194214.375 [CBIT] Loaded
2013-03-13T17:03:34.375Z,1363194214.375 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2013-03-13T17:03:34.375Z,1363194214.375 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2013-03-13T17:03:34.376Z,1363194214.376 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2013-03-13T17:03:34.552Z,1363194214.552 [BuoyancyServo] Loaded
2013-03-13T17:03:34.552Z,1363194214.552 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2013-03-13T17:03:34.565Z,1363194214.565 [ElevatorServo] Loaded
2013-03-13T17:03:34.565Z,1363194214.565 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2013-03-13T17:03:34.581Z,1363194214.581 [MassServo] Loaded
2013-03-13T17:03:34.581Z,1363194214.581 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2013-03-13T17:03:34.593Z,1363194214.593 [RudderServo] Loaded
2013-03-13T17:03:34.593Z,1363194214.593 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2013-03-13T17:03:34.605Z,1363194214.605 [ThrusterServo] Loaded
2013-03-13T17:03:34.605Z,1363194214.605 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2013-03-13T17:03:34.606Z,1363194214.606 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2013-03-13T17:03:34.607Z,1363194214.607 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2013-03-13T17:03:34.639Z,1363194214.639 [DepthRateCalculator] Loaded
2013-03-13T17:03:34.640Z,1363194214.640 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2013-03-13T17:03:38.752Z,1363194218.752 [HFRadarModelCalc] Loaded
2013-03-13T17:03:38.752Z,1363194218.752 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2013-03-13T17:03:38.772Z,1363194218.772 [NavChart] Loaded
2013-03-13T17:03:38.772Z,1363194218.773 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2013-03-13T17:03:38.778Z,1363194218.778 [PitchRateCalculator] Loaded
2013-03-13T17:03:38.779Z,1363194218.779 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2013-03-13T17:03:38.785Z,1363194218.785 [SpeedCalculator] Loaded
2013-03-13T17:03:38.785Z,1363194218.785 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2013-03-13T17:03:38.805Z,1363194218.805 [TempGradientCalculator] Loaded
2013-03-13T17:03:38.805Z,1363194218.805 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2013-03-13T17:03:38.811Z,1363194218.811 [YawRateCalculator] Loaded
2013-03-13T17:03:38.811Z,1363194218.811 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2013-03-13T17:03:38.856Z,1363194218.856 [Navigation] Loaded
2013-03-13T17:03:38.857Z,1363194218.857 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread.
2013-03-13T17:03:38.857Z,1363194218.857 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2013-03-13T17:03:38.858Z,1363194218.858 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2013-03-13T17:03:39.149Z,1363194219.149 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2013-03-13T17:03:39.150Z,1363194219.150 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2013-03-13T17:03:39.191Z,1363194219.191 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2013-03-13T17:03:39.192Z,1363194219.192 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2013-03-13T17:03:39.255Z,1363194219.255 [VerticalControl](DEBUG): Construct VerticalControl.
2013-03-13T17:03:39.360Z,1363194219.360 [VerticalControl] Loaded
2013-03-13T17:03:39.361Z,1363194219.361 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2013-03-13T17:03:39.361Z,1363194219.362 [HorizontalControl](DEBUG): Construct HorizontalControl.
2013-03-13T17:03:39.422Z,1363194219.422 [HorizontalControl] Loaded
2013-03-13T17:03:39.422Z,1363194219.422 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2013-03-13T17:03:39.423Z,1363194219.423 [SpeedControl](DEBUG): Construct SpeedControl.
2013-03-13T17:03:39.425Z,1363194219.425 [SpeedControl] Loaded
2013-03-13T17:03:39.425Z,1363194219.425 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2013-03-13T17:03:39.426Z,1363194219.426 [LoopControl](DEBUG): Construct LoopControl.
2013-03-13T17:03:39.427Z,1363194219.427 [LoopControl] Loaded
2013-03-13T17:03:39.427Z,1363194219.427 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2013-03-13T17:03:39.427Z,1363194219.427 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2013-03-13T17:03:39.428Z,1363194219.428 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2013-03-13T17:03:39.436Z,1363194219.436 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator.
2013-03-13T17:03:39.441Z,1363194219.441 [AsyncPiEstimator] Loaded
2013-03-13T17:03:39.441Z,1363194219.441 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread.
2013-03-13T17:03:39.446Z,1363194219.446 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406A44E0
2013-03-13T17:03:39.447Z,1363194219.447 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2013-03-13T17:03:39.448Z,1363194219.448 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2013-03-13T17:03:39.633Z,1363194219.633 [AHRS_sp3003D] Loaded
2013-03-13T17:03:39.633Z,1363194219.633 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2013-03-13T17:03:39.925Z,1363194219.925 [Batt_Ocean_Server] Loaded
2013-03-13T17:03:39.925Z,1363194219.925 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2013-03-13T17:03:39.943Z,1363194219.943 [Depth_Keller] Loaded
2013-03-13T17:03:39.943Z,1363194219.944 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2013-03-13T17:03:39.949Z,1363194219.949 [DropWeight] Loaded
2013-03-13T17:03:39.949Z,1363194219.949 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2013-03-13T17:03:40.144Z,1363194220.144 [DVL_micro] Loaded
2013-03-13T17:03:40.145Z,1363194220.145 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread.
2013-03-13T17:03:40.146Z,1363194220.146 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 407284E0
2013-03-13T17:03:40.239Z,1363194220.239 [NAL9602] Loaded
2013-03-13T17:03:40.240Z,1363194220.240 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2013-03-13T17:03:40.296Z,1363194220.296 [Onboard] Loaded
2013-03-13T17:03:40.297Z,1363194220.297 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2013-03-13T17:03:40.308Z,1363194220.307 [Radio_Freewave] Loaded
2013-03-13T17:03:40.308Z,1363194220.308 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread.
2013-03-13T17:03:40.308Z,1363194220.309 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2013-03-13T17:03:40.309Z,1363194220.309 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2013-03-13T17:03:40.397Z,1363194220.397 [Aanderaa_O2] Loaded
2013-03-13T17:03:40.398Z,1363194220.398 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2013-03-13T17:03:40.435Z,1363194220.435 [CTD_NeilBrown] Loaded
2013-03-13T17:03:40.435Z,1363194220.435 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2013-03-13T17:03:40.438Z,1363194220.438 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4077A4E0
2013-03-13T17:03:40.455Z,1363194220.455 [PAR_Licor] Loaded
2013-03-13T17:03:40.455Z,1363194220.455 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2013-03-13T17:03:40.490Z,1363194220.490 [WetLabsBB2FL] Loaded
2013-03-13T17:03:40.490Z,1363194220.490 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2013-03-13T17:03:40.494Z,1363194220.494 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407AA4E0
2013-03-13T17:03:40.495Z,1363194220.495 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2013-03-13T17:03:40.497Z,1363194220.497 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2013-03-13T17:03:40.498Z,1363194220.498 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2013-03-13T17:03:40.508Z,1363194220.508 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2013-03-13T17:03:40.510Z,1363194220.510 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 407DA4E0
2013-03-13T17:03:40.515Z,1363194220.515 [Supervisor](DEBUG): Running supervisor.
2013-03-13T17:03:40.516Z,1363194220.516 [CommandLine](INFO): Thread ID is 749
2013-03-13T17:03:40.519Z,1363194220.519 [controlThread](INFO): Thread ID is 748
2013-03-13T17:03:40.519Z,1363194220.519 [controlThread](DEBUG): Initializing ControlThread
2013-03-13T17:03:40.520Z,1363194220.520 [CycleStarter](INFO): Thread ID is 747
2013-03-13T17:03:40.520Z,1363194220.520 [InternalSim](DEBUG):  InternalSim initializing...
2013-03-13T17:03:40.625Z,1363194220.625 [logger](INFO): Thread ID is 750
2013-03-13T17:03:40.743Z,1363194220.743 [AsyncPiEstimator](INFO): Thread ID is 811
2013-03-13T17:03:40.743Z,1363194220.743 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator.
2013-03-13T17:03:40.826Z,1363194220.826 [DVL_micro](INFO): Thread ID is 812
2013-03-13T17:03:40.854Z,1363194220.854 [DVL_micro](INFO): Initializing
2013-03-13T17:03:40.854Z,1363194220.854 [DVL_micro](INFO): start:Powering up
2013-03-13T17:03:40.855Z,1363194220.855 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-03-13T17:03:40.855Z,1363194220.855 [DVL_micro](INFO): Cycling power to configure device.
2013-03-13T17:03:40.859Z,1363194220.859 [CTD_NeilBrown](INFO): Thread ID is 813
2013-03-13T17:03:40.860Z,1363194220.860 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2013-03-13T17:03:40.871Z,1363194220.871 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2013-03-13T17:03:40.923Z,1363194220.923 [WetLabsBB2FL](INFO): Thread ID is 814
2013-03-13T17:03:40.923Z,1363194220.923 [WetLabsBB2FL](INFO): Powering down
2013-03-13T17:03:40.941Z,1363194220.941 [SBIT](INFO): Initialize SBIT Component.
2013-03-13T17:03:40.942Z,1363194220.942 [SBIT](IMPORTANT): Tethys CM Info:
$Rev: 10234
2013-03-13T17:03:40.946Z,1363194220.946 [IBIT](INFO): Initialize IBIT Component.
2013-03-13T17:03:40.971Z,1363194220.971 [NavChartDb](INFO): Thread ID is 815
2013-03-13T17:03:40.973Z,1363194220.973 [CBIT](DEBUG): Initialize CBIT Component.
2013-03-13T17:03:40.974Z,1363194220.974 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2013-03-13T17:03:40.974Z,1363194220.974 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2013-03-13T17:03:40.980Z,1363194220.980 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2013-03-13T17:03:40.981Z,1363194220.981 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2013-03-13T17:03:40.981Z,1363194220.981 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2013-03-13T17:03:40.981Z,1363194220.981 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2013-03-13T17:03:40.981Z,1363194220.981 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2013-03-13T17:03:40.982Z,1363194220.982 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2013-03-13T17:03:40.982Z,1363194220.982 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2013-03-13T17:03:40.982Z,1363194220.982 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2013-03-13T17:03:40.983Z,1363194220.983 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2013-03-13T17:03:41.016Z,1363194221.016 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2013-03-13T17:03:41.016Z,1363194221.016 [NavChart](DEBUG): Initialize NavChart Derivation.
2013-03-13T17:03:41.017Z,1363194221.017 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2013-03-13T17:03:41.017Z,1363194221.017 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2013-03-13T17:03:41.018Z,1363194221.017 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2013-03-13T17:03:41.022Z,1363194221.022 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2013-03-13T17:03:41.023Z,1363194221.023 [Navigation](DEBUG): Initializing Navigation.
2013-03-13T17:03:41.023Z,1363194221.023 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2013-03-13T17:03:41.025Z,1363194221.025 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2013-03-13T17:03:41.026Z,1363194221.026 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2013-03-13T17:03:41.032Z,1363194221.032 [LoopControl](DEBUG): Initialize LoopControlComponent.
2013-03-13T17:03:41.999Z,1363194221.999 [Batt_Ocean_Server](ERROR): Batt_Ocean_Server A initialization uart error: serial timeout
2013-03-13T17:03:41.999Z,1363194221.999 [Batt_Ocean_Server](ERROR): Ocean Server Batteries failed to initialize. Re-initializing
2013-03-13T17:03:41.999Z,1363194221.999 [Batt_Ocean_Server] Communications Fault, FailCount= 1
2013-03-13T17:03:41.999Z,1363194221.999 [Batt_Ocean_Server](ERROR): Communications Fault
2013-03-13T17:03:42.010Z,1363194222.010 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2013-03-13T17:03:42.044Z,1363194222.044 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2013-03-13T17:03:42.082Z,1363194222.082 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://aosn.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface RunIn="Progression"/>

    <Aggregate Id="StartupSatComms" >

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

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

    </Aggregate>

</Mission>


2013-03-13T17:03:42.090Z,1363194222.091 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2013-03-13T17:03:42.177Z,1363194222.177 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2013-03-13T17:03:42.179Z,1363194222.179 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2013-03-13T17:03:42.182Z,1363194222.182 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-03-13T17:03:42.216Z,1363194222.216 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2013-03-13T17:03:42.228Z,1363194222.227 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-03-13T17:03:42.234Z,1363194222.234 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2013-03-13T17:03:42.279Z,1363194222.279 [Default:D.SetSpeed](DEBUG): Construct.
2013-03-13T17:03:42.282Z,1363194222.282 [Default:E.GoToSurface](DEBUG): Construct GoToSurface.
2013-03-13T17:03:42.301Z,1363194222.301 [Default:F.Wait](DEBUG): Construct Wait.
2013-03-13T17:03:42.313Z,1363194222.313 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
xmlns:Control="Tethys/Control"
xmlns:Guidance="Tethys/Guidance" 
xmlns:Units="Tethys/Units"
xmlns:Universal="Tethys/Universal"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="Tethys http://aosn.mbari.org/tethys/Xml/Tethys.xsd
Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
Id="Default">

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

    <Aggregate Id="GPS" >

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

<!-- Run at high speed -->

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

<!-- Get to the surface -->

        <Guidance:GoToSurface RunIn="Sequence"/>

<!-- Get GPS fix -->

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

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

    </Aggregate>

    <Aggregate Id="Iridium" >

<!-- Run at high speed -->

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

<!-- Get to the surface -->

        <Guidance:GoToSurface RunIn="Sequence"/>

<!-- Do data comms -->

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

    </Aggregate>

    <Aggregate Id="CallIridium" >

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

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

        <Call RefId="Iridium"/>

    </Aggregate>

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

<!-- Run at low speed -->

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

    <Guidance:GoToSurface RunIn="Parallel"/>

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

</Mission>


2013-03-13T17:03:42.318Z,1363194222.318 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,NAL9602,Onboard,Radio_Freewave,Aanderaa_O2,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,
2013-03-13T17:03:42.367Z,1363194222.367 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-03-13T17:03:42.563Z,1363194222.563 [Radio_Freewave](INFO): Powering up
2013-03-13T17:03:42.927Z,1363194222.927 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-03-13T17:03:42.927Z,1363194222.927 [DVL_micro](INFO): Querying output modes
2013-03-13T17:03:42.927Z,1363194222.927 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-03-13T17:03:42.938Z,1363194222.938 [DVL_micro](DEBUG): cmdResponse: 01
2013-03-13T17:03:42.939Z,1363194222.939 [DVL_micro](INFO): NQ1 output enabled
2013-03-13T17:03:42.939Z,1363194222.939 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-03-13T17:03:42.947Z,1363194222.947 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2013-03-13T17:03:42.955Z,1363194222.955 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 
2013-03-13T17:03:42.960Z,1363194222.960 [DVL_micro](INFO): pause:Powering down
2013-03-13T17:03:42.975Z,1363194222.975 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2013-03-13T17:03:42.981Z,1363194222.981 [ElevatorServo](DEBUG): Initializing EZServoServo.
2013-03-13T17:03:42.991Z,1363194222.991 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2013-03-13T17:03:43.005Z,1363194223.006 [MassServo](DEBUG): Initializing EZServoServo.
2013-03-13T17:03:43.011Z,1363194223.011 [MassServo](DEBUG): Initializing MassServo.
2013-03-13T17:03:43.016Z,1363194223.016 [RudderServo](DEBUG): Initializing EZServoServo.
2013-03-13T17:03:43.023Z,1363194223.023 [RudderServo](DEBUG): Initializing RudderServo.
2013-03-13T17:03:43.028Z,1363194223.028 [ThrusterServo](DEBUG): Initializing EZServoServo.
2013-03-13T17:03:43.035Z,1363194223.035 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2013-03-13T17:03:43.105Z,1363194223.105 [CBIT](ERROR): Communications Fault in component: Batt_Ocean_Server
2013-03-13T17:03:43.105Z,1363194223.105 [CBIT](INFO): Clearing failed state for component Batt_Ocean_Server
2013-03-13T17:03:43.105Z,1363194223.105 [Batt_Ocean_Server] No Fault, FailCount= 1
2013-03-13T17:03:45.149Z,1363194225.149 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2013-03-13T17:03:45.939Z,1363194225.939 [NAL9602](INFO): Powering up NAL9602
2013-03-13T17:03:47.331Z,1363194227.331 [Aanderaa_O2](INFO): Powering down
2013-03-13T17:03:56.567Z,1363194236.567 [NAL9602](INFO): NAL9602 initialized
2013-03-13T17:03:56.640Z,1363194236.640 [SBIT](IMPORTANT): Beginning Startup BIT
2013-03-13T17:03:56.643Z,1363194236.643 [CBIT](IMPORTANT): Beginning GF scan
2013-03-13T17:04:18.216Z,1363194258.216 [NAL9602](IMPORTANT): GPS fix at: 1363194243.00
2013-03-13T17:04:23.495Z,1363194263.495 [CBIT](IMPORTANT): No ground fault detected
2013-03-13T17:04:25.459Z,1363194265.459 [NAL9602](INFO): Powering down
2013-03-13T17:04:50.417Z,1363194290.417 [SBIT](IMPORTANT): SBIT PASSED
2013-03-13T17:04:50.814Z,1363194290.814 [MissionManager](IMPORTANT): Started mission Startup
2013-03-13T17:04:50.814Z,1363194290.815 [Startup] Running Loop=1
2013-03-13T17:04:50.815Z,1363194290.815 [Startup](INFO): Aggregate::initialize Startup
2013-03-13T17:04:50.815Z,1363194290.815 [Startup:A.GoToSurface] Running Loop=1
2013-03-13T17:04:50.815Z,1363194290.815 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T17:04:50.821Z,1363194290.821 [Startup:StartupSatComms] Running Loop=1
2013-03-13T17:04:50.821Z,1363194290.821 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2013-03-13T17:04:50.821Z,1363194290.821 [Startup:StartupSatComms:A] Running Loop=1
2013-03-13T17:04:51.214Z,1363194291.214 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2013-03-13T17:04:51.636Z,1363194291.635 [NAL9602](INFO): Powering up
2013-03-13T17:05:02.663Z,1363194302.663 [NAL9602](INFO): NAL9602 initialized
2013-03-13T17:05:18.143Z,1363194318.143 [NAL9602](IMPORTANT): GPS fix at: 1363194303.00
2013-03-13T17:05:18.175Z,1363194318.175 [Startup:StartupSatComms:A] Stopped
2013-03-13T17:05:18.175Z,1363194318.175 [Startup:StartupSatComms:B] Running Loop=1
2013-03-13T17:05:18.535Z,1363194318.535 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2013-03-13T17:05:38.828Z,1363194338.828 [NAL9602](INFO): SBD MO Status=1, MOMSN=7108, MT Status=0, MTMSN=0
2013-03-13T17:05:38.883Z,1363194338.883 [NAL9602](INFO): Sent 136 bytes from file Logs/20130312T160652/shore0055.lzma
2013-03-13T17:05:38.883Z,1363194338.883 [NAL9602](INFO): Packets left to send: 0
2013-03-13T17:05:38.885Z,1363194338.885 [NAL9602](INFO): Stored copy of sent data in Logs/20130312T160652/shore0055.lzma.parts/0000.sbd
2013-03-13T17:05:48.275Z,1363194348.275 [NAL9602](INFO): SBD MO Status=1, MOMSN=7109, MT Status=0, MTMSN=0
2013-03-13T17:05:48.323Z,1363194348.323 [NAL9602](INFO): Sent 332 bytes from file Logs/20130312T215505/shore0000.lzma
2013-03-13T17:05:48.323Z,1363194348.323 [NAL9602](INFO): Packets left to send: 2
2013-03-13T17:05:48.324Z,1363194348.324 [NAL9602](INFO): Stored copy of sent data in Logs/20130312T215505/shore0000.lzma.parts/0002.sbd
2013-03-13T17:06:00.955Z,1363194360.955 [NAL9602](INFO): SBD MO Status=1, MOMSN=7110, MT Status=0, MTMSN=0
2013-03-13T17:06:01.003Z,1363194361.003 [NAL9602](INFO): Sent 332 bytes from file Logs/20130312T215505/shore0000.lzma
2013-03-13T17:06:01.003Z,1363194361.003 [NAL9602](INFO): Packets left to send: 1
2013-03-13T17:06:01.004Z,1363194361.004 [NAL9602](INFO): Stored copy of sent data in Logs/20130312T215505/shore0000.lzma.parts/0001.sbd
2013-03-13T17:06:06.063Z,1363194366.063 [CommandLine](IMPORTANT): got command failComponent
2013-03-13T17:06:06.063Z,1363194366.063 [CommandLine](IMPORTANT): Failed components:
2013-03-13T17:06:06.064Z,1363194366.063 [CommandLine](IMPORTANT): No failed Components.
2013-03-13T17:06:14.498Z,1363194374.498 [NAL9602](INFO): SBD MO Status=1, MOMSN=7111, MT Status=0, MTMSN=0
2013-03-13T17:06:14.547Z,1363194374.547 [NAL9602](INFO): Sent 280 bytes from file Logs/20130312T215505/shore0000.lzma
2013-03-13T17:06:14.547Z,1363194374.547 [NAL9602](INFO): Packets left to send: 0
2013-03-13T17:06:14.548Z,1363194374.548 [NAL9602](INFO): Stored copy of sent data in Logs/20130312T215505/shore0000.lzma.parts/0000.sbd
2013-03-13T17:06:18.380Z,1363194378.379 [Startup:StartupSatComms:B](INFO): Timed out from 2013-03-13T17:05:18.2Z
2013-03-13T17:06:18.380Z,1363194378.380 [Startup:StartupSatComms:B:A_Timeout] Running Loop=1
2013-03-13T17:06:18.380Z,1363194378.380 [Startup:StartupSatComms:B:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:B:A_Timeout
2013-03-13T17:06:18.380Z,1363194378.380 [Startup:StartupSatComms:B:A_Timeout](INFO): Completed Startup:StartupSatComms:B:A_Timeout
2013-03-13T17:06:18.380Z,1363194378.380 [Startup:StartupSatComms:B] Stopped
2013-03-13T17:06:18.380Z,1363194378.380 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2013-03-13T17:06:18.380Z,1363194378.380 [Startup:StartupSatComms] Stopped
2013-03-13T17:06:18.380Z,1363194378.381 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2013-03-13T17:06:18.381Z,1363194378.381 [Startup](INFO): Completed Startup
2013-03-13T17:06:18.381Z,1363194378.381 [Startup] Stopped
2013-03-13T17:06:18.382Z,1363194378.382 [Startup](INFO): Aggregate::uninitialize Startup
2013-03-13T17:06:18.382Z,1363194378.382 [Startup:A.GoToSurface] Stopped
2013-03-13T17:06:18.382Z,1363194378.382 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T17:06:18.819Z,1363194378.819 [MissionManager](IMPORTANT): Started mission Default
2013-03-13T17:06:18.819Z,1363194378.819 [Default] Running Loop=1
2013-03-13T17:06:18.819Z,1363194378.819 [Default](INFO): Aggregate::initialize Default
2013-03-13T17:06:18.819Z,1363194378.819 [Default:D.SetSpeed] Running Loop=1
2013-03-13T17:06:18.819Z,1363194378.819 [Default:D.SetSpeed](DEBUG): Initialize.
2013-03-13T17:06:18.819Z,1363194378.819 [Default:E.GoToSurface] Running Loop=1
2013-03-13T17:06:18.819Z,1363194378.819 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T17:06:18.820Z,1363194378.819 [Default:Iridium] Running Loop=1
2013-03-13T17:06:18.820Z,1363194378.820 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-03-13T17:06:18.820Z,1363194378.820 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-13T17:06:18.820Z,1363194378.820 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-03-13T17:06:18.820Z,1363194378.820 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-03-13T17:06:18.820Z,1363194378.820 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T17:06:18.821Z,1363194378.820 [Default:E.GoToSurface] Running Loop=1
2013-03-13T17:06:18.826Z,1363194378.826 [Default:D.SetSpeed] Running Loop=1
2013-03-13T17:06:18.830Z,1363194378.830 [Default:CallIridium] Running Loop=1
2013-03-13T17:06:18.831Z,1363194378.831 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-03-13T17:06:18.831Z,1363194378.831 [Default:CallIridium:A] Running Loop=1
2013-03-13T17:06:18.832Z,1363194378.832 [Default:CallIridium:A] Stopped
2013-03-13T17:06:18.833Z,1363194378.833 [Default:CallIridium:B] Running Loop=1
2013-03-13T17:06:18.833Z,1363194378.833 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-03-13T17:06:18.838Z,1363194378.838 [Default:Iridium:B.GoToSurface] Stopped
2013-03-13T17:06:18.838Z,1363194378.838 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T17:06:18.838Z,1363194378.838 [Default:Iridium:Read_Iridium] Running Loop=1
2013-03-13T17:06:18.838Z,1363194378.838 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-13T17:06:18.843Z,1363194378.843 [Default:GPS] Running Loop=1
2013-03-13T17:06:18.843Z,1363194378.843 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-03-13T17:06:18.843Z,1363194378.843 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-13T17:06:18.843Z,1363194378.843 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-03-13T17:06:18.844Z,1363194378.843 [Default:GPS:B.GoToSurface] Running Loop=1
2013-03-13T17:06:18.844Z,1363194378.844 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T17:06:18.849Z,1363194378.849 [Default:GPS:B.GoToSurface] Stopped
2013-03-13T17:06:18.849Z,1363194378.849 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T17:06:18.849Z,1363194378.849 [Default:GPS:Read_GPS] Running Loop=1
2013-03-13T17:06:18.849Z,1363194378.849 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-13T17:06:19.245Z,1363194379.245 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2013-03-13T17:06:19.248Z,1363194379.248 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2013-03-13T17:06:26.358Z,1363194386.358 [NAL9602](INFO): SBD MO Status=1, MOMSN=7112, MT Status=0, MTMSN=0
2013-03-13T17:06:26.407Z,1363194386.407 [NAL9602](INFO): Sent 332 bytes from file Logs/20130313T170330/shore0000.lzma
2013-03-13T17:06:26.407Z,1363194386.407 [NAL9602](INFO): Packets left to send: 2
2013-03-13T17:06:26.408Z,1363194386.408 [NAL9602](INFO): Stored copy of sent data in Logs/20130313T170330/shore0000.lzma.parts/0002.sbd
2013-03-13T17:06:32.555Z,1363194392.555 [CommandLine](IMPORTANT): got command ibit
2013-03-13T17:06:32.687Z,1363194392.687 [IBIT](IMPORTANT): Beginning Initiated BIT
2013-03-13T17:06:32.687Z,1363194392.687 [IBIT](IMPORTANT): Beginning control surface checks.

2013-03-13T17:06:32.689Z,1363194392.689 [CBIT](IMPORTANT): Beginning GF scan
2013-03-13T17:06:33.460Z,1363194393.460 [Radio_Freewave](INFO): Powering down
2013-03-13T17:06:34.264Z,1363194394.263 [Radio_Freewave](INFO): Powering up
2013-03-13T17:06:41.925Z,1363194401.925 [NAL9602](INFO): SBD MO Status=1, MOMSN=7113, MT Status=0, MTMSN=0
2013-03-13T17:06:41.975Z,1363194401.975 [NAL9602](INFO): Sent 332 bytes from file Logs/20130313T170330/shore0000.lzma
2013-03-13T17:06:41.975Z,1363194401.975 [NAL9602](INFO): Packets left to send: 1
2013-03-13T17:06:41.976Z,1363194401.976 [NAL9602](INFO): Stored copy of sent data in Logs/20130313T170330/shore0000.lzma.parts/0001.sbd
2013-03-13T17:06:51.645Z,1363194411.645 [NAL9602](INFO): SBD MO Status=1, MOMSN=7114, MT Status=0, MTMSN=0
2013-03-13T17:06:51.695Z,1363194411.695 [NAL9602](INFO): Sent 71 bytes from file Logs/20130313T170330/shore0000.lzma
2013-03-13T17:06:51.695Z,1363194411.695 [NAL9602](INFO): Packets left to send: 0
2013-03-13T17:06:51.696Z,1363194411.696 [NAL9602](INFO): Stored copy of sent data in Logs/20130313T170330/shore0000.lzma.parts/0000.sbd
2013-03-13T17:06:58.901Z,1363194418.901 [NAL9602](INFO): SBD MO Status=0, MOMSN=7115, MT Status=0, MTMSN=0
2013-03-13T17:07:00.107Z,1363194420.107 [NAL9602](IMPORTANT): GPS fix at: 1363194406.00
2013-03-13T17:07:00.928Z,1363194420.928 [CBIT](IMPORTANT): No ground fault detected
2013-03-13T17:07:16.398Z,1363194436.398 [NAL9602](INFO): SBD MO Status=1, MOMSN=7116, MT Status=0, MTMSN=0
2013-03-13T17:07:16.451Z,1363194436.451 [NAL9602](INFO): Sent 332 bytes from file Logs/20130313T170330/shore0001.lzma
2013-03-13T17:07:16.451Z,1363194436.451 [NAL9602](INFO): Packets left to send: 1
2013-03-13T17:07:16.452Z,1363194436.452 [NAL9602](INFO): Stored copy of sent data in Logs/20130313T170330/shore0001.lzma.parts/0001.sbd
2013-03-13T17:07:19.587Z,1363194439.587 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 5
Latitude: 33.616806 Longitude: -117.918358
2013-03-13T17:07:19.877Z,1363194439.877 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 235.129990
Voltage: 16.242874
2013-03-13T17:07:19.877Z,1363194439.877 [IBIT](IMPORTANT): batteryCapacityThreshold: 5.000000 Ah
2013-03-13T17:07:19.877Z,1363194439.877 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.500000 V
2013-03-13T17:07:20.250Z,1363194440.250 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2013-03-13T17:07:20.250Z,1363194440.250 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2013-03-13T17:07:20.276Z,1363194440.276 [IBIT](IMPORTANT): Pressure:17.106230 PSI
2013-03-13T17:07:20.277Z,1363194440.277 [IBIT](IMPORTANT): Humidity:12.707974 %
2013-03-13T17:07:20.649Z,1363194440.649 [IBIT](IMPORTANT): surfaceThreshold: 0.500000 m
2013-03-13T17:07:20.650Z,1363194440.650 [IBIT](IMPORTANT): buoyancyNeutral: 360.000000 cc
2013-03-13T17:07:20.650Z,1363194440.650 [IBIT](IMPORTANT): massDefault: 0.900000 cm
2013-03-13T17:07:20.676Z,1363194440.676 [IBIT](IMPORTANT): stopDepth: 95.000000 m
2013-03-13T17:07:20.676Z,1363194440.676 [IBIT](IMPORTANT): abortDepth: 125.000000 m
2013-03-13T17:07:20.676Z,1363194440.676 [IBIT](IMPORTANT): IBIT PASSED
2013-03-13T17:07:21.086Z,1363194441.086 [Default:Iridium:Read_Iridium] Stopped
2013-03-13T17:07:21.086Z,1363194441.086 [Default:Iridium](INFO): Completed Default:Iridium
2013-03-13T17:07:21.086Z,1363194441.086 [Default:Iridium] Stopped
2013-03-13T17:07:21.086Z,1363194441.086 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-03-13T17:07:21.087Z,1363194441.087 [Default:Iridium:A.SetSpeed] Stopped
2013-03-13T17:07:21.087Z,1363194441.087 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T17:07:21.087Z,1363194441.087 [Default:F.Wait] Running Loop=1
2013-03-13T17:07:21.087Z,1363194441.087 [Default:F.Wait](DEBUG): Initialize Wait Component.
2013-03-13T17:07:21.087Z,1363194441.087 [Default:GPS:Read_GPS] Stopped
2013-03-13T17:07:21.087Z,1363194441.087 [Default:GPS:D] Running Loop=1
2013-03-13T17:07:21.449Z,1363194441.448 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-03-13T17:07:21.449Z,1363194441.449 [Default:CallIridium:B] Stopped
2013-03-13T17:07:21.449Z,1363194441.449 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-03-13T17:07:21.449Z,1363194441.449 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-03-13T17:07:21.449Z,1363194441.449 [Default:CallIridium] Stopped
2013-03-13T17:07:21.449Z,1363194441.449 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-03-13T17:07:21.473Z,1363194441.473 [Default:GPS:D] Stopped
2013-03-13T17:07:21.474Z,1363194441.474 [Default:GPS](INFO): Completed Default:GPS
2013-03-13T17:07:21.474Z,1363194441.474 [Default:GPS] Stopped
2013-03-13T17:07:21.474Z,1363194441.474 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-03-13T17:07:21.474Z,1363194441.474 [Default:GPS:A.SetSpeed] Stopped
2013-03-13T17:07:21.474Z,1363194441.474 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T17:07:27.014Z,1363194447.014 [NAL9602](INFO): SBD MO Status=1, MOMSN=7117, MT Status=0, MTMSN=0
2013-03-13T17:07:27.063Z,1363194447.063 [NAL9602](INFO): Sent 7 bytes from file Logs/20130313T170330/shore0001.lzma
2013-03-13T17:07:27.063Z,1363194447.063 [NAL9602](INFO): Packets left to send: 0
2013-03-13T17:07:27.064Z,1363194447.064 [NAL9602](INFO): Stored copy of sent data in Logs/20130313T170330/shore0001.lzma.parts/0000.sbd
2013-03-13T17:07:36.982Z,1363194456.982 [NAL9602](INFO): SBD MO Status=0, MOMSN=7118, MT Status=0, MTMSN=0
2013-03-13T17:07:52.012Z,1363194472.012 [NAL9602](INFO): Powering down
2013-03-13T17:12:37.083Z,1363194757.083 [Default:CallIridium] Running Loop=1
2013-03-13T17:12:37.083Z,1363194757.083 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-03-13T17:12:37.083Z,1363194757.083 [Default:CallIridium:A] Running Loop=1
2013-03-13T17:12:37.084Z,1363194757.084 [Default:CallIridium:A] Stopped
2013-03-13T17:12:37.084Z,1363194757.084 [Default:CallIridium:B] Running Loop=1
2013-03-13T17:12:37.084Z,1363194757.084 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-03-13T17:12:42.029Z,1363194762.029 [Default:Iridium] Running Loop=1
2013-03-13T17:12:42.029Z,1363194762.029 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-03-13T17:12:42.029Z,1363194762.029 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-13T17:12:42.029Z,1363194762.029 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-03-13T17:12:42.029Z,1363194762.029 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-03-13T17:12:42.029Z,1363194762.029 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T17:12:42.030Z,1363194762.030 [Default:Iridium:B.GoToSurface] Stopped
2013-03-13T17:12:42.030Z,1363194762.030 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T17:12:42.030Z,1363194762.030 [Default:Iridium:Read_Iridium] Running Loop=1
2013-03-13T17:12:42.031Z,1363194762.030 [Default:GPS] Running Loop=1
2013-03-13T17:12:42.031Z,1363194762.031 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-03-13T17:12:42.031Z,1363194762.031 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-13T17:12:42.031Z,1363194762.031 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-03-13T17:12:42.031Z,1363194762.031 [Default:GPS:B.GoToSurface] Running Loop=1
2013-03-13T17:12:42.031Z,1363194762.031 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T17:12:42.032Z,1363194762.032 [Default:GPS:B.GoToSurface] Stopped
2013-03-13T17:12:42.032Z,1363194762.032 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T17:12:42.032Z,1363194762.032 [Default:GPS:Read_GPS] Running Loop=1
2013-03-13T17:12:42.675Z,1363194762.675 [NAL9602](INFO): Powering up
2013-03-13T17:12:53.503Z,1363194773.503 [NAL9602](INFO): NAL9602 initialized
2013-03-13T17:13:17.409Z,1363194797.409 [NAL9602](INFO): SBD MO Status=2, MOMSN=7119, MT Status=2, MTMSN=0
2013-03-13T17:13:17.409Z,1363194797.409 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-03-13T17:15:45.229Z,1363194945.229 [NAL9602](INFO): SBD MO Status=1, MOMSN=7119, MT Status=0, MTMSN=0
2013-03-13T17:15:45.279Z,1363194945.279 [NAL9602](INFO): Sent 332 bytes from file Logs/20130313T170330/shore0002.lzma
2013-03-13T17:15:45.279Z,1363194945.279 [NAL9602](INFO): Packets left to send: 1
2013-03-13T17:15:45.280Z,1363194945.280 [NAL9602](INFO): Stored copy of sent data in Logs/20130313T170330/shore0002.lzma.parts/0001.sbd
2013-03-13T17:16:00.694Z,1363194960.694 [NAL9602](INFO): SBD MO Status=1, MOMSN=7120, MT Status=0, MTMSN=0
2013-03-13T17:16:00.743Z,1363194960.743 [NAL9602](INFO): Sent 129 bytes from file Logs/20130313T170330/shore0002.lzma
2013-03-13T17:16:00.743Z,1363194960.743 [NAL9602](INFO): Packets left to send: 0
2013-03-13T17:16:00.744Z,1363194960.744 [NAL9602](INFO): Stored copy of sent data in Logs/20130313T170330/shore0002.lzma.parts/0000.sbd
2013-03-13T17:16:09.465Z,1363194969.465 [NAL9602](INFO): SBD MO Status=0, MOMSN=7121, MT Status=0, MTMSN=0
2013-03-13T17:16:09.550Z,1363194969.550 [Default:Iridium:Read_Iridium] Stopped
2013-03-13T17:16:09.566Z,1363194969.566 [Default:Iridium](INFO): Completed Default:Iridium
2013-03-13T17:16:09.567Z,1363194969.566 [Default:Iridium] Stopped
2013-03-13T17:16:09.567Z,1363194969.567 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-03-13T17:16:09.567Z,1363194969.567 [Default:Iridium:A.SetSpeed] Stopped
2013-03-13T17:16:09.567Z,1363194969.567 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T17:16:09.887Z,1363194969.887 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-03-13T17:16:09.887Z,1363194969.888 [Default:CallIridium:B] Stopped
2013-03-13T17:16:09.888Z,1363194969.888 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-03-13T17:16:09.888Z,1363194969.888 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-03-13T17:16:09.888Z,1363194969.888 [Default:CallIridium] Stopped
2013-03-13T17:16:09.888Z,1363194969.888 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-03-13T17:16:16.263Z,1363194976.263 [NAL9602](IMPORTANT): GPS fix at: 1363194962.00
2013-03-13T17:16:16.283Z,1363194976.283 [Default:GPS:Read_GPS] Stopped
2013-03-13T17:16:16.283Z,1363194976.283 [Default:GPS:D] Running Loop=1
2013-03-13T17:16:16.701Z,1363194976.701 [Default:GPS:D] Stopped
2013-03-13T17:16:16.701Z,1363194976.701 [Default:GPS](INFO): Completed Default:GPS
2013-03-13T17:16:16.701Z,1363194976.701 [Default:GPS] Stopped
2013-03-13T17:16:16.701Z,1363194976.701 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-03-13T17:16:16.701Z,1363194976.701 [Default:GPS:A.SetSpeed] Stopped
2013-03-13T17:16:16.701Z,1363194976.701 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T17:16:37.236Z,1363194997.236 [NAL9602](INFO): Powering down
2013-03-13T17:21:12.274Z,1363195272.274 [Default:CallIridium] Running Loop=1
2013-03-13T17:21:12.274Z,1363195272.274 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-03-13T17:21:12.274Z,1363195272.274 [Default:CallIridium:A] Running Loop=1
2013-03-13T17:21:12.274Z,1363195272.274 [Default:CallIridium:A] Stopped
2013-03-13T17:21:12.275Z,1363195272.274 [Default:CallIridium:B] Running Loop=1
2013-03-13T17:21:12.275Z,1363195272.275 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-03-13T17:21:17.249Z,1363195277.249 [Default:Iridium] Running Loop=1
2013-03-13T17:21:17.249Z,1363195277.249 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-03-13T17:21:17.249Z,1363195277.249 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-13T17:21:17.249Z,1363195277.249 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-03-13T17:21:17.249Z,1363195277.249 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-03-13T17:21:17.249Z,1363195277.249 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T17:21:17.250Z,1363195277.250 [Default:Iridium:B.GoToSurface] Stopped
2013-03-13T17:21:17.270Z,1363195277.270 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T17:21:17.270Z,1363195277.270 [Default:Iridium:Read_Iridium] Running Loop=1
2013-03-13T17:21:17.271Z,1363195277.271 [Default:GPS] Running Loop=1
2013-03-13T17:21:17.271Z,1363195277.271 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-03-13T17:21:17.271Z,1363195277.271 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-13T17:21:17.271Z,1363195277.271 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-03-13T17:21:17.271Z,1363195277.271 [Default:GPS:B.GoToSurface] Running Loop=1
2013-03-13T17:21:17.271Z,1363195277.271 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T17:21:17.272Z,1363195277.272 [Default:GPS:B.GoToSurface] Stopped
2013-03-13T17:21:17.272Z,1363195277.272 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T17:21:17.272Z,1363195277.272 [Default:GPS:Read_GPS] Running Loop=1
2013-03-13T17:21:17.883Z,1363195277.884 [NAL9602](INFO): Powering up
2013-03-13T17:21:28.403Z,1363195288.403 [NAL9602](INFO): NAL9602 initialized
2013-03-13T17:21:53.781Z,1363195313.781 [NAL9602](INFO): SBD MO Status=1, MOMSN=7122, MT Status=0, MTMSN=0
2013-03-13T17:21:53.831Z,1363195313.831 [NAL9602](INFO): Sent 260 bytes from file Logs/20130313T170330/shore0003.lzma
2013-03-13T17:21:53.831Z,1363195313.831 [NAL9602](INFO): Packets left to send: 0
2013-03-13T17:21:53.832Z,1363195313.832 [NAL9602](INFO): Stored copy of sent data in Logs/20130313T170330/shore0003.lzma.parts/0000.sbd
2013-03-13T17:22:04.924Z,1363195324.924 [NAL9602](INFO): SBD MO Status=0, MOMSN=7123, MT Status=0, MTMSN=0
2013-03-13T17:22:05.005Z,1363195325.005 [Default:Iridium:Read_Iridium] Stopped
2013-03-13T17:22:05.005Z,1363195325.005 [Default:Iridium](INFO): Completed Default:Iridium
2013-03-13T17:22:05.005Z,1363195325.006 [Default:Iridium] Stopped
2013-03-13T17:22:05.006Z,1363195325.006 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-03-13T17:22:05.006Z,1363195325.006 [Default:Iridium:A.SetSpeed] Stopped
2013-03-13T17:22:05.006Z,1363195325.006 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T17:22:05.344Z,1363195325.344 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-03-13T17:22:05.344Z,1363195325.344 [Default:CallIridium:B] Stopped
2013-03-13T17:22:05.344Z,1363195325.344 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-03-13T17:22:05.345Z,1363195325.345 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-03-13T17:22:05.345Z,1363195325.345 [Default:CallIridium] Stopped
2013-03-13T17:22:05.345Z,1363195325.345 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-03-13T17:22:06.211Z,1363195326.211 [NAL9602](IMPORTANT): GPS fix at: 1363195312.00
2013-03-13T17:22:06.228Z,1363195326.228 [Default:GPS:Read_GPS] Stopped
2013-03-13T17:22:06.228Z,1363195326.228 [Default:GPS:D] Running Loop=1
2013-03-13T17:22:06.577Z,1363195326.577 [Default:GPS:D] Stopped
2013-03-13T17:22:06.577Z,1363195326.577 [Default:GPS](INFO): Completed Default:GPS
2013-03-13T17:22:06.577Z,1363195326.578 [Default:GPS] Stopped
2013-03-13T17:22:06.578Z,1363195326.578 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-03-13T17:22:06.578Z,1363195326.578 [Default:GPS:A.SetSpeed] Stopped
2013-03-13T17:22:06.578Z,1363195326.578 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T17:22:27.124Z,1363195347.124 [NAL9602](INFO): Powering down
2013-03-13T17:26:55.859Z,1363195615.859 [CommandLine](IMPORTANT): got command failComponent
2013-03-13T17:26:55.859Z,1363195615.859 [CommandLine](IMPORTANT): Failed components:
2013-03-13T17:26:55.859Z,1363195615.859 [CommandLine](IMPORTANT): No failed Components.
2013-03-13T17:27:07.124Z,1363195627.124 [Default:CallIridium] Running Loop=1
2013-03-13T17:27:07.124Z,1363195627.124 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-03-13T17:27:07.125Z,1363195627.125 [Default:CallIridium:A] Running Loop=1
2013-03-13T17:27:07.125Z,1363195627.125 [Default:CallIridium:A] Stopped
2013-03-13T17:27:07.125Z,1363195627.125 [Default:CallIridium:B] Running Loop=1
2013-03-13T17:27:07.125Z,1363195627.125 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-03-13T17:27:12.128Z,1363195632.128 [Default:Iridium] Running Loop=1
2013-03-13T17:27:12.129Z,1363195632.129 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-03-13T17:27:12.129Z,1363195632.129 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-13T17:27:12.129Z,1363195632.129 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-03-13T17:27:12.129Z,1363195632.129 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-03-13T17:27:12.129Z,1363195632.129 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T17:27:12.130Z,1363195632.130 [Default:Iridium:B.GoToSurface] Stopped
2013-03-13T17:27:12.130Z,1363195632.130 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T17:27:12.130Z,1363195632.130 [Default:Iridium:Read_Iridium] Running Loop=1
2013-03-13T17:27:12.131Z,1363195632.131 [Default:GPS] Running Loop=1
2013-03-13T17:27:12.131Z,1363195632.131 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-03-13T17:27:12.131Z,1363195632.131 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-13T17:27:12.131Z,1363195632.131 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-03-13T17:27:12.131Z,1363195632.131 [Default:GPS:B.GoToSurface] Running Loop=1
2013-03-13T17:27:12.131Z,1363195632.131 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T17:27:12.132Z,1363195632.132 [Default:GPS:B.GoToSurface] Stopped
2013-03-13T17:27:12.132Z,1363195632.132 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T17:27:12.132Z,1363195632.132 [Default:GPS:Read_GPS] Running Loop=1
2013-03-13T17:27:12.739Z,1363195632.740 [NAL9602](INFO): Powering up
2013-03-13T17:27:23.771Z,1363195643.771 [NAL9602](INFO): NAL9602 initialized
2013-03-13T17:27:46.659Z,1363195666.659 [NAL9602](INFO): SBD MO Status=2, MOMSN=7124, MT Status=2, MTMSN=0
2013-03-13T17:27:46.660Z,1363195666.660 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-03-13T17:27:47.911Z,1363195667.911 [NAL9602](IMPORTANT): GPS fix at: 1363195654.00
2013-03-13T17:27:47.935Z,1363195667.935 [Default:GPS:Read_GPS] Stopped
2013-03-13T17:27:47.935Z,1363195667.935 [Default:GPS:D] Running Loop=1
2013-03-13T17:27:48.291Z,1363195668.291 [Default:GPS:D] Stopped
2013-03-13T17:27:48.292Z,1363195668.292 [Default:GPS](INFO): Completed Default:GPS
2013-03-13T17:27:48.292Z,1363195668.292 [Default:GPS] Stopped
2013-03-13T17:27:48.292Z,1363195668.292 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-03-13T17:27:48.292Z,1363195668.292 [Default:GPS:A.SetSpeed] Stopped
2013-03-13T17:27:48.292Z,1363195668.292 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T17:28:07.673Z,1363195687.673 [NAL9602](INFO): SBD MO Status=1, MOMSN=7124, MT Status=0, MTMSN=0
2013-03-13T17:28:07.723Z,1363195687.723 [NAL9602](INFO): Sent 191 bytes from file Logs/20130313T170330/shore0004.lzma
2013-03-13T17:28:07.723Z,1363195687.723 [NAL9602](INFO): Packets left to send: 0
2013-03-13T17:28:07.724Z,1363195687.724 [NAL9602](INFO): Stored copy of sent data in Logs/20130313T170330/shore0004.lzma.parts/0000.sbd
2013-03-13T17:28:32.498Z,1363195712.498 [NAL9602](INFO): SBD MO Status=2, MOMSN=7125, MT Status=2, MTMSN=0
2013-03-13T17:28:32.498Z,1363195712.498 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-03-13T17:28:41.594Z,1363195721.594 [NAL9602](INFO): SBD MO Status=0, MOMSN=7125, MT Status=0, MTMSN=0
2013-03-13T17:28:41.685Z,1363195721.685 [Default:Iridium:Read_Iridium] Stopped
2013-03-13T17:28:41.685Z,1363195721.685 [Default:Iridium](INFO): Completed Default:Iridium
2013-03-13T17:28:41.686Z,1363195721.685 [Default:Iridium] Stopped
2013-03-13T17:28:41.686Z,1363195721.686 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-03-13T17:28:41.686Z,1363195721.686 [Default:Iridium:A.SetSpeed] Stopped
2013-03-13T17:28:41.686Z,1363195721.686 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T17:28:42.048Z,1363195722.048 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-03-13T17:28:42.048Z,1363195722.048 [Default:CallIridium:B] Stopped
2013-03-13T17:28:42.048Z,1363195722.048 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-03-13T17:28:42.049Z,1363195722.049 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-03-13T17:28:42.049Z,1363195722.049 [Default:CallIridium] Stopped
2013-03-13T17:28:42.049Z,1363195722.049 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-03-13T17:28:52.228Z,1363195732.228 [NAL9602](INFO): Powering down
2013-03-13T17:33:42.170Z,1363196022.170 [Default:CallIridium] Running Loop=1
2013-03-13T17:33:42.170Z,1363196022.170 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-03-13T17:33:42.170Z,1363196022.170 [Default:CallIridium:A] Running Loop=1
2013-03-13T17:33:42.171Z,1363196022.171 [Default:CallIridium:A] Stopped
2013-03-13T17:33:42.171Z,1363196022.171 [Default:CallIridium:B] Running Loop=1
2013-03-13T17:33:42.171Z,1363196022.171 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-03-13T17:33:47.197Z,1363196027.197 [Default:Iridium] Running Loop=1
2013-03-13T17:33:47.197Z,1363196027.197 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-03-13T17:33:47.197Z,1363196027.197 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-13T17:33:47.197Z,1363196027.197 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-03-13T17:33:47.197Z,1363196027.197 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-03-13T17:33:47.197Z,1363196027.197 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T17:33:47.198Z,1363196027.198 [Default:Iridium:B.GoToSurface] Stopped
2013-03-13T17:33:47.198Z,1363196027.198 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T17:33:47.198Z,1363196027.198 [Default:Iridium:Read_Iridium] Running Loop=1
2013-03-13T17:33:47.199Z,1363196027.199 [Default:GPS] Running Loop=1
2013-03-13T17:33:47.199Z,1363196027.199 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-03-13T17:33:47.199Z,1363196027.199 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-13T17:33:47.199Z,1363196027.199 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-03-13T17:33:47.199Z,1363196027.199 [Default:GPS:B.GoToSurface] Running Loop=1
2013-03-13T17:33:47.199Z,1363196027.199 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T17:33:47.200Z,1363196027.200 [Default:GPS:B.GoToSurface] Stopped
2013-03-13T17:33:47.200Z,1363196027.200 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T17:33:47.200Z,1363196027.200 [Default:GPS:Read_GPS] Running Loop=1
2013-03-13T17:33:47.795Z,1363196027.796 [NAL9602](INFO): Powering up
2013-03-13T17:33:58.707Z,1363196038.707 [NAL9602](INFO): NAL9602 initialized
2013-03-13T17:34:16.405Z,1363196056.405 [NAL9602](INFO): SBD MO Status=1, MOMSN=7126, MT Status=0, MTMSN=0
2013-03-13T17:34:16.457Z,1363196056.457 [NAL9602](INFO): Sent 138 bytes from file Logs/20130313T170330/shore0005.lzma
2013-03-13T17:34:16.457Z,1363196056.457 [NAL9602](INFO): Packets left to send: 0
2013-03-13T17:34:16.459Z,1363196056.459 [NAL9602](INFO): Stored copy of sent data in Logs/20130313T170330/shore0005.lzma.parts/0000.sbd
2013-03-13T17:34:24.804Z,1363196064.804 [NAL9602](INFO): SBD MO Status=0, MOMSN=7127, MT Status=0, MTMSN=0
2013-03-13T17:34:24.893Z,1363196064.893 [Default:Iridium:Read_Iridium] Stopped
2013-03-13T17:34:24.893Z,1363196064.894 [Default:Iridium](INFO): Completed Default:Iridium
2013-03-13T17:34:24.893Z,1363196064.894 [Default:Iridium] Stopped
2013-03-13T17:34:24.894Z,1363196064.894 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-03-13T17:34:24.894Z,1363196064.894 [Default:Iridium:A.SetSpeed] Stopped
2013-03-13T17:34:24.894Z,1363196064.894 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T17:34:25.269Z,1363196065.269 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-03-13T17:34:25.269Z,1363196065.269 [Default:CallIridium:B] Stopped
2013-03-13T17:34:25.269Z,1363196065.269 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-03-13T17:34:25.269Z,1363196065.269 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-03-13T17:34:25.269Z,1363196065.269 [Default:CallIridium] Stopped
2013-03-13T17:34:25.269Z,1363196065.269 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-03-13T17:34:26.011Z,1363196066.011 [NAL9602](IMPORTANT): GPS fix at: 1363196053.00
2013-03-13T17:34:26.028Z,1363196066.028 [Default:GPS:Read_GPS] Stopped
2013-03-13T17:34:26.028Z,1363196066.028 [Default:GPS:D] Running Loop=1
2013-03-13T17:34:26.440Z,1363196066.440 [Default:GPS:D] Stopped
2013-03-13T17:34:26.441Z,1363196066.441 [Default:GPS](INFO): Completed Default:GPS
2013-03-13T17:34:26.441Z,1363196066.441 [Default:GPS] Stopped
2013-03-13T17:34:26.441Z,1363196066.441 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-03-13T17:34:26.441Z,1363196066.441 [Default:GPS:A.SetSpeed] Stopped
2013-03-13T17:34:26.441Z,1363196066.441 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T17:34:46.996Z,1363196086.996 [NAL9602](INFO): Powering down
2013-03-13T17:39:27.013Z,1363196367.013 [Default:CallIridium] Running Loop=1
2013-03-13T17:39:27.013Z,1363196367.013 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-03-13T17:39:27.013Z,1363196367.013 [Default:CallIridium:A] Running Loop=1
2013-03-13T17:39:27.013Z,1363196367.013 [Default:CallIridium:A] Stopped
2013-03-13T17:39:27.013Z,1363196367.013 [Default:CallIridium:B] Running Loop=1
2013-03-13T17:39:27.014Z,1363196367.013 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-03-13T17:39:32.013Z,1363196372.013 [Default:Iridium] Running Loop=1
2013-03-13T17:39:32.013Z,1363196372.013 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-03-13T17:39:32.013Z,1363196372.013 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-13T17:39:32.013Z,1363196372.013 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-03-13T17:39:32.013Z,1363196372.013 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-03-13T17:39:32.013Z,1363196372.013 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T17:39:32.014Z,1363196372.014 [Default:Iridium:B.GoToSurface] Stopped
2013-03-13T17:39:32.014Z,1363196372.014 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T17:39:32.014Z,1363196372.014 [Default:Iridium:Read_Iridium] Running Loop=1
2013-03-13T17:39:32.015Z,1363196372.015 [Default:GPS] Running Loop=1
2013-03-13T17:39:32.015Z,1363196372.015 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-03-13T17:39:32.015Z,1363196372.015 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-13T17:39:32.015Z,1363196372.015 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-03-13T17:39:32.015Z,1363196372.015 [Default:GPS:B.GoToSurface] Running Loop=1
2013-03-13T17:39:32.015Z,1363196372.015 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T17:39:32.016Z,1363196372.016 [Default:GPS:B.GoToSurface] Stopped
2013-03-13T17:39:32.016Z,1363196372.016 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T17:39:32.016Z,1363196372.016 [Default:GPS:Read_GPS] Running Loop=1
2013-03-13T17:39:32.608Z,1363196372.608 [NAL9602](INFO): Powering up
2013-03-13T17:39:43.467Z,1363196383.467 [NAL9602](INFO): NAL9602 initialized
2013-03-13T17:40:21.982Z,1363196421.982 [NAL9602](INFO): SBD MO Status=1, MOMSN=7128, MT Status=0, MTMSN=0
2013-03-13T17:40:22.031Z,1363196422.031 [NAL9602](INFO): Sent 138 bytes from file Logs/20130313T170330/shore0006.lzma
2013-03-13T17:40:22.031Z,1363196422.031 [NAL9602](INFO): Packets left to send: 0
2013-03-13T17:40:22.032Z,1363196422.032 [NAL9602](INFO): Stored copy of sent data in Logs/20130313T170330/shore0006.lzma.parts/0000.sbd
2013-03-13T17:40:33.169Z,1363196433.169 [NAL9602](INFO): SBD MO Status=0, MOMSN=7129, MT Status=0, MTMSN=0
2013-03-13T17:40:33.265Z,1363196433.265 [Default:Iridium:Read_Iridium] Stopped
2013-03-13T17:40:33.265Z,1363196433.265 [Default:Iridium](INFO): Completed Default:Iridium
2013-03-13T17:40:33.266Z,1363196433.266 [Default:Iridium] Stopped
2013-03-13T17:40:33.266Z,1363196433.266 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-03-13T17:40:33.266Z,1363196433.266 [Default:Iridium:A.SetSpeed] Stopped
2013-03-13T17:40:33.266Z,1363196433.266 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T17:40:33.559Z,1363196433.559 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-03-13T17:40:33.559Z,1363196433.559 [Default:CallIridium:B] Stopped
2013-03-13T17:40:33.559Z,1363196433.559 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-03-13T17:40:33.559Z,1363196433.559 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-03-13T17:40:33.559Z,1363196433.559 [Default:CallIridium] Stopped
2013-03-13T17:40:33.559Z,1363196433.559 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-03-13T17:40:34.335Z,1363196434.335 [NAL9602](IMPORTANT): GPS fix at: 1363196422.00
2013-03-13T17:40:34.368Z,1363196434.368 [Default:GPS:Read_GPS] Stopped
2013-03-13T17:40:34.368Z,1363196434.368 [Default:GPS:D] Running Loop=1
2013-03-13T17:40:34.771Z,1363196434.771 [Default:GPS:D] Stopped
2013-03-13T17:40:34.772Z,1363196434.772 [Default:GPS](INFO): Completed Default:GPS
2013-03-13T17:40:34.772Z,1363196434.772 [Default:GPS] Stopped
2013-03-13T17:40:34.772Z,1363196434.772 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-03-13T17:40:34.772Z,1363196434.772 [Default:GPS:A.SetSpeed] Stopped
2013-03-13T17:40:34.772Z,1363196434.772 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T17:40:55.309Z,1363196455.309 [NAL9602](INFO): Powering down
2013-03-13T17:45:35.325Z,1363196735.325 [Default:CallIridium] Running Loop=1
2013-03-13T17:45:35.325Z,1363196735.325 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-03-13T17:45:35.326Z,1363196735.326 [Default:CallIridium:A] Running Loop=1
2013-03-13T17:45:35.326Z,1363196735.326 [Default:CallIridium:A] Stopped
2013-03-13T17:45:35.326Z,1363196735.326 [Default:CallIridium:B] Running Loop=1
2013-03-13T17:45:35.326Z,1363196735.326 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-03-13T17:45:40.384Z,1363196740.384 [Default:Iridium] Running Loop=1
2013-03-13T17:45:40.384Z,1363196740.385 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-03-13T17:45:40.385Z,1363196740.385 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-13T17:45:40.385Z,1363196740.385 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-03-13T17:45:40.385Z,1363196740.385 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-03-13T17:45:40.385Z,1363196740.385 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T17:45:40.386Z,1363196740.386 [Default:Iridium:B.GoToSurface] Stopped
2013-03-13T17:45:40.386Z,1363196740.386 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T17:45:40.386Z,1363196740.386 [Default:Iridium:Read_Iridium] Running Loop=1
2013-03-13T17:45:40.386Z,1363196740.386 [Default:GPS] Running Loop=1
2013-03-13T17:45:40.386Z,1363196740.386 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-03-13T17:45:40.387Z,1363196740.386 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-13T17:45:40.387Z,1363196740.387 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-03-13T17:45:40.387Z,1363196740.387 [Default:GPS:B.GoToSurface] Running Loop=1
2013-03-13T17:45:40.387Z,1363196740.387 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T17:45:40.387Z,1363196740.388 [Default:GPS:B.GoToSurface] Stopped
2013-03-13T17:45:40.388Z,1363196740.388 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T17:45:40.388Z,1363196740.388 [Default:GPS:Read_GPS] Running Loop=1
2013-03-13T17:45:40.980Z,1363196740.980 [NAL9602](INFO): Powering up
2013-03-13T17:45:51.483Z,1363196751.483 [NAL9602](INFO): NAL9602 initialized
2013-03-13T17:46:08.785Z,1363196768.785 [NAL9602](INFO): SBD MO Status=1, MOMSN=7130, MT Status=0, MTMSN=0
2013-03-13T17:46:08.835Z,1363196768.835 [NAL9602](INFO): Sent 141 bytes from file Logs/20130313T170330/shore0007.lzma
2013-03-13T17:46:08.835Z,1363196768.835 [NAL9602](INFO): Packets left to send: 0
2013-03-13T17:46:08.836Z,1363196768.836 [NAL9602](INFO): Stored copy of sent data in Logs/20130313T170330/shore0007.lzma.parts/0000.sbd
2013-03-13T17:46:16.385Z,1363196776.385 [NAL9602](INFO): SBD MO Status=0, MOMSN=7131, MT Status=0, MTMSN=0
2013-03-13T17:46:16.477Z,1363196776.477 [Default:Iridium:Read_Iridium] Stopped
2013-03-13T17:46:16.477Z,1363196776.477 [Default:Iridium](INFO): Completed Default:Iridium
2013-03-13T17:46:16.477Z,1363196776.477 [Default:Iridium] Stopped
2013-03-13T17:46:16.477Z,1363196776.477 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-03-13T17:46:16.477Z,1363196776.477 [Default:Iridium:A.SetSpeed] Stopped
2013-03-13T17:46:16.477Z,1363196776.477 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T17:46:16.800Z,1363196776.800 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-03-13T17:46:16.800Z,1363196776.800 [Default:CallIridium:B] Stopped
2013-03-13T17:46:16.800Z,1363196776.800 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-03-13T17:46:16.800Z,1363196776.800 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-03-13T17:46:16.801Z,1363196776.801 [Default:CallIridium] Stopped
2013-03-13T17:46:16.801Z,1363196776.801 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-03-13T17:46:17.590Z,1363196777.591 [NAL9602](IMPORTANT): GPS fix at: 1363196766.00
2013-03-13T17:46:17.607Z,1363196777.607 [Default:GPS:Read_GPS] Stopped
2013-03-13T17:46:17.607Z,1363196777.607 [Default:GPS:D] Running Loop=1
2013-03-13T17:46:18.007Z,1363196778.007 [Default:GPS:D] Stopped
2013-03-13T17:46:18.007Z,1363196778.007 [Default:GPS](INFO): Completed Default:GPS
2013-03-13T17:46:18.007Z,1363196778.007 [Default:GPS] Stopped
2013-03-13T17:46:18.007Z,1363196778.007 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-03-13T17:46:18.008Z,1363196778.008 [Default:GPS:A.SetSpeed] Stopped
2013-03-13T17:46:18.008Z,1363196778.008 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T17:46:38.564Z,1363196798.564 [NAL9602](INFO): Powering down
2013-03-13T17:51:18.579Z,1363197078.579 [Default:CallIridium] Running Loop=1
2013-03-13T17:51:18.579Z,1363197078.579 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-03-13T17:51:18.580Z,1363197078.579 [Default:CallIridium:A] Running Loop=1
2013-03-13T17:51:18.580Z,1363197078.580 [Default:CallIridium:A] Stopped
2013-03-13T17:51:18.580Z,1363197078.580 [Default:CallIridium:B] Running Loop=1
2013-03-13T17:51:18.580Z,1363197078.580 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-03-13T17:51:23.579Z,1363197083.579 [Default:Iridium] Running Loop=1
2013-03-13T17:51:23.579Z,1363197083.579 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-03-13T17:51:23.579Z,1363197083.579 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-13T17:51:23.579Z,1363197083.579 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-03-13T17:51:23.580Z,1363197083.579 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-03-13T17:51:23.580Z,1363197083.580 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T17:51:23.580Z,1363197083.580 [Default:Iridium:B.GoToSurface] Stopped
2013-03-13T17:51:23.580Z,1363197083.580 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T17:51:23.581Z,1363197083.580 [Default:Iridium:Read_Iridium] Running Loop=1
2013-03-13T17:51:23.581Z,1363197083.581 [Default:GPS] Running Loop=1
2013-03-13T17:51:23.581Z,1363197083.581 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-03-13T17:51:23.581Z,1363197083.581 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-13T17:51:23.581Z,1363197083.581 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-03-13T17:51:23.581Z,1363197083.581 [Default:GPS:B.GoToSurface] Running Loop=1
2013-03-13T17:51:23.581Z,1363197083.581 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T17:51:23.582Z,1363197083.582 [Default:GPS:B.GoToSurface] Stopped
2013-03-13T17:51:23.582Z,1363197083.582 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T17:51:23.582Z,1363197083.582 [Default:GPS:Read_GPS] Running Loop=1
2013-03-13T17:51:24.184Z,1363197084.184 [NAL9602](INFO): Powering up
2013-03-13T17:51:35.223Z,1363197095.223 [NAL9602](INFO): NAL9602 initialized
2013-03-13T17:51:52.937Z,1363197112.937 [NAL9602](INFO): SBD MO Status=1, MOMSN=7132, MT Status=0, MTMSN=0
2013-03-13T17:51:52.987Z,1363197112.987 [NAL9602](INFO): Sent 138 bytes from file Logs/20130313T170330/shore0008.lzma
2013-03-13T17:51:52.987Z,1363197112.987 [NAL9602](INFO): Packets left to send: 0
2013-03-13T17:51:52.988Z,1363197112.988 [NAL9602](INFO): Stored copy of sent data in Logs/20130313T170330/shore0008.lzma.parts/0000.sbd
2013-03-13T17:52:01.386Z,1363197121.386 [NAL9602](INFO): SBD MO Status=0, MOMSN=7133, MT Status=0, MTMSN=0
2013-03-13T17:52:01.487Z,1363197121.487 [Default:Iridium:Read_Iridium] Stopped
2013-03-13T17:52:01.487Z,1363197121.487 [Default:Iridium](INFO): Completed Default:Iridium
2013-03-13T17:52:01.487Z,1363197121.487 [Default:Iridium] Stopped
2013-03-13T17:52:01.488Z,1363197121.488 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-03-13T17:52:01.488Z,1363197121.488 [Default:Iridium:A.SetSpeed] Stopped
2013-03-13T17:52:01.488Z,1363197121.488 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T17:52:01.776Z,1363197121.776 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-03-13T17:52:01.776Z,1363197121.776 [Default:CallIridium:B] Stopped
2013-03-13T17:52:01.776Z,1363197121.776 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-03-13T17:52:01.777Z,1363197121.777 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-03-13T17:52:01.777Z,1363197121.777 [Default:CallIridium] Stopped
2013-03-13T17:52:01.777Z,1363197121.777 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-03-13T17:52:02.539Z,1363197122.539 [NAL9602](IMPORTANT): GPS fix at: 1363197112.00
2013-03-13T17:52:02.570Z,1363197122.570 [Default:GPS:Read_GPS] Stopped
2013-03-13T17:52:02.570Z,1363197122.570 [Default:GPS:D] Running Loop=1
2013-03-13T17:52:03.001Z,1363197123.000 [Default:GPS:D] Stopped
2013-03-13T17:52:03.001Z,1363197123.001 [Default:GPS](INFO): Completed Default:GPS
2013-03-13T17:52:03.001Z,1363197123.001 [Default:GPS] Stopped
2013-03-13T17:52:03.001Z,1363197123.001 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-03-13T17:52:03.001Z,1363197123.001 [Default:GPS:A.SetSpeed] Stopped
2013-03-13T17:52:03.001Z,1363197123.001 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T17:52:23.516Z,1363197143.516 [NAL9602](INFO): Powering down
2013-03-13T17:57:03.533Z,1363197423.533 [Default:CallIridium] Running Loop=1
2013-03-13T17:57:03.533Z,1363197423.533 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-03-13T17:57:03.533Z,1363197423.533 [Default:CallIridium:A] Running Loop=1
2013-03-13T17:57:03.533Z,1363197423.533 [Default:CallIridium:A] Stopped
2013-03-13T17:57:03.533Z,1363197423.533 [Default:CallIridium:B] Running Loop=1
2013-03-13T17:57:03.533Z,1363197423.533 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-03-13T17:57:08.529Z,1363197428.529 [Default:Iridium] Running Loop=1
2013-03-13T17:57:08.529Z,1363197428.529 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-03-13T17:57:08.529Z,1363197428.529 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-13T17:57:08.529Z,1363197428.529 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-03-13T17:57:08.529Z,1363197428.529 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-03-13T17:57:08.529Z,1363197428.529 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T17:57:08.530Z,1363197428.530 [Default:Iridium:B.GoToSurface] Stopped
2013-03-13T17:57:08.530Z,1363197428.530 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T17:57:08.530Z,1363197428.530 [Default:Iridium:Read_Iridium] Running Loop=1
2013-03-13T17:57:08.531Z,1363197428.531 [Default:GPS] Running Loop=1
2013-03-13T17:57:08.531Z,1363197428.531 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-03-13T17:57:08.531Z,1363197428.531 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-13T17:57:08.531Z,1363197428.531 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-03-13T17:57:08.531Z,1363197428.531 [Default:GPS:B.GoToSurface] Running Loop=1
2013-03-13T17:57:08.531Z,1363197428.531 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T17:57:08.532Z,1363197428.532 [Default:GPS:B.GoToSurface] Stopped
2013-03-13T17:57:08.532Z,1363197428.532 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T17:57:08.532Z,1363197428.532 [Default:GPS:Read_GPS] Running Loop=1
2013-03-13T17:57:09.144Z,1363197429.144 [NAL9602](INFO): Powering up
2013-03-13T17:57:20.187Z,1363197440.187 [NAL9602](INFO): NAL9602 initialized
2013-03-13T17:57:57.337Z,1363197477.337 [NAL9602](INFO): SBD MO Status=2, MOMSN=7134, MT Status=2, MTMSN=0
2013-03-13T17:57:57.337Z,1363197477.337 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-03-13T17:57:58.579Z,1363197478.579 [NAL9602](IMPORTANT): GPS fix at: 1363197468.00
2013-03-13T17:57:58.596Z,1363197478.596 [Default:GPS:Read_GPS] Stopped
2013-03-13T17:57:58.596Z,1363197478.596 [Default:GPS:D] Running Loop=1
2013-03-13T17:57:58.967Z,1363197478.967 [Default:GPS:D] Stopped
2013-03-13T17:57:58.968Z,1363197478.968 [Default:GPS](INFO): Completed Default:GPS
2013-03-13T17:57:58.968Z,1363197478.968 [Default:GPS] Stopped
2013-03-13T17:57:58.968Z,1363197478.968 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-03-13T17:57:58.968Z,1363197478.968 [Default:GPS:A.SetSpeed] Stopped
2013-03-13T17:57:58.968Z,1363197478.968 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T17:58:17.152Z,1363197497.152 [NAL9602](INFO): SBD MO Status=1, MOMSN=7134, MT Status=0, MTMSN=0
2013-03-13T17:58:17.203Z,1363197497.203 [NAL9602](INFO): Sent 152 bytes from file Logs/20130313T170330/shore0009.lzma
2013-03-13T17:58:17.203Z,1363197497.203 [NAL9602](INFO): Packets left to send: 0
2013-03-13T17:58:17.204Z,1363197497.204 [NAL9602](INFO): Stored copy of sent data in Logs/20130313T170330/shore0009.lzma.parts/0000.sbd
2013-03-13T17:58:25.956Z,1363197505.956 [NAL9602](INFO): SBD MO Status=0, MOMSN=7135, MT Status=0, MTMSN=0
2013-03-13T17:58:26.037Z,1363197506.037 [Default:Iridium:Read_Iridium] Stopped
2013-03-13T17:58:26.037Z,1363197506.037 [Default:Iridium](INFO): Completed Default:Iridium
2013-03-13T17:58:26.038Z,1363197506.037 [Default:Iridium] Stopped
2013-03-13T17:58:26.038Z,1363197506.038 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-03-13T17:58:26.038Z,1363197506.038 [Default:Iridium:A.SetSpeed] Stopped
2013-03-13T17:58:26.038Z,1363197506.038 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T17:58:26.370Z,1363197506.370 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-03-13T17:58:26.370Z,1363197506.370 [Default:CallIridium:B] Stopped
2013-03-13T17:58:26.370Z,1363197506.370 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-03-13T17:58:26.371Z,1363197506.371 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-03-13T17:58:26.371Z,1363197506.371 [Default:CallIridium] Stopped
2013-03-13T17:58:26.371Z,1363197506.371 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-03-13T17:58:36.516Z,1363197516.516 [NAL9602](INFO): Powering down
2013-03-13T18:03:26.571Z,1363197806.571 [Default:CallIridium] Running Loop=1
2013-03-13T18:03:26.572Z,1363197806.572 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-03-13T18:03:26.572Z,1363197806.572 [Default:CallIridium:A] Running Loop=1
2013-03-13T18:03:26.572Z,1363197806.572 [Default:CallIridium:A] Stopped
2013-03-13T18:03:26.572Z,1363197806.572 [Default:CallIridium:B] Running Loop=1
2013-03-13T18:03:26.572Z,1363197806.572 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-03-13T18:03:31.525Z,1363197811.525 [Default:Iridium] Running Loop=1
2013-03-13T18:03:31.525Z,1363197811.525 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-03-13T18:03:31.525Z,1363197811.525 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-13T18:03:31.525Z,1363197811.525 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-03-13T18:03:31.525Z,1363197811.525 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-03-13T18:03:31.525Z,1363197811.525 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T18:03:31.526Z,1363197811.526 [Default:Iridium:B.GoToSurface] Stopped
2013-03-13T18:03:31.526Z,1363197811.526 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T18:03:31.526Z,1363197811.526 [Default:Iridium:Read_Iridium] Running Loop=1
2013-03-13T18:03:31.527Z,1363197811.527 [Default:GPS] Running Loop=1
2013-03-13T18:03:31.527Z,1363197811.527 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-03-13T18:03:31.527Z,1363197811.527 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-13T18:03:31.527Z,1363197811.527 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-03-13T18:03:31.527Z,1363197811.527 [Default:GPS:B.GoToSurface] Running Loop=1
2013-03-13T18:03:31.527Z,1363197811.527 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T18:03:31.528Z,1363197811.528 [Default:GPS:B.GoToSurface] Stopped
2013-03-13T18:03:31.528Z,1363197811.528 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T18:03:31.528Z,1363197811.528 [Default:GPS:Read_GPS] Running Loop=1
2013-03-13T18:03:32.154Z,1363197812.154 [NAL9602](INFO): Powering up
2013-03-13T18:03:42.687Z,1363197822.687 [NAL9602](INFO): NAL9602 initialized
2013-03-13T18:04:00.834Z,1363197840.834 [NAL9602](INFO): SBD MO Status=1, MOMSN=7136, MT Status=0, MTMSN=0
2013-03-13T18:04:00.887Z,1363197840.887 [NAL9602](INFO): Sent 153 bytes from file Logs/20130313T170330/shore0010.lzma
2013-03-13T18:04:00.887Z,1363197840.887 [NAL9602](INFO): Packets left to send: 0
2013-03-13T18:04:00.888Z,1363197840.888 [NAL9602](INFO): Stored copy of sent data in Logs/20130313T170330/shore0010.lzma.parts/0000.sbd
2013-03-13T18:04:11.584Z,1363197851.584 [NAL9602](INFO): SBD MO Status=0, MOMSN=7137, MT Status=0, MTMSN=0
2013-03-13T18:04:11.680Z,1363197851.680 [Default:Iridium:Read_Iridium] Stopped
2013-03-13T18:04:11.681Z,1363197851.681 [Default:Iridium](INFO): Completed Default:Iridium
2013-03-13T18:04:11.681Z,1363197851.681 [Default:Iridium] Stopped
2013-03-13T18:04:11.681Z,1363197851.681 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-03-13T18:04:11.681Z,1363197851.681 [Default:Iridium:A.SetSpeed] Stopped
2013-03-13T18:04:11.681Z,1363197851.681 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T18:04:11.995Z,1363197851.995 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-03-13T18:04:11.995Z,1363197851.995 [Default:CallIridium:B] Stopped
2013-03-13T18:04:11.995Z,1363197851.995 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-03-13T18:04:11.995Z,1363197851.995 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-03-13T18:04:11.995Z,1363197851.995 [Default:CallIridium] Stopped
2013-03-13T18:04:11.996Z,1363197851.996 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-03-13T18:04:12.819Z,1363197852.819 [NAL9602](IMPORTANT): GPS fix at: 1363197843.00
2013-03-13T18:04:12.836Z,1363197852.836 [Default:GPS:Read_GPS] Stopped
2013-03-13T18:04:12.836Z,1363197852.836 [Default:GPS:D] Running Loop=1
2013-03-13T18:04:13.211Z,1363197853.211 [Default:GPS:D] Stopped
2013-03-13T18:04:13.212Z,1363197853.211 [Default:GPS](INFO): Completed Default:GPS
2013-03-13T18:04:13.212Z,1363197853.212 [Default:GPS] Stopped
2013-03-13T18:04:13.212Z,1363197853.212 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-03-13T18:04:13.212Z,1363197853.212 [Default:GPS:A.SetSpeed] Stopped
2013-03-13T18:04:13.212Z,1363197853.212 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T18:04:18.764Z,1363197858.764 [Depth_Keller](ERROR): Pressure reading out of range: 1830.600708 decibar
2013-03-13T18:04:33.747Z,1363197873.747 [NAL9602](INFO): Powering down
2013-03-13T18:04:48.783Z,1363197888.783 [Depth_Keller](ERROR): Pressure reading out of range: 1830.637451 decibar
2013-03-13T18:04:58.784Z,1363197898.784 [Depth_Keller](ERROR): Pressure reading out of range: 1830.642578 decibar
2013-03-13T18:05:48.784Z,1363197948.784 [Depth_Keller](ERROR): Pressure reading out of range: 1830.619873 decibar
2013-03-13T18:05:58.792Z,1363197958.792 [Depth_Keller](ERROR): Pressure reading out of range: 1830.598022 decibar
2013-03-13T18:07:18.748Z,1363198038.747 [Depth_Keller](ERROR): Pressure reading out of range: 1830.630493 decibar
2013-03-13T18:07:28.776Z,1363198048.776 [Depth_Keller](ERROR): Pressure reading out of range: 1830.628662 decibar
2013-03-13T18:07:38.776Z,1363198058.776 [Depth_Keller](ERROR): Pressure reading out of range: 1830.612061 decibar
2013-03-13T18:07:48.780Z,1363198068.780 [Depth_Keller](ERROR): Pressure reading out of range: 1830.589478 decibar
2013-03-13T18:07:58.780Z,1363198078.780 [Depth_Keller](ERROR): Pressure reading out of range: 1830.600708 decibar
2013-03-13T18:08:08.788Z,1363198088.788 [Depth_Keller](ERROR): Pressure reading out of range: 1830.619141 decibar
2013-03-13T18:08:18.784Z,1363198098.784 [Depth_Keller](ERROR): Pressure reading out of range: 1830.637451 decibar
2013-03-13T18:08:28.759Z,1363198108.759 [Depth_Keller](ERROR): Pressure reading out of range: 1830.616333 decibar
2013-03-13T18:08:48.748Z,1363198128.748 [Depth_Keller](ERROR): Pressure reading out of range: 1830.638306 decibar
2013-03-13T18:09:08.740Z,1363198148.740 [Depth_Keller](ERROR): Pressure reading out of range: -850.302734 decibar
2013-03-13T18:09:13.789Z,1363198153.789 [Default:CallIridium] Running Loop=1
2013-03-13T18:09:13.789Z,1363198153.789 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-03-13T18:09:13.789Z,1363198153.789 [Default:CallIridium:A] Running Loop=1
2013-03-13T18:09:13.790Z,1363198153.790 [Default:CallIridium:A] Stopped
2013-03-13T18:09:13.790Z,1363198153.790 [Default:CallIridium:B] Running Loop=1
2013-03-13T18:09:13.790Z,1363198153.790 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-03-13T18:09:18.740Z,1363198158.740 [Depth_Keller](ERROR): Pressure reading out of range: 1372.908691 decibar
2013-03-13T18:09:18.779Z,1363198158.779 [Default:Iridium] Running Loop=1
2013-03-13T18:09:18.779Z,1363198158.779 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-03-13T18:09:18.779Z,1363198158.779 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-13T18:09:18.779Z,1363198158.779 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-03-13T18:09:18.779Z,1363198158.779 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-03-13T18:09:18.779Z,1363198158.779 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T18:09:18.780Z,1363198158.780 [Default:Iridium:B.GoToSurface] Stopped
2013-03-13T18:09:18.780Z,1363198158.780 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T18:09:18.780Z,1363198158.780 [Default:Iridium:Read_Iridium] Running Loop=1
2013-03-13T18:09:18.780Z,1363198158.780 [Default:GPS] Running Loop=1
2013-03-13T18:09:18.781Z,1363198158.781 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-03-13T18:09:18.781Z,1363198158.781 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-13T18:09:18.781Z,1363198158.781 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-03-13T18:09:18.781Z,1363198158.781 [Default:GPS:B.GoToSurface] Running Loop=1
2013-03-13T18:09:18.781Z,1363198158.781 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T18:09:18.782Z,1363198158.782 [Default:GPS:B.GoToSurface] Stopped
2013-03-13T18:09:18.782Z,1363198158.782 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T18:09:18.782Z,1363198158.782 [Default:GPS:Read_GPS] Running Loop=1
2013-03-13T18:09:19.384Z,1363198159.384 [NAL9602](INFO): Powering up
2013-03-13T18:09:30.303Z,1363198170.303 [NAL9602](INFO): NAL9602 initialized
2013-03-13T18:09:48.009Z,1363198188.009 [NAL9602](INFO): SBD MO Status=1, MOMSN=7138, MT Status=0, MTMSN=0
2013-03-13T18:09:48.059Z,1363198188.059 [NAL9602](INFO): Sent 141 bytes from file Logs/20130313T170330/shore0011.lzma
2013-03-13T18:09:48.059Z,1363198188.059 [NAL9602](INFO): Packets left to send: 0
2013-03-13T18:09:48.060Z,1363198188.060 [NAL9602](INFO): Stored copy of sent data in Logs/20130313T170330/shore0011.lzma.parts/0000.sbd
2013-03-13T18:10:00.412Z,1363198200.411 [NAL9602](INFO): SBD MO Status=0, MOMSN=7139, MT Status=0, MTMSN=0
2013-03-13T18:10:00.488Z,1363198200.488 [Default:Iridium:Read_Iridium] Stopped
2013-03-13T18:10:00.488Z,1363198200.488 [Default:Iridium](INFO): Completed Default:Iridium
2013-03-13T18:10:00.488Z,1363198200.488 [Default:Iridium] Stopped
2013-03-13T18:10:00.488Z,1363198200.488 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-03-13T18:10:00.488Z,1363198200.489 [Default:Iridium:A.SetSpeed] Stopped
2013-03-13T18:10:00.489Z,1363198200.489 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T18:10:00.819Z,1363198200.819 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-03-13T18:10:00.819Z,1363198200.819 [Default:CallIridium:B] Stopped
2013-03-13T18:10:00.819Z,1363198200.819 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-03-13T18:10:00.819Z,1363198200.819 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-03-13T18:10:00.820Z,1363198200.819 [Default:CallIridium] Stopped
2013-03-13T18:10:00.820Z,1363198200.820 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-03-13T18:10:01.610Z,1363198201.611 [NAL9602](IMPORTANT): GPS fix at: 1363198192.00
2013-03-13T18:10:01.627Z,1363198201.627 [Default:GPS:Read_GPS] Stopped
2013-03-13T18:10:01.627Z,1363198201.627 [Default:GPS:D] Running Loop=1
2013-03-13T18:10:02.041Z,1363198202.040 [Default:GPS:D] Stopped
2013-03-13T18:10:02.041Z,1363198202.041 [Default:GPS](INFO): Completed Default:GPS
2013-03-13T18:10:02.041Z,1363198202.041 [Default:GPS] Stopped
2013-03-13T18:10:02.041Z,1363198202.041 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-03-13T18:10:02.041Z,1363198202.041 [Default:GPS:A.SetSpeed] Stopped
2013-03-13T18:10:02.041Z,1363198202.041 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T18:10:17.563Z,1363198217.563 [Depth_Keller](ERROR): Pressure reading out of range: 1830.619873 decibar
2013-03-13T18:10:22.601Z,1363198222.601 [NAL9602](INFO): Powering down
2013-03-13T18:10:27.564Z,1363198227.564 [Depth_Keller](ERROR): Pressure reading out of range: 1830.647827 decibar
2013-03-13T18:10:37.587Z,1363198237.587 [Depth_Keller](ERROR): Pressure reading out of range: 1830.633911 decibar
2013-03-13T18:10:47.592Z,1363198247.592 [Depth_Keller](ERROR): Pressure reading out of range: 1830.619873 decibar
2013-03-13T18:10:57.596Z,1363198257.596 [Depth_Keller](ERROR): Pressure reading out of range: 1830.619873 decibar
2013-03-13T18:11:07.588Z,1363198267.588 [Depth_Keller](ERROR): Pressure reading out of range: 1830.613892 decibar
2013-03-13T18:11:27.592Z,1363198287.592 [Depth_Keller](ERROR): Pressure reading out of range: 1830.626953 decibar
2013-03-13T18:11:47.564Z,1363198307.564 [Depth_Keller](ERROR): Pressure reading out of range: 1830.611084 decibar
2013-03-13T18:12:07.563Z,1363198327.563 [Depth_Keller](ERROR): Pressure reading out of range: 1830.598022 decibar
2013-03-13T18:12:17.563Z,1363198337.563 [Depth_Keller](ERROR): Pressure reading out of range: 1830.614624 decibar
2013-03-13T18:12:27.580Z,1363198347.579 [Depth_Keller](ERROR): Pressure reading out of range: 1830.618164 decibar
2013-03-13T18:13:27.560Z,1363198407.560 [Depth_Keller](ERROR): Pressure reading out of range: 1830.625977 decibar
2013-03-13T18:13:37.563Z,1363198417.563 [Depth_Keller](ERROR): Pressure reading out of range: 1830.617310 decibar
2013-03-13T18:13:47.564Z,1363198427.564 [Depth_Keller](ERROR): Pressure reading out of range: 1830.619873 decibar
2013-03-13T18:14:07.583Z,1363198447.583 [Depth_Keller](ERROR): Pressure reading out of range: 1830.585938 decibar
2013-03-13T18:15:02.581Z,1363198502.581 [Default:CallIridium] Running Loop=1
2013-03-13T18:15:02.581Z,1363198502.581 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-03-13T18:15:02.581Z,1363198502.581 [Default:CallIridium:A] Running Loop=1
2013-03-13T18:15:02.581Z,1363198502.582 [Default:CallIridium:A] Stopped
2013-03-13T18:15:02.582Z,1363198502.582 [Default:CallIridium:B] Running Loop=1
2013-03-13T18:15:02.582Z,1363198502.582 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-03-13T18:15:07.604Z,1363198507.604 [Default:Iridium] Running Loop=1
2013-03-13T18:15:07.605Z,1363198507.605 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-03-13T18:15:07.605Z,1363198507.605 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-13T18:15:07.605Z,1363198507.605 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-03-13T18:15:07.605Z,1363198507.605 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-03-13T18:15:07.605Z,1363198507.605 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T18:15:07.606Z,1363198507.606 [Default:Iridium:B.GoToSurface] Stopped
2013-03-13T18:15:07.606Z,1363198507.606 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T18:15:07.606Z,1363198507.606 [Default:Iridium:Read_Iridium] Running Loop=1
2013-03-13T18:15:07.606Z,1363198507.606 [Default:GPS] Running Loop=1
2013-03-13T18:15:07.607Z,1363198507.606 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-03-13T18:15:07.607Z,1363198507.607 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-13T18:15:07.607Z,1363198507.607 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-03-13T18:15:07.607Z,1363198507.607 [Default:GPS:B.GoToSurface] Running Loop=1
2013-03-13T18:15:07.607Z,1363198507.607 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T18:15:07.608Z,1363198507.608 [Default:GPS:B.GoToSurface] Stopped
2013-03-13T18:15:07.608Z,1363198507.608 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T18:15:07.608Z,1363198507.608 [Default:GPS:Read_GPS] Running Loop=1
2013-03-13T18:15:08.207Z,1363198508.207 [NAL9602](INFO): Powering up
2013-03-13T18:15:19.151Z,1363198519.151 [NAL9602](INFO): NAL9602 initialized
2013-03-13T18:15:48.804Z,1363198548.804 [NAL9602](INFO): SBD MO Status=2, MOMSN=7140, MT Status=2, MTMSN=0
2013-03-13T18:15:48.804Z,1363198548.804 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-03-13T18:15:50.064Z,1363198550.064 [NAL9602](IMPORTANT): GPS fix at: 1363198541.00
2013-03-13T18:15:50.084Z,1363198550.084 [Default:GPS:Read_GPS] Stopped
2013-03-13T18:15:50.084Z,1363198550.084 [Default:GPS:D] Running Loop=1
2013-03-13T18:15:50.445Z,1363198550.445 [Default:GPS:D] Stopped
2013-03-13T18:15:50.445Z,1363198550.445 [Default:GPS](INFO): Completed Default:GPS
2013-03-13T18:15:50.445Z,1363198550.445 [Default:GPS] Stopped
2013-03-13T18:15:50.445Z,1363198550.445 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-03-13T18:15:50.445Z,1363198550.445 [Default:GPS:A.SetSpeed] Stopped
2013-03-13T18:15:50.445Z,1363198550.445 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T18:16:13.297Z,1363198573.297 [NAL9602](INFO): SBD MO Status=1, MOMSN=7140, MT Status=0, MTMSN=0
2013-03-13T18:16:13.347Z,1363198573.347 [NAL9602](INFO): Sent 135 bytes from file Logs/20130313T170330/shore0012.lzma
2013-03-13T18:16:13.347Z,1363198573.347 [NAL9602](INFO): Packets left to send: 0
2013-03-13T18:16:13.348Z,1363198573.348 [NAL9602](INFO): Stored copy of sent data in Logs/20130313T170330/shore0012.lzma.parts/0000.sbd
2013-03-13T18:16:23.693Z,1363198583.693 [NAL9602](INFO): SBD MO Status=0, MOMSN=7141, MT Status=0, MTMSN=0
2013-03-13T18:16:23.785Z,1363198583.785 [Default:Iridium:Read_Iridium] Stopped
2013-03-13T18:16:23.786Z,1363198583.786 [Default:Iridium](INFO): Completed Default:Iridium
2013-03-13T18:16:23.786Z,1363198583.786 [Default:Iridium] Stopped
2013-03-13T18:16:23.786Z,1363198583.786 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-03-13T18:16:23.786Z,1363198583.786 [Default:Iridium:A.SetSpeed] Stopped
2013-03-13T18:16:23.786Z,1363198583.786 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T18:16:24.166Z,1363198584.166 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-03-13T18:16:24.166Z,1363198584.166 [Default:CallIridium:B] Stopped
2013-03-13T18:16:24.166Z,1363198584.166 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-03-13T18:16:24.167Z,1363198584.167 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-03-13T18:16:24.167Z,1363198584.167 [Default:CallIridium] Stopped
2013-03-13T18:16:24.167Z,1363198584.167 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-03-13T18:16:34.264Z,1363198594.264 [NAL9602](INFO): Powering down
2013-03-13T18:17:19.262Z,1363198639.262 [Depth_Keller](ERROR): Pressure reading out of range: 1355.026123 decibar
2013-03-13T18:18:49.284Z,1363198729.284 [Depth_Keller](ERROR): Pressure reading out of range: 1830.586670 decibar
2013-03-13T18:18:59.264Z,1363198739.264 [Depth_Keller](ERROR): Pressure reading out of range: 1830.604248 decibar
2013-03-13T18:19:19.276Z,1363198759.276 [Depth_Keller](ERROR): Pressure reading out of range: 1830.643555 decibar
2013-03-13T18:19:29.311Z,1363198769.311 [Depth_Keller](ERROR): Pressure reading out of range: 1830.637451 decibar
2013-03-13T18:19:49.241Z,1363198789.241 [Radio_Freewave](INFO): Powering down
2013-03-13T18:19:54.263Z,1363198794.263 [Depth_Keller](ERROR): Pressure reading out of range: 1830.639038 decibar
2013-03-13T18:21:24.292Z,1363198884.293 [Default:CallIridium] Running Loop=1
2013-03-13T18:21:24.293Z,1363198884.293 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-03-13T18:21:24.293Z,1363198884.293 [Default:CallIridium:A] Running Loop=1
2013-03-13T18:21:24.293Z,1363198884.293 [Default:CallIridium:A] Stopped
2013-03-13T18:21:24.293Z,1363198884.293 [Default:CallIridium:B] Running Loop=1
2013-03-13T18:21:24.293Z,1363198884.293 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-03-13T18:21:29.278Z,1363198889.278 [Default:Iridium] Running Loop=1
2013-03-13T18:21:29.278Z,1363198889.278 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-03-13T18:21:29.278Z,1363198889.278 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-13T18:21:29.278Z,1363198889.278 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-03-13T18:21:29.278Z,1363198889.278 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-03-13T18:21:29.278Z,1363198889.278 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T18:21:29.279Z,1363198889.279 [Default:GPS] Running Loop=1
2013-03-13T18:21:29.280Z,1363198889.280 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-03-13T18:21:29.280Z,1363198889.280 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-13T18:21:29.280Z,1363198889.280 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-03-13T18:21:29.280Z,1363198889.280 [Default:GPS:B.GoToSurface] Running Loop=1
2013-03-13T18:21:29.280Z,1363198889.280 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T18:21:29.525Z,1363198889.525 [Radio_Freewave](INFO): Powering up
2013-03-13T18:21:29.539Z,1363198889.539 [Default:Iridium:B.GoToSurface] Stopped
2013-03-13T18:21:29.539Z,1363198889.539 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T18:21:29.539Z,1363198889.539 [Default:Iridium:Read_Iridium] Running Loop=1
2013-03-13T18:21:29.540Z,1363198889.540 [Default:GPS:B.GoToSurface] Stopped
2013-03-13T18:21:29.540Z,1363198889.540 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T18:21:29.540Z,1363198889.540 [Default:GPS:Read_GPS] Running Loop=1
2013-03-13T18:21:30.304Z,1363198890.304 [NAL9602](INFO): Powering up
2013-03-13T18:21:41.031Z,1363198901.031 [NAL9602](INFO): NAL9602 initialized
2013-03-13T18:22:03.577Z,1363198923.577 [NAL9602](INFO): SBD MO Status=1, MOMSN=7142, MT Status=0, MTMSN=0
2013-03-13T18:22:03.627Z,1363198923.627 [NAL9602](INFO): Sent 184 bytes from file Logs/20130313T170330/shore0013.lzma
2013-03-13T18:22:03.627Z,1363198923.627 [NAL9602](INFO): Packets left to send: 0
2013-03-13T18:22:03.628Z,1363198923.628 [NAL9602](INFO): Stored copy of sent data in Logs/20130313T170330/shore0013.lzma.parts/0000.sbd
2013-03-13T18:22:15.168Z,1363198935.168 [NAL9602](INFO): SBD MO Status=0, MOMSN=7143, MT Status=0, MTMSN=0
2013-03-13T18:22:15.266Z,1363198935.266 [Default:Iridium:Read_Iridium] Stopped
2013-03-13T18:22:15.267Z,1363198935.267 [Default:Iridium](INFO): Completed Default:Iridium
2013-03-13T18:22:15.267Z,1363198935.267 [Default:Iridium] Stopped
2013-03-13T18:22:15.267Z,1363198935.267 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-03-13T18:22:15.267Z,1363198935.267 [Default:Iridium:A.SetSpeed] Stopped
2013-03-13T18:22:15.267Z,1363198935.267 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T18:22:15.596Z,1363198935.596 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-03-13T18:22:15.596Z,1363198935.596 [Default:CallIridium:B] Stopped
2013-03-13T18:22:15.596Z,1363198935.596 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-03-13T18:22:15.596Z,1363198935.596 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-03-13T18:22:15.597Z,1363198935.597 [Default:CallIridium] Stopped
2013-03-13T18:22:15.597Z,1363198935.597 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-03-13T18:22:16.383Z,1363198936.383 [NAL9602](IMPORTANT): GPS fix at: 1363198928.00
2013-03-13T18:22:16.400Z,1363198936.400 [Default:GPS:Read_GPS] Stopped
2013-03-13T18:22:16.400Z,1363198936.400 [Default:GPS:D] Running Loop=1
2013-03-13T18:22:16.813Z,1363198936.813 [Default:GPS:D] Stopped
2013-03-13T18:22:16.813Z,1363198936.813 [Default:GPS](INFO): Completed Default:GPS
2013-03-13T18:22:16.813Z,1363198936.813 [Default:GPS] Stopped
2013-03-13T18:22:16.813Z,1363198936.813 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-03-13T18:22:16.813Z,1363198936.813 [Default:GPS:A.SetSpeed] Stopped
2013-03-13T18:22:16.813Z,1363198936.813 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T18:22:27.328Z,1363198947.328 [Depth_Keller](ERROR): Pressure reading out of range: 1355.038330 decibar
2013-03-13T18:22:37.336Z,1363198957.336 [NAL9602](INFO): Powering down
2013-03-13T18:22:47.332Z,1363198967.332 [Depth_Keller](ERROR): Pressure reading out of range: 1830.629517 decibar
2013-03-13T18:22:57.328Z,1363198977.328 [Depth_Keller](ERROR): Pressure reading out of range: 1830.603271 decibar
2013-03-13T18:23:07.344Z,1363198987.344 [Depth_Keller](ERROR): Pressure reading out of range: 1830.625977 decibar
2013-03-13T18:23:17.328Z,1363198997.328 [Depth_Keller](ERROR): Pressure reading out of range: 1830.633911 decibar
2013-03-13T18:23:27.348Z,1363199007.348 [Depth_Keller](ERROR): Pressure reading out of range: 1830.625977 decibar
2013-03-13T18:23:37.384Z,1363199017.384 [Depth_Keller](ERROR): Pressure reading out of range: 1830.653931 decibar
2013-03-13T18:23:47.348Z,1363199027.348 [Depth_Keller](ERROR): Pressure reading out of range: 1830.624146 decibar
2013-03-13T18:23:57.363Z,1363199037.363 [Depth_Keller](ERROR): Pressure reading out of range: 1830.612915 decibar
2013-03-13T18:24:07.348Z,1363199047.348 [Depth_Keller](ERROR): Pressure reading out of range: 1830.642578 decibar
2013-03-13T18:24:17.344Z,1363199057.344 [Depth_Keller](ERROR): Pressure reading out of range: 1830.617310 decibar
2013-03-13T18:24:27.331Z,1363199067.332 [Depth_Keller](ERROR): Pressure reading out of range: 1830.625122 decibar
2013-03-13T18:24:37.328Z,1363199077.328 [Depth_Keller](ERROR): Pressure reading out of range: 1830.617310 decibar
2013-03-13T18:24:47.328Z,1363199087.328 [Depth_Keller](ERROR): Pressure reading out of range: 1830.628662 decibar
2013-03-13T18:24:57.363Z,1363199097.363 [Depth_Keller](ERROR): Pressure reading out of range: 1830.621704 decibar
2013-03-13T18:25:07.332Z,1363199107.332 [Depth_Keller](ERROR): Pressure reading out of range: 1830.625977 decibar
2013-03-13T18:25:17.362Z,1363199117.362 [Depth_Keller](ERROR): Pressure reading out of range: 1830.606079 decibar
2013-03-13T18:25:27.362Z,1363199127.362 [Depth_Keller](ERROR): Pressure reading out of range: 1830.612915 decibar
2013-03-13T18:25:37.348Z,1363199137.348 [Depth_Keller](ERROR): Pressure reading out of range: 1830.644287 decibar
2013-03-13T18:25:57.335Z,1363199157.335 [Depth_Keller](ERROR): Pressure reading out of range: 1830.625122 decibar
2013-03-13T18:26:07.319Z,1363199167.319 [Depth_Keller](ERROR): Pressure reading out of range: 1830.616333 decibar
2013-03-13T18:26:17.348Z,1363199177.348 [Depth_Keller](ERROR): Pressure reading out of range: 1830.630493 decibar
2013-03-13T18:26:27.328Z,1363199187.328 [Depth_Keller](ERROR): Pressure reading out of range: 1830.618164 decibar
2013-03-13T18:26:37.332Z,1363199197.332 [Depth_Keller](ERROR): Pressure reading out of range: 1830.632935 decibar
2013-03-13T18:26:47.335Z,1363199207.335 [Depth_Keller](ERROR): Pressure reading out of range: 1830.603271 decibar
2013-03-13T18:26:57.348Z,1363199217.348 [Depth_Keller](ERROR): Pressure reading out of range: 1830.628662 decibar
2013-03-13T18:27:07.364Z,1363199227.364 [Depth_Keller](ERROR): Pressure reading out of range: 1830.593750 decibar
2013-03-13T18:27:17.348Z,1363199237.348 [Depth_Keller](ERROR): Pressure reading out of range: 1830.640015 decibar
2013-03-13T18:27:17.381Z,1363199237.381 [Default:CallIridium] Running Loop=1
2013-03-13T18:27:17.382Z,1363199237.382 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-03-13T18:27:17.382Z,1363199237.382 [Default:CallIridium:A] Running Loop=1
2013-03-13T18:27:17.382Z,1363199237.382 [Default:CallIridium:A] Stopped
2013-03-13T18:27:17.382Z,1363199237.382 [Default:CallIridium:B] Running Loop=1
2013-03-13T18:27:17.382Z,1363199237.382 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-03-13T18:27:22.345Z,1363199242.345 [Default:Iridium] Running Loop=1
2013-03-13T18:27:22.345Z,1363199242.345 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-03-13T18:27:22.345Z,1363199242.345 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-13T18:27:22.345Z,1363199242.345 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-03-13T18:27:22.345Z,1363199242.345 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-03-13T18:27:22.345Z,1363199242.345 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T18:27:22.346Z,1363199242.346 [Default:Iridium:B.GoToSurface] Stopped
2013-03-13T18:27:22.347Z,1363199242.346 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T18:27:22.347Z,1363199242.347 [Default:Iridium:Read_Iridium] Running Loop=1
2013-03-13T18:27:22.347Z,1363199242.347 [Default:GPS] Running Loop=1
2013-03-13T18:27:22.347Z,1363199242.347 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-03-13T18:27:22.347Z,1363199242.347 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-13T18:27:22.347Z,1363199242.347 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-03-13T18:27:22.347Z,1363199242.348 [Default:GPS:B.GoToSurface] Running Loop=1
2013-03-13T18:27:22.347Z,1363199242.348 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T18:27:22.348Z,1363199242.348 [Default:GPS:B.GoToSurface] Stopped
2013-03-13T18:27:22.348Z,1363199242.348 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T18:27:22.349Z,1363199242.349 [Default:GPS:Read_GPS] Running Loop=1
2013-03-13T18:27:22.972Z,1363199242.972 [NAL9602](INFO): Powering up
2013-03-13T18:27:33.543Z,1363199253.543 [NAL9602](INFO): NAL9602 initialized
2013-03-13T18:28:00.402Z,1363199280.402 [NAL9602](INFO): SBD MO Status=2, MOMSN=7144, MT Status=2, MTMSN=0
2013-03-13T18:28:00.402Z,1363199280.402 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-03-13T18:28:01.557Z,1363199281.557 [NAL9602](IMPORTANT): GPS fix at: 1363199274.00
2013-03-13T18:28:01.574Z,1363199281.574 [Default:GPS:Read_GPS] Stopped
2013-03-13T18:28:01.575Z,1363199281.575 [Default:GPS:D] Running Loop=1
2013-03-13T18:28:01.988Z,1363199281.989 [Default:GPS:D] Stopped
2013-03-13T18:28:01.989Z,1363199281.989 [Default:GPS](INFO): Completed Default:GPS
2013-03-13T18:28:01.989Z,1363199281.989 [Default:GPS] Stopped
2013-03-13T18:28:01.989Z,1363199281.989 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-03-13T18:28:01.989Z,1363199281.989 [Default:GPS:A.SetSpeed] Stopped
2013-03-13T18:28:01.989Z,1363199281.989 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T18:28:25.129Z,1363199305.129 [NAL9602](INFO): SBD MO Status=1, MOMSN=7144, MT Status=0, MTMSN=0
2013-03-13T18:28:25.183Z,1363199305.183 [NAL9602](INFO): Sent 153 bytes from file Logs/20130313T170330/shore0014.lzma
2013-03-13T18:28:25.183Z,1363199305.183 [NAL9602](INFO): Packets left to send: 0
2013-03-13T18:28:25.184Z,1363199305.184 [NAL9602](INFO): Stored copy of sent data in Logs/20130313T170330/shore0014.lzma.parts/0000.sbd
2013-03-13T18:28:38.293Z,1363199318.293 [NAL9602](INFO): SBD MO Status=0, MOMSN=7145, MT Status=0, MTMSN=0
2013-03-13T18:28:38.381Z,1363199318.381 [Default:Iridium:Read_Iridium] Stopped
2013-03-13T18:28:38.382Z,1363199318.382 [Default:Iridium](INFO): Completed Default:Iridium
2013-03-13T18:28:38.382Z,1363199318.382 [Default:Iridium] Stopped
2013-03-13T18:28:38.382Z,1363199318.382 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-03-13T18:28:38.382Z,1363199318.382 [Default:Iridium:A.SetSpeed] Stopped
2013-03-13T18:28:38.382Z,1363199318.382 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T18:28:38.712Z,1363199318.712 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-03-13T18:28:38.712Z,1363199318.712 [Default:CallIridium:B] Stopped
2013-03-13T18:28:38.712Z,1363199318.712 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-03-13T18:28:38.712Z,1363199318.713 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-03-13T18:28:38.713Z,1363199318.713 [Default:CallIridium] Stopped
2013-03-13T18:28:38.713Z,1363199318.713 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-03-13T18:28:48.864Z,1363199328.864 [NAL9602](INFO): Powering down
2013-03-13T18:28:53.867Z,1363199333.867 [Depth_Keller](ERROR): Pressure reading out of range: 1830.658325 decibar
2013-03-13T18:29:03.876Z,1363199343.876 [Depth_Keller](ERROR): Pressure reading out of range: 1830.594727 decibar
2013-03-13T18:29:13.864Z,1363199353.864 [Depth_Keller](ERROR): Pressure reading out of range: 1830.649536 decibar
2013-03-13T18:29:23.864Z,1363199363.864 [Depth_Keller](ERROR): Pressure reading out of range: 1830.652344 decibar
2013-03-13T18:29:33.865Z,1363199373.865 [Depth_Keller](ERROR): Pressure reading out of range: 1830.580688 decibar
2013-03-13T18:29:43.864Z,1363199383.864 [Depth_Keller](ERROR): Pressure reading out of range: 1830.634766 decibar
2013-03-13T18:29:53.864Z,1363199393.864 [Depth_Keller](ERROR): Pressure reading out of range: 1830.619873 decibar
2013-03-13T18:30:03.836Z,1363199403.836 [Depth_Keller](ERROR): Pressure reading out of range: 1830.648804 decibar
2013-03-13T18:30:13.844Z,1363199413.844 [Depth_Keller](ERROR): Pressure reading out of range: 1830.612061 decibar
2013-03-13T18:30:23.844Z,1363199423.844 [Depth_Keller](ERROR): Pressure reading out of range: 1830.618164 decibar
2013-03-13T18:30:33.844Z,1363199433.844 [Depth_Keller](ERROR): Pressure reading out of range: 1830.620850 decibar
2013-03-13T18:30:43.847Z,1363199443.847 [Depth_Keller](ERROR): Pressure reading out of range: 1830.630493 decibar
2013-03-13T18:31:03.815Z,1363199463.815 [Depth_Keller](ERROR): Pressure reading out of range: 1830.673950 decibar
2013-03-13T18:31:13.843Z,1363199473.843 [Depth_Keller](ERROR): Pressure reading out of range: 1830.645264 decibar
2013-03-13T18:32:13.844Z,1363199533.844 [Depth_Keller](ERROR): Pressure reading out of range: 1830.619141 decibar
2013-03-13T18:32:23.844Z,1363199543.844 [Depth_Keller](ERROR): Pressure reading out of range: 1830.632202 decibar
2013-03-13T18:33:38.877Z,1363199618.877 [Default:CallIridium] Running Loop=1
2013-03-13T18:33:38.877Z,1363199618.877 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-03-13T18:33:38.877Z,1363199618.877 [Default:CallIridium:A] Running Loop=1
2013-03-13T18:33:38.877Z,1363199618.878 [Default:CallIridium:A] Stopped
2013-03-13T18:33:38.878Z,1363199618.878 [Default:CallIridium:B] Running Loop=1
2013-03-13T18:33:38.878Z,1363199618.878 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-03-13T18:33:43.880Z,1363199623.880 [Default:Iridium] Running Loop=1
2013-03-13T18:33:43.880Z,1363199623.880 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-03-13T18:33:43.880Z,1363199623.880 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-13T18:33:43.880Z,1363199623.880 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-03-13T18:33:43.881Z,1363199623.881 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-03-13T18:33:43.881Z,1363199623.881 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T18:33:43.881Z,1363199623.881 [Default:Iridium:B.GoToSurface] Stopped
2013-03-13T18:33:43.882Z,1363199623.882 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T18:33:43.882Z,1363199623.882 [Default:Iridium:Read_Iridium] Running Loop=1
2013-03-13T18:33:43.882Z,1363199623.882 [Default:GPS] Running Loop=1
2013-03-13T18:33:43.882Z,1363199623.882 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-03-13T18:33:43.882Z,1363199623.882 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-13T18:33:43.882Z,1363199623.882 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-03-13T18:33:43.882Z,1363199623.882 [Default:GPS:B.GoToSurface] Running Loop=1
2013-03-13T18:33:43.882Z,1363199623.882 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T18:33:43.883Z,1363199623.883 [Default:GPS:B.GoToSurface] Stopped
2013-03-13T18:33:43.883Z,1363199623.883 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T18:33:43.883Z,1363199623.884 [Default:GPS:Read_GPS] Running Loop=1
2013-03-13T18:33:44.495Z,1363199624.496 [NAL9602](INFO): Powering up
2013-03-13T18:33:55.435Z,1363199635.435 [NAL9602](INFO): NAL9602 initialized
2013-03-13T18:34:15.493Z,1363199655.493 [NAL9602](INFO): SBD MO Status=2, MOMSN=7146, MT Status=2, MTMSN=0
2013-03-13T18:34:15.493Z,1363199655.493 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-03-13T18:34:16.691Z,1363199656.691 [NAL9602](IMPORTANT): GPS fix at: 1363199649.00
2013-03-13T18:34:16.708Z,1363199656.708 [Default:GPS:Read_GPS] Stopped
2013-03-13T18:34:16.708Z,1363199656.708 [Default:GPS:D] Running Loop=1
2013-03-13T18:34:17.120Z,1363199657.121 [Default:GPS:D] Stopped
2013-03-13T18:34:17.121Z,1363199657.121 [Default:GPS](INFO): Completed Default:GPS
2013-03-13T18:34:17.121Z,1363199657.121 [Default:GPS] Stopped
2013-03-13T18:34:17.121Z,1363199657.121 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-03-13T18:34:17.121Z,1363199657.121 [Default:GPS:A.SetSpeed] Stopped
2013-03-13T18:34:17.121Z,1363199657.121 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T18:35:17.261Z,1363199717.261 [NAL9602](INFO): SBD MO Status=1, MOMSN=7146, MT Status=0, MTMSN=0
2013-03-13T18:35:17.311Z,1363199717.311 [NAL9602](INFO): Sent 148 bytes from file Logs/20130313T170330/shore0015.lzma
2013-03-13T18:35:17.311Z,1363199717.311 [NAL9602](INFO): Packets left to send: 0
2013-03-13T18:35:17.312Z,1363199717.312 [NAL9602](INFO): Stored copy of sent data in Logs/20130313T170330/shore0015.lzma.parts/0000.sbd
2013-03-13T18:35:30.065Z,1363199730.065 [NAL9602](INFO): SBD MO Status=0, MOMSN=7147, MT Status=0, MTMSN=0
2013-03-13T18:35:30.143Z,1363199730.143 [Default:Iridium:Read_Iridium] Stopped
2013-03-13T18:35:30.144Z,1363199730.144 [Default:Iridium](INFO): Completed Default:Iridium
2013-03-13T18:35:30.144Z,1363199730.144 [Default:Iridium] Stopped
2013-03-13T18:35:30.144Z,1363199730.144 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-03-13T18:35:30.144Z,1363199730.144 [Default:Iridium:A.SetSpeed] Stopped
2013-03-13T18:35:30.144Z,1363199730.144 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T18:35:30.480Z,1363199730.480 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-03-13T18:35:30.480Z,1363199730.480 [Default:CallIridium:B] Stopped
2013-03-13T18:35:30.480Z,1363199730.480 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-03-13T18:35:30.481Z,1363199730.480 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-03-13T18:35:30.481Z,1363199730.481 [Default:CallIridium] Stopped
2013-03-13T18:35:30.481Z,1363199730.481 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-03-13T18:35:40.628Z,1363199740.628 [NAL9602](INFO): Powering down
2013-03-13T18:36:45.583Z,1363199805.583 [Depth_Keller](ERROR): Pressure reading out of range: 1830.600708 decibar
2013-03-13T18:40:30.668Z,1363200030.668 [Default:CallIridium] Running Loop=1
2013-03-13T18:40:30.668Z,1363200030.668 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-03-13T18:40:30.669Z,1363200030.669 [Default:CallIridium:A] Running Loop=1
2013-03-13T18:40:30.669Z,1363200030.669 [Default:CallIridium:A] Stopped
2013-03-13T18:40:30.669Z,1363200030.669 [Default:CallIridium:B] Running Loop=1
2013-03-13T18:40:30.669Z,1363200030.669 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-03-13T18:40:35.624Z,1363200035.624 [Default:Iridium] Running Loop=1
2013-03-13T18:40:35.624Z,1363200035.624 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-03-13T18:40:35.624Z,1363200035.624 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-13T18:40:35.624Z,1363200035.624 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-03-13T18:40:35.624Z,1363200035.624 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-03-13T18:40:35.624Z,1363200035.625 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T18:40:35.625Z,1363200035.625 [Default:Iridium:B.GoToSurface] Stopped
2013-03-13T18:40:35.625Z,1363200035.625 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T18:40:35.626Z,1363200035.625 [Default:Iridium:Read_Iridium] Running Loop=1
2013-03-13T18:40:35.626Z,1363200035.626 [Default:GPS] Running Loop=1
2013-03-13T18:40:35.626Z,1363200035.626 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-03-13T18:40:35.626Z,1363200035.626 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-13T18:40:35.626Z,1363200035.626 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-03-13T18:40:35.626Z,1363200035.626 [Default:GPS:B.GoToSurface] Running Loop=1
2013-03-13T18:40:35.626Z,1363200035.626 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T18:40:35.627Z,1363200035.627 [Default:GPS:B.GoToSurface] Stopped
2013-03-13T18:40:35.627Z,1363200035.627 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T18:40:35.627Z,1363200035.627 [Default:GPS:Read_GPS] Running Loop=1
2013-03-13T18:40:36.257Z,1363200036.257 [NAL9602](INFO): Powering up
2013-03-13T18:40:47.315Z,1363200047.315 [NAL9602](INFO): NAL9602 initialized
2013-03-13T18:41:02.213Z,1363200062.213 [NAL9602](INFO): SBD MO Status=1, MOMSN=7148, MT Status=0, MTMSN=0
2013-03-13T18:41:02.263Z,1363200062.263 [NAL9602](INFO): Sent 143 bytes from file Logs/20130313T170330/shore0016.lzma
2013-03-13T18:41:02.263Z,1363200062.263 [NAL9602](INFO): Packets left to send: 0
2013-03-13T18:41:02.264Z,1363200062.264 [NAL9602](INFO): Stored copy of sent data in Logs/20130313T170330/shore0016.lzma.parts/0000.sbd
2013-03-13T18:41:06.649Z,1363200066.649 [NAL9602](INFO): SBD MO Status=0, MOMSN=7149, MT Status=0, MTMSN=0
2013-03-13T18:41:06.733Z,1363200066.733 [Default:Iridium:Read_Iridium] Stopped
2013-03-13T18:41:06.733Z,1363200066.733 [Default:Iridium](INFO): Completed Default:Iridium
2013-03-13T18:41:06.734Z,1363200066.734 [Default:Iridium] Stopped
2013-03-13T18:41:06.734Z,1363200066.734 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-03-13T18:41:06.734Z,1363200066.734 [Default:Iridium:A.SetSpeed] Stopped
2013-03-13T18:41:06.734Z,1363200066.734 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T18:41:07.027Z,1363200067.027 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-03-13T18:41:07.028Z,1363200067.028 [Default:CallIridium:B] Stopped
2013-03-13T18:41:07.028Z,1363200067.028 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-03-13T18:41:07.028Z,1363200067.028 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-03-13T18:41:07.028Z,1363200067.028 [Default:CallIridium] Stopped
2013-03-13T18:41:07.028Z,1363200067.028 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-03-13T18:41:07.815Z,1363200067.815 [NAL9602](IMPORTANT): GPS fix at: 1363200061.99
2013-03-13T18:41:07.832Z,1363200067.832 [Default:GPS:Read_GPS] Stopped
2013-03-13T18:41:07.832Z,1363200067.832 [Default:GPS:D] Running Loop=1
2013-03-13T18:41:08.239Z,1363200068.239 [Default:GPS:D] Stopped
2013-03-13T18:41:08.239Z,1363200068.239 [Default:GPS](INFO): Completed Default:GPS
2013-03-13T18:41:08.239Z,1363200068.239 [Default:GPS] Stopped
2013-03-13T18:41:08.240Z,1363200068.240 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-03-13T18:41:08.240Z,1363200068.240 [Default:GPS:A.SetSpeed] Stopped
2013-03-13T18:41:08.240Z,1363200068.240 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T18:41:28.796Z,1363200088.796 [NAL9602](INFO): Powering down
2013-03-13T18:46:08.801Z,1363200368.801 [Default:CallIridium] Running Loop=1
2013-03-13T18:46:08.801Z,1363200368.801 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-03-13T18:46:08.801Z,1363200368.801 [Default:CallIridium:A] Running Loop=1
2013-03-13T18:46:08.801Z,1363200368.801 [Default:CallIridium:A] Stopped
2013-03-13T18:46:08.802Z,1363200368.802 [Default:CallIridium:B] Running Loop=1
2013-03-13T18:46:08.802Z,1363200368.802 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-03-13T18:46:13.824Z,1363200373.824 [Default:Iridium] Running Loop=1
2013-03-13T18:46:13.824Z,1363200373.824 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-03-13T18:46:13.824Z,1363200373.824 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-13T18:46:13.824Z,1363200373.824 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-03-13T18:46:13.825Z,1363200373.825 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-03-13T18:46:13.825Z,1363200373.825 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T18:46:13.825Z,1363200373.825 [Default:Iridium:B.GoToSurface] Stopped
2013-03-13T18:46:13.825Z,1363200373.825 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T18:46:13.826Z,1363200373.826 [Default:Iridium:Read_Iridium] Running Loop=1
2013-03-13T18:46:13.826Z,1363200373.826 [Default:GPS] Running Loop=1
2013-03-13T18:46:13.826Z,1363200373.826 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-03-13T18:46:13.826Z,1363200373.826 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-13T18:46:13.826Z,1363200373.826 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-03-13T18:46:13.826Z,1363200373.826 [Default:GPS:B.GoToSurface] Running Loop=1
2013-03-13T18:46:13.826Z,1363200373.826 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T18:46:13.827Z,1363200373.827 [Default:GPS:B.GoToSurface] Stopped
2013-03-13T18:46:13.827Z,1363200373.827 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T18:46:13.827Z,1363200373.827 [Default:GPS:Read_GPS] Running Loop=1
2013-03-13T18:46:14.420Z,1363200374.420 [NAL9602](INFO): Powering up
2013-03-13T18:46:24.927Z,1363200384.927 [NAL9602](INFO): NAL9602 initialized
2013-03-13T18:46:45.109Z,1363200405.109 [NAL9602](INFO): SBD MO Status=1, MOMSN=7150, MT Status=0, MTMSN=0
2013-03-13T18:46:45.159Z,1363200405.159 [NAL9602](INFO): Sent 137 bytes from file Logs/20130313T170330/shore0017.lzma
2013-03-13T18:46:45.159Z,1363200405.159 [NAL9602](INFO): Packets left to send: 0
2013-03-13T18:46:45.161Z,1363200405.161 [NAL9602](INFO): Stored copy of sent data in Logs/20130313T170330/shore0017.lzma.parts/0000.sbd
2013-03-13T18:46:57.517Z,1363200417.517 [NAL9602](INFO): SBD MO Status=0, MOMSN=7151, MT Status=0, MTMSN=0
2013-03-13T18:46:57.605Z,1363200417.605 [Default:Iridium:Read_Iridium] Stopped
2013-03-13T18:46:57.605Z,1363200417.605 [Default:Iridium](INFO): Completed Default:Iridium
2013-03-13T18:46:57.605Z,1363200417.605 [Default:Iridium] Stopped
2013-03-13T18:46:57.605Z,1363200417.605 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-03-13T18:46:57.605Z,1363200417.605 [Default:Iridium:A.SetSpeed] Stopped
2013-03-13T18:46:57.606Z,1363200417.606 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T18:46:57.981Z,1363200417.981 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-03-13T18:46:57.981Z,1363200417.981 [Default:CallIridium:B] Stopped
2013-03-13T18:46:57.981Z,1363200417.981 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-03-13T18:46:57.981Z,1363200417.981 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-03-13T18:46:57.981Z,1363200417.981 [Default:CallIridium] Stopped
2013-03-13T18:46:57.981Z,1363200417.981 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-03-13T18:47:04.715Z,1363200424.715 [NAL9602](IMPORTANT): GPS fix at: 1363200419.00
2013-03-13T18:47:04.731Z,1363200424.731 [Default:GPS:Read_GPS] Stopped
2013-03-13T18:47:04.732Z,1363200424.731 [Default:GPS:D] Running Loop=1
2013-03-13T18:47:05.175Z,1363200425.175 [Default:GPS:D] Stopped
2013-03-13T18:47:05.176Z,1363200425.176 [Default:GPS](INFO): Completed Default:GPS
2013-03-13T18:47:05.176Z,1363200425.176 [Default:GPS] Stopped
2013-03-13T18:47:05.176Z,1363200425.176 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-03-13T18:47:05.176Z,1363200425.176 [Default:GPS:A.SetSpeed] Stopped
2013-03-13T18:47:05.176Z,1363200425.176 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T18:47:25.704Z,1363200445.704 [NAL9602](INFO): Powering down
2013-03-13T18:49:51.043Z,1363200591.043 [CommandLine](IMPORTANT): got command ibit
2013-03-13T18:49:55.728Z,1363200595.728 [IBIT](IMPORTANT): Beginning Initiated BIT
2013-03-13T18:49:55.729Z,1363200595.729 [IBIT](IMPORTANT): Beginning control surface checks.

2013-03-13T18:49:55.731Z,1363200595.731 [CBIT](IMPORTANT): Beginning GF scan
2013-03-13T18:50:00.628Z,1363200600.628 [NAL9602](INFO): Powering up
2013-03-13T18:50:11.067Z,1363200611.066 [IBIT](FAULT): Elevator: EXPECTED:15.000000 ACTUAL:14.795477
2013-03-13T18:50:11.067Z,1363200611.067 [IBIT](FAULT): Control surface position failure.
2013-03-13T18:50:11.367Z,1363200611.367 [NAL9602](INFO): NAL9602 initialized
2013-03-13T18:50:22.273Z,1363200622.273 [CBIT](FAULT): Chan 4 High side GF detected
mA:
CHAN 5 (24V): 0.050504
CHAN 4 (Batt): 0.015304
CHAN 2 (12V): 0.005739
CHAN 1 (5V): 0.000765
CHAN 0 (3.3V): 0.000574
OPEN: 0.000765
Full Scale Calc: 0.392
2013-03-13T18:50:45.475Z,1363200645.474 [CommandLine](INFO): End of History
2013-03-13T18:50:45.515Z,1363200645.515 [CommandLine](INFO): End of History
2013-03-13T18:50:45.555Z,1363200645.555 [CommandLine](INFO): End of History
2013-03-13T18:50:48.243Z,1363200648.243 [NAL9602](IMPORTANT): GPS fix at: 1363200642.00
2013-03-13T18:50:51.499Z,1363200651.499 [NAL9602](IMPORTANT): GPS fix at: 1363200646.00
2013-03-13T18:50:54.203Z,1363200654.203 [NAL9602](IMPORTANT): GPS fix at: 1363200648.00
2013-03-13T18:50:57.403Z,1363200657.403 [NAL9602](IMPORTANT): GPS fix at: 1363200652.00
2013-03-13T18:51:00.207Z,1363200660.207 [NAL9602](IMPORTANT): GPS fix at: 1363200655.00
2013-03-13T18:51:03.403Z,1363200663.403 [NAL9602](IMPORTANT): GPS fix at: 1363200658.00
2013-03-13T18:51:06.207Z,1363200666.207 [NAL9602](IMPORTANT): GPS fix at: 1363200661.00
2013-03-13T18:51:09.403Z,1363200669.403 [NAL9602](IMPORTANT): GPS fix at: 1363200664.00
2013-03-13T18:51:12.203Z,1363200672.203 [NAL9602](IMPORTANT): GPS fix at: 1363200667.00
2013-03-13T18:51:15.403Z,1363200675.403 [NAL9602](IMPORTANT): GPS fix at: 1363200670.00
2013-03-13T18:51:18.207Z,1363200678.207 [NAL9602](IMPORTANT): GPS fix at: 1363200673.00
2013-03-13T18:51:21.403Z,1363200681.403 [NAL9602](IMPORTANT): GPS fix at: 1363200676.00
2013-03-13T18:51:24.263Z,1363200684.263 [NAL9602](IMPORTANT): GPS fix at: 1363200679.00
2013-03-13T18:51:27.431Z,1363200687.431 [NAL9602](IMPORTANT): GPS fix at: 1363200682.00
2013-03-13T18:51:27.555Z,1363200687.555 [CommandLine](IMPORTANT): got command ibit
2013-03-13T18:51:30.231Z,1363200690.231 [NAL9602](IMPORTANT): GPS fix at: 1363200685.00
2013-03-13T18:51:33.431Z,1363200693.431 [NAL9602](IMPORTANT): GPS fix at: 1363200688.00
2013-03-13T18:51:36.231Z,1363200696.231 [NAL9602](IMPORTANT): GPS fix at: 1363200691.00
2013-03-13T18:51:39.439Z,1363200699.439 [NAL9602](IMPORTANT): GPS fix at: 1363200694.00
2013-03-13T18:51:42.299Z,1363200702.299 [NAL9602](IMPORTANT): GPS fix at: 1363200697.00
2013-03-13T18:51:45.439Z,1363200705.439 [NAL9602](IMPORTANT): GPS fix at: 1363200700.00
2013-03-13T18:51:46.729Z,1363200706.729 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired.
2013-03-13T18:51:47.141Z,1363200707.141 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 235.979996
Voltage: 16.192562
2013-03-13T18:51:47.141Z,1363200707.141 [IBIT](IMPORTANT): batteryCapacityThreshold: 5.000000 Ah
2013-03-13T18:51:47.142Z,1363200707.142 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.500000 V
2013-03-13T18:51:47.641Z,1363200707.641 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2013-03-13T18:51:47.641Z,1363200707.641 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2013-03-13T18:51:47.642Z,1363200707.642 [IBIT](IMPORTANT): Pressure:17.106230 PSI
2013-03-13T18:51:47.642Z,1363200707.642 [IBIT](IMPORTANT): Humidity:11.168997 %
2013-03-13T18:51:47.993Z,1363200707.993 [IBIT](IMPORTANT): surfaceThreshold: 0.500000 m
2013-03-13T18:51:47.993Z,1363200707.993 [IBIT](IMPORTANT): buoyancyNeutral: 360.000000 cc
2013-03-13T18:51:47.994Z,1363200707.994 [IBIT](IMPORTANT): massDefault: 0.900000 cm
2013-03-13T18:51:47.994Z,1363200707.994 [IBIT](IMPORTANT): stopDepth: 95.000000 m
2013-03-13T18:51:47.994Z,1363200707.994 [IBIT](IMPORTANT): abortDepth: 125.000000 m
2013-03-13T18:51:47.994Z,1363200707.994 [IBIT](IMPORTANT): IBIT FAILED
2013-03-13T18:51:48.258Z,1363200708.258 [NAL9602](IMPORTANT): GPS fix at: 1363200703.00
2013-03-13T18:51:58.444Z,1363200718.444 [Default:CallIridium] Running Loop=1
2013-03-13T18:51:58.444Z,1363200718.444 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-03-13T18:51:58.445Z,1363200718.445 [Default:CallIridium:A] Running Loop=1
2013-03-13T18:51:58.445Z,1363200718.445 [Default:CallIridium:A] Stopped
2013-03-13T18:51:58.445Z,1363200718.445 [Default:CallIridium:B] Running Loop=1
2013-03-13T18:51:58.445Z,1363200718.445 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-03-13T18:52:03.415Z,1363200723.415 [Default:Iridium] Running Loop=1
2013-03-13T18:52:03.416Z,1363200723.416 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-03-13T18:52:03.416Z,1363200723.416 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-13T18:52:03.416Z,1363200723.416 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-03-13T18:52:03.416Z,1363200723.416 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-03-13T18:52:03.416Z,1363200723.416 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T18:52:03.417Z,1363200723.417 [Default:Iridium:B.GoToSurface] Stopped
2013-03-13T18:52:03.417Z,1363200723.417 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T18:52:03.417Z,1363200723.417 [Default:Iridium:Read_Iridium] Running Loop=1
2013-03-13T18:52:03.417Z,1363200723.417 [Default:GPS] Running Loop=1
2013-03-13T18:52:03.417Z,1363200723.418 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-03-13T18:52:03.418Z,1363200723.418 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-13T18:52:03.418Z,1363200723.418 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-03-13T18:52:03.418Z,1363200723.418 [Default:GPS:B.GoToSurface] Running Loop=1
2013-03-13T18:52:03.418Z,1363200723.418 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T18:52:03.419Z,1363200723.419 [Default:GPS:B.GoToSurface] Stopped
2013-03-13T18:52:03.419Z,1363200723.419 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T18:52:03.419Z,1363200723.419 [Default:GPS:Read_GPS] Running Loop=1
2013-03-13T18:52:05.282Z,1363200725.283 [NAL9602](IMPORTANT): GPS fix at: 1363200720.00
2013-03-13T18:52:05.299Z,1363200725.299 [Default:GPS:Read_GPS] Stopped
2013-03-13T18:52:05.300Z,1363200725.300 [Default:GPS:D] Running Loop=1
2013-03-13T18:52:05.719Z,1363200725.719 [Default:GPS:D] Stopped
2013-03-13T18:52:05.720Z,1363200725.720 [Default:GPS](INFO): Completed Default:GPS
2013-03-13T18:52:05.720Z,1363200725.720 [Default:GPS] Stopped
2013-03-13T18:52:05.720Z,1363200725.720 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-03-13T18:52:05.720Z,1363200725.720 [Default:GPS:A.SetSpeed] Stopped
2013-03-13T18:52:05.720Z,1363200725.720 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T18:53:13.756Z,1363200793.756 [NAL9602](INFO): SBD MO Status=2, MOMSN=7152, MT Status=2, MTMSN=0
2013-03-13T18:53:13.756Z,1363200793.756 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-03-13T18:53:39.509Z,1363200819.509 [NAL9602](INFO): SBD MO Status=1, MOMSN=7152, MT Status=0, MTMSN=0
2013-03-13T18:53:39.562Z,1363200819.562 [NAL9602](INFO): Sent 332 bytes from file Logs/20130313T170330/shore0018.lzma
2013-03-13T18:53:39.563Z,1363200819.563 [NAL9602](INFO): Packets left to send: 3
2013-03-13T18:53:39.564Z,1363200819.564 [NAL9602](INFO): Stored copy of sent data in Logs/20130313T170330/shore0018.lzma.parts/0003.sbd
2013-03-13T18:53:49.325Z,1363200829.325 [NAL9602](INFO): SBD MO Status=1, MOMSN=7153, MT Status=0, MTMSN=0
2013-03-13T18:53:49.375Z,1363200829.375 [NAL9602](INFO): Sent 332 bytes from file Logs/20130313T170330/shore0018.lzma
2013-03-13T18:53:49.375Z,1363200829.375 [NAL9602](INFO): Packets left to send: 2
2013-03-13T18:53:49.376Z,1363200829.376 [NAL9602](INFO): Stored copy of sent data in Logs/20130313T170330/shore0018.lzma.parts/0002.sbd
2013-03-13T18:54:02.365Z,1363200842.365 [NAL9602](INFO): SBD MO Status=1, MOMSN=7154, MT Status=0, MTMSN=0
2013-03-13T18:54:02.415Z,1363200842.415 [NAL9602](INFO): Sent 332 bytes from file Logs/20130313T170330/shore0018.lzma
2013-03-13T18:54:02.415Z,1363200842.415 [NAL9602](INFO): Packets left to send: 1
2013-03-13T18:54:02.416Z,1363200842.416 [NAL9602](INFO): Stored copy of sent data in Logs/20130313T170330/shore0018.lzma.parts/0001.sbd
2013-03-13T18:54:26.601Z,1363200866.601 [NAL9602](INFO): SBD MO Status=1, MOMSN=7155, MT Status=0, MTMSN=0
2013-03-13T18:54:26.651Z,1363200866.651 [NAL9602](INFO): Sent 66 bytes from file Logs/20130313T170330/shore0018.lzma
2013-03-13T18:54:26.651Z,1363200866.651 [NAL9602](INFO): Packets left to send: 0
2013-03-13T18:54:26.652Z,1363200866.652 [NAL9602](INFO): Stored copy of sent data in Logs/20130313T170330/shore0018.lzma.parts/0000.sbd
2013-03-13T18:54:36.205Z,1363200876.205 [NAL9602](INFO): SBD MO Status=0, MOMSN=7156, MT Status=0, MTMSN=0
2013-03-13T18:54:36.292Z,1363200876.292 [Default:Iridium:Read_Iridium] Stopped
2013-03-13T18:54:36.292Z,1363200876.292 [Default:Iridium](INFO): Completed Default:Iridium
2013-03-13T18:54:36.292Z,1363200876.292 [Default:Iridium] Stopped
2013-03-13T18:54:36.292Z,1363200876.292 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-03-13T18:54:36.292Z,1363200876.293 [Default:Iridium:A.SetSpeed] Stopped
2013-03-13T18:54:36.292Z,1363200876.293 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T18:54:36.611Z,1363200876.611 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-03-13T18:54:36.611Z,1363200876.611 [Default:CallIridium:B] Stopped
2013-03-13T18:54:36.611Z,1363200876.611 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-03-13T18:54:36.611Z,1363200876.611 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-03-13T18:54:36.611Z,1363200876.611 [Default:CallIridium] Stopped
2013-03-13T18:54:36.611Z,1363200876.611 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-03-13T18:54:46.764Z,1363200886.764 [NAL9602](INFO): Powering down
2013-03-13T18:59:36.821Z,1363201176.821 [Default:CallIridium] Running Loop=1
2013-03-13T18:59:36.821Z,1363201176.821 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-03-13T18:59:36.821Z,1363201176.821 [Default:CallIridium:A] Running Loop=1
2013-03-13T18:59:36.821Z,1363201176.821 [Default:CallIridium:A] Stopped
2013-03-13T18:59:36.821Z,1363201176.821 [Default:CallIridium:B] Running Loop=1
2013-03-13T18:59:36.822Z,1363201176.822 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-03-13T18:59:41.781Z,1363201181.781 [Default:Iridium] Running Loop=1
2013-03-13T18:59:41.781Z,1363201181.781 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-03-13T18:59:41.781Z,1363201181.781 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-13T18:59:41.781Z,1363201181.781 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-03-13T18:59:41.781Z,1363201181.781 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-03-13T18:59:41.781Z,1363201181.781 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T18:59:41.782Z,1363201181.782 [Default:Iridium:B.GoToSurface] Stopped
2013-03-13T18:59:41.782Z,1363201181.782 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T18:59:41.782Z,1363201181.782 [Default:Iridium:Read_Iridium] Running Loop=1
2013-03-13T18:59:41.783Z,1363201181.783 [Default:GPS] Running Loop=1
2013-03-13T18:59:41.783Z,1363201181.783 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-03-13T18:59:41.783Z,1363201181.783 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-13T18:59:41.783Z,1363201181.783 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-03-13T18:59:41.783Z,1363201181.783 [Default:GPS:B.GoToSurface] Running Loop=1
2013-03-13T18:59:41.783Z,1363201181.783 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T18:59:41.784Z,1363201181.784 [Default:GPS:B.GoToSurface] Stopped
2013-03-13T18:59:41.784Z,1363201181.784 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T18:59:41.784Z,1363201181.784 [Default:GPS:Read_GPS] Running Loop=1
2013-03-13T18:59:42.400Z,1363201182.399 [NAL9602](INFO): Powering up
2013-03-13T18:59:52.979Z,1363201192.979 [NAL9602](INFO): NAL9602 initialized
2013-03-13T19:00:18.275Z,1363201218.275 [NAL9602](INFO): SBD MO Status=1, MOMSN=7157, MT Status=0, MTMSN=0
2013-03-13T19:00:18.323Z,1363201218.323 [NAL9602](INFO): Sent 103 bytes from file Logs/20130313T170330/shore0019.lzma
2013-03-13T19:00:18.323Z,1363201218.323 [NAL9602](INFO): Packets left to send: 0
2013-03-13T19:00:18.325Z,1363201218.325 [NAL9602](INFO): Stored copy of sent data in Logs/20130313T170330/shore0019.lzma.parts/0000.sbd
2013-03-13T19:00:29.475Z,1363201229.475 [NAL9602](INFO): SBD MO Status=0, MOMSN=7158, MT Status=0, MTMSN=0
2013-03-13T19:00:29.567Z,1363201229.567 [Default:Iridium:Read_Iridium] Stopped
2013-03-13T19:00:29.567Z,1363201229.567 [Default:Iridium](INFO): Completed Default:Iridium
2013-03-13T19:00:29.567Z,1363201229.568 [Default:Iridium] Stopped
2013-03-13T19:00:29.568Z,1363201229.568 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-03-13T19:00:29.568Z,1363201229.568 [Default:Iridium:A.SetSpeed] Stopped
2013-03-13T19:00:29.568Z,1363201229.568 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T19:00:29.885Z,1363201229.885 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-03-13T19:00:29.885Z,1363201229.885 [Default:CallIridium:B] Stopped
2013-03-13T19:00:29.885Z,1363201229.885 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-03-13T19:00:29.885Z,1363201229.885 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-03-13T19:00:29.885Z,1363201229.885 [Default:CallIridium] Stopped
2013-03-13T19:00:29.886Z,1363201229.885 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-03-13T19:00:30.676Z,1363201230.676 [NAL9602](IMPORTANT): GPS fix at: 1363201226.00
2013-03-13T19:00:30.693Z,1363201230.693 [Default:GPS:Read_GPS] Stopped
2013-03-13T19:00:30.693Z,1363201230.693 [Default:GPS:D] Running Loop=1
2013-03-13T19:00:31.113Z,1363201231.113 [Default:GPS:D] Stopped
2013-03-13T19:00:31.113Z,1363201231.113 [Default:GPS](INFO): Completed Default:GPS
2013-03-13T19:00:31.113Z,1363201231.113 [Default:GPS] Stopped
2013-03-13T19:00:31.113Z,1363201231.114 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-03-13T19:00:31.114Z,1363201231.114 [Default:GPS:A.SetSpeed] Stopped
2013-03-13T19:00:31.114Z,1363201231.114 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T19:00:51.680Z,1363201251.680 [NAL9602](INFO): Powering down
2013-03-13T19:05:31.677Z,1363201531.677 [Default:CallIridium] Running Loop=1
2013-03-13T19:05:31.677Z,1363201531.677 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-03-13T19:05:31.677Z,1363201531.677 [Default:CallIridium:A] Running Loop=1
2013-03-13T19:05:31.678Z,1363201531.678 [Default:CallIridium:A] Stopped
2013-03-13T19:05:31.678Z,1363201531.678 [Default:CallIridium:B] Running Loop=1
2013-03-13T19:05:31.678Z,1363201531.678 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-03-13T19:05:36.695Z,1363201536.695 [Default:Iridium] Running Loop=1
2013-03-13T19:05:36.696Z,1363201536.695 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-03-13T19:05:36.696Z,1363201536.696 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-13T19:05:36.696Z,1363201536.696 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-03-13T19:05:36.696Z,1363201536.696 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-03-13T19:05:36.696Z,1363201536.696 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T19:05:36.697Z,1363201536.697 [Default:Iridium:B.GoToSurface] Stopped
2013-03-13T19:05:36.697Z,1363201536.697 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T19:05:36.697Z,1363201536.697 [Default:Iridium:Read_Iridium] Running Loop=1
2013-03-13T19:05:36.697Z,1363201536.697 [Default:GPS] Running Loop=1
2013-03-13T19:05:36.697Z,1363201536.697 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-03-13T19:05:36.697Z,1363201536.697 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-13T19:05:36.697Z,1363201536.697 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-03-13T19:05:36.698Z,1363201536.698 [Default:GPS:B.GoToSurface] Running Loop=1
2013-03-13T19:05:36.698Z,1363201536.698 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T19:05:36.698Z,1363201536.698 [Default:GPS:B.GoToSurface] Stopped
2013-03-13T19:05:36.699Z,1363201536.699 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T19:05:36.699Z,1363201536.699 [Default:GPS:Read_GPS] Running Loop=1
2013-03-13T19:05:37.292Z,1363201537.292 [NAL9602](INFO): Powering up
2013-03-13T19:05:48.339Z,1363201548.339 [NAL9602](INFO): NAL9602 initialized
2013-03-13T19:06:04.025Z,1363201564.025 [NAL9602](INFO): SBD MO Status=1, MOMSN=7159, MT Status=0, MTMSN=0
2013-03-13T19:06:04.075Z,1363201564.075 [NAL9602](INFO): Sent 137 bytes from file Logs/20130313T170330/shore0020.lzma
2013-03-13T19:06:04.075Z,1363201564.075 [NAL9602](INFO): Packets left to send: 0
2013-03-13T19:06:04.076Z,1363201564.076 [NAL9602](INFO): Stored copy of sent data in Logs/20130313T170330/shore0020.lzma.parts/0000.sbd
2013-03-13T19:06:14.059Z,1363201574.059 [NAL9602](INFO): SBD MO Status=0, MOMSN=7160, MT Status=0, MTMSN=0
2013-03-13T19:06:14.145Z,1363201574.145 [Default:Iridium:Read_Iridium] Stopped
2013-03-13T19:06:14.146Z,1363201574.145 [Default:Iridium](INFO): Completed Default:Iridium
2013-03-13T19:06:14.146Z,1363201574.146 [Default:Iridium] Stopped
2013-03-13T19:06:14.146Z,1363201574.146 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-03-13T19:06:14.146Z,1363201574.146 [Default:Iridium:A.SetSpeed] Stopped
2013-03-13T19:06:14.146Z,1363201574.146 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T19:06:14.440Z,1363201574.440 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-03-13T19:06:14.440Z,1363201574.440 [Default:CallIridium:B] Stopped
2013-03-13T19:06:14.440Z,1363201574.440 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-03-13T19:06:14.441Z,1363201574.441 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-03-13T19:06:14.441Z,1363201574.441 [Default:CallIridium] Stopped
2013-03-13T19:06:14.441Z,1363201574.441 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-03-13T19:06:36.027Z,1363201596.027 [NAL9602](IMPORTANT): GPS fix at: 1363201592.00
2013-03-13T19:06:36.044Z,1363201596.044 [Default:GPS:Read_GPS] Stopped
2013-03-13T19:06:36.044Z,1363201596.044 [Default:GPS:D] Running Loop=1
2013-03-13T19:06:36.447Z,1363201596.447 [Default:GPS:D] Stopped
2013-03-13T19:06:36.448Z,1363201596.448 [Default:GPS](INFO): Completed Default:GPS
2013-03-13T19:06:36.448Z,1363201596.448 [Default:GPS] Stopped
2013-03-13T19:06:36.448Z,1363201596.448 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-03-13T19:06:36.448Z,1363201596.448 [Default:GPS:A.SetSpeed] Stopped
2013-03-13T19:06:36.448Z,1363201596.448 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T19:06:57.012Z,1363201617.012 [NAL9602](INFO): Powering down
2013-03-13T19:11:17.004Z,1363201877.004 [Default:CallIridium] Running Loop=1
2013-03-13T19:11:17.004Z,1363201877.004 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-03-13T19:11:17.004Z,1363201877.004 [Default:CallIridium:A] Running Loop=1
2013-03-13T19:11:17.005Z,1363201877.005 [Default:CallIridium:A] Stopped
2013-03-13T19:11:17.005Z,1363201877.005 [Default:CallIridium:B] Running Loop=1
2013-03-13T19:11:17.005Z,1363201877.005 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-03-13T19:11:21.976Z,1363201881.976 [Default:Iridium] Running Loop=1
2013-03-13T19:11:21.976Z,1363201881.977 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-03-13T19:11:21.977Z,1363201881.977 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-13T19:11:21.977Z,1363201881.977 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-03-13T19:11:21.977Z,1363201881.977 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-03-13T19:11:21.977Z,1363201881.977 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T19:11:21.978Z,1363201881.978 [Default:Iridium:B.GoToSurface] Stopped
2013-03-13T19:11:21.978Z,1363201881.978 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T19:11:21.978Z,1363201881.978 [Default:Iridium:Read_Iridium] Running Loop=1
2013-03-13T19:11:21.978Z,1363201881.978 [Default:GPS] Running Loop=1
2013-03-13T19:11:21.979Z,1363201881.979 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-03-13T19:11:21.979Z,1363201881.979 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-13T19:11:21.979Z,1363201881.979 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-03-13T19:11:21.979Z,1363201881.979 [Default:GPS:B.GoToSurface] Running Loop=1
2013-03-13T19:11:21.979Z,1363201881.979 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T19:11:21.980Z,1363201881.980 [Default:GPS:B.GoToSurface] Stopped
2013-03-13T19:11:21.980Z,1363201881.980 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T19:11:21.980Z,1363201881.980 [Default:GPS:Read_GPS] Running Loop=1
2013-03-13T19:11:22.688Z,1363201882.688 [NAL9602](INFO): Powering up
2013-03-13T19:11:33.103Z,1363201893.103 [NAL9602](INFO): NAL9602 initialized
2013-03-13T19:11:54.401Z,1363201914.401 [NAL9602](INFO): SBD MO Status=1, MOMSN=7161, MT Status=0, MTMSN=0
2013-03-13T19:11:54.451Z,1363201914.451 [NAL9602](INFO): Sent 139 bytes from file Logs/20130313T170330/shore0021.lzma
2013-03-13T19:11:54.451Z,1363201914.451 [NAL9602](INFO): Packets left to send: 0
2013-03-13T19:11:54.453Z,1363201914.453 [NAL9602](INFO): Stored copy of sent data in Logs/20130313T170330/shore0021.lzma.parts/0000.sbd
2013-03-13T19:12:02.037Z,1363201922.037 [NAL9602](INFO): SBD MO Status=0, MOMSN=7162, MT Status=0, MTMSN=0
2013-03-13T19:12:02.121Z,1363201922.121 [Default:Iridium:Read_Iridium] Stopped
2013-03-13T19:12:02.122Z,1363201922.122 [Default:Iridium](INFO): Completed Default:Iridium
2013-03-13T19:12:02.122Z,1363201922.122 [Default:Iridium] Stopped
2013-03-13T19:12:02.122Z,1363201922.122 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-03-13T19:12:02.122Z,1363201922.122 [Default:Iridium:A.SetSpeed] Stopped
2013-03-13T19:12:02.122Z,1363201922.122 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T19:12:02.419Z,1363201922.419 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-03-13T19:12:02.419Z,1363201922.419 [Default:CallIridium:B] Stopped
2013-03-13T19:12:02.419Z,1363201922.419 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-03-13T19:12:02.419Z,1363201922.419 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-03-13T19:12:02.419Z,1363201922.419 [Default:CallIridium] Stopped
2013-03-13T19:12:02.419Z,1363201922.419 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-03-13T19:12:03.264Z,1363201923.264 [NAL9602](IMPORTANT): GPS fix at: 1363201920.00
2013-03-13T19:12:03.281Z,1363201923.281 [Default:GPS:Read_GPS] Stopped
2013-03-13T19:12:03.281Z,1363201923.281 [Default:GPS:D] Running Loop=1
2013-03-13T19:12:03.627Z,1363201923.627 [Default:GPS:D] Stopped
2013-03-13T19:12:03.628Z,1363201923.628 [Default:GPS](INFO): Completed Default:GPS
2013-03-13T19:12:03.628Z,1363201923.628 [Default:GPS] Stopped
2013-03-13T19:12:03.628Z,1363201923.628 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-03-13T19:12:03.628Z,1363201923.628 [Default:GPS:A.SetSpeed] Stopped
2013-03-13T19:12:03.628Z,1363201923.628 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T19:12:24.165Z,1363201944.165 [NAL9602](INFO): Powering down
2013-03-13T19:17:04.209Z,1363202224.209 [Default:CallIridium] Running Loop=1
2013-03-13T19:17:04.209Z,1363202224.209 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-03-13T19:17:04.209Z,1363202224.209 [Default:CallIridium:A] Running Loop=1
2013-03-13T19:17:04.210Z,1363202224.210 [Default:CallIridium:A] Stopped
2013-03-13T19:17:04.210Z,1363202224.210 [Default:CallIridium:B] Running Loop=1
2013-03-13T19:17:04.210Z,1363202224.210 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-03-13T19:17:09.181Z,1363202229.181 [Default:Iridium] Running Loop=1
2013-03-13T19:17:09.181Z,1363202229.181 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-03-13T19:17:09.181Z,1363202229.181 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-13T19:17:09.182Z,1363202229.181 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-03-13T19:17:09.182Z,1363202229.182 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-03-13T19:17:09.182Z,1363202229.182 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T19:17:09.183Z,1363202229.182 [Default:Iridium:B.GoToSurface] Stopped
2013-03-13T19:17:09.183Z,1363202229.183 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T19:17:09.183Z,1363202229.183 [Default:Iridium:Read_Iridium] Running Loop=1
2013-03-13T19:17:09.183Z,1363202229.183 [Default:GPS] Running Loop=1
2013-03-13T19:17:09.183Z,1363202229.183 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-03-13T19:17:09.183Z,1363202229.183 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-13T19:17:09.183Z,1363202229.183 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-03-13T19:17:09.184Z,1363202229.184 [Default:GPS:B.GoToSurface] Running Loop=1
2013-03-13T19:17:09.184Z,1363202229.184 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-13T19:17:09.184Z,1363202229.184 [Default:GPS:B.GoToSurface] Stopped
2013-03-13T19:17:09.184Z,1363202229.184 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T19:17:09.185Z,1363202229.185 [Default:GPS:Read_GPS] Running Loop=1
2013-03-13T19:17:09.799Z,1363202229.799 [NAL9602](INFO): Powering up
2013-03-13T19:17:20.715Z,1363202240.715 [NAL9602](INFO): NAL9602 initialized
2013-03-13T19:17:37.609Z,1363202257.609 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=7163, MT Status=1, MTMSN=572
2013-03-13T19:17:37.661Z,1363202257.661 [NAL9602](INFO): Sent 137 bytes from file Logs/20130313T170330/shore0022.lzma
2013-03-13T19:17:37.661Z,1363202257.661 [NAL9602](INFO): Packets left to send: 0
2013-03-13T19:17:37.674Z,1363202257.674 [NAL9602](INFO): Stored copy of sent data in Logs/20130313T170330/shore0022.lzma.parts/0000.sbd
2013-03-13T19:17:38.111Z,1363202258.111 [NAL9602](INFO): Received command:Restart app
2013-03-13T19:17:38.151Z,1363202258.151 [CommandLine](IMPORTANT): got command restart application
2013-03-13T19:17:39.182Z,1363202259.182 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2013-03-13T19:17:39.182Z,1363202259.182 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2013-03-13T19:17:39.207Z,1363202259.207 [NAL9602](IMPORTANT): GPS fix at: 1363202256.00
2013-03-13T19:17:39.224Z,1363202259.224 [Default:GPS:Read_GPS] Stopped
2013-03-13T19:17:39.224Z,1363202259.224 [Default:GPS:D] Running Loop=1
2013-03-13T19:17:39.490Z,1363202259.490 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2013-03-13T19:17:39.637Z,1363202259.637 [Default:GPS:D] Stopped
2013-03-13T19:17:39.637Z,1363202259.637 [Default:GPS](INFO): Completed Default:GPS
2013-03-13T19:17:39.637Z,1363202259.637 [Default:GPS] Stopped
2013-03-13T19:17:39.637Z,1363202259.637 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-03-13T19:17:39.637Z,1363202259.638 [Default:GPS:A.SetSpeed] Stopped
2013-03-13T19:17:39.638Z,1363202259.638 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T19:17:39.759Z,1363202259.759 [WetLabsBB2FL](INFO): Powering down
2013-03-13T19:17:39.770Z,1363202259.770 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2013-03-13T19:17:39.967Z,1363202259.967 [CTD_NeilBrown](INFO): Powering down
2013-03-13T19:17:39.974Z,1363202259.974 [ComponentRegistry](INFO): Shutting down DVL_micro ThreadHandler
2013-03-13T19:17:40.115Z,1363202260.115 [DVL_micro](INFO): uninitialize:Powering down
2013-03-13T19:17:40.134Z,1363202260.134 [ComponentRegistry](INFO): Shutting down AsyncPiEstimator ThreadHandler
2013-03-13T19:17:40.403Z,1363202260.402 [AsyncPiEstimator](DEBUG): Uninitialize AsyncPiEstimator.
2013-03-13T19:17:40.404Z,1363202260.404 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2013-03-13T19:17:40.471Z,1363202260.471 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2013-03-13T19:17:40.472Z,1363202260.473 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2013-03-13T19:17:40.623Z,1363202260.623 [controlThread](DEBUG): Uninitializing ControlThread
2013-03-13T19:17:40.623Z,1363202260.623 [AHRS_sp3003D](INFO): Powering down
2013-03-13T19:17:40.711Z,1363202260.711 [NAL9602](INFO): Powering down
2013-03-13T19:17:40.713Z,1363202260.713 [Aanderaa_O2](INFO): Powering down
2013-03-13T19:17:40.714Z,1363202260.714 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2013-03-13T19:17:40.715Z,1363202260.715 [NavChart](DEBUG): Uninitialize NavChart Derivation.
2013-03-13T19:17:40.716Z,1363202260.716 [Default] Stopped
2013-03-13T19:17:40.716Z,1363202260.716 [Default](INFO): Aggregate::uninitialize Default
2013-03-13T19:17:40.716Z,1363202260.716 [Default:Iridium] Stopped
2013-03-13T19:17:40.716Z,1363202260.716 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-03-13T19:17:40.716Z,1363202260.716 [Default:Iridium:A.SetSpeed] Stopped
2013-03-13T19:17:40.716Z,1363202260.716 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-03-13T19:17:40.716Z,1363202260.716 [Default:Iridium:Read_Iridium] Stopped
2013-03-13T19:17:40.716Z,1363202260.717 [Default:CallIridium] Stopped
2013-03-13T19:17:40.717Z,1363202260.717 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-03-13T19:17:40.717Z,1363202260.717 [Default:CallIridium:B] Stopped
2013-03-13T19:17:40.717Z,1363202260.717 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-03-13T19:17:40.717Z,1363202260.717 [Default:D.SetSpeed] Stopped
2013-03-13T19:17:40.717Z,1363202260.717 [Default:D.SetSpeed](DEBUG): Uninitialize.
2013-03-13T19:17:40.717Z,1363202260.717 [Default:E.GoToSurface] Stopped
2013-03-13T19:17:40.717Z,1363202260.717 [Default:E.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-13T19:17:40.717Z,1363202260.717 [Default:F.Wait] Stopped
2013-03-13T19:17:40.717Z,1363202260.717 [Default:F.Wait](DEBUG): Uninitialize Wait Component.
2013-03-13T19:17:40.721Z,1363202260.721 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2013-03-13T19:17:40.722Z,1363202260.722 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2013-03-13T19:17:40.722Z,1363202260.722 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2013-03-13T19:17:40.722Z,1363202260.722 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2013-03-13T19:17:40.723Z,1363202260.723 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2013-03-13T19:17:40.723Z,1363202260.723 [BuoyancyServo](INFO): Powering down
2013-03-13T19:17:40.734Z,1363202260.734 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2013-03-13T19:17:40.735Z,1363202260.735 [ElevatorServo](INFO): Powering down
2013-03-13T19:17:40.735Z,1363202260.736 [MassServo](DEBUG): Uninitialize Mass Servo.
2013-03-13T19:17:40.736Z,1363202260.736 [MassServo](INFO): Powering down
2013-03-13T19:17:40.736Z,1363202260.736 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2013-03-13T19:17:40.736Z,1363202260.736 [RudderServo](INFO): Powering down
2013-03-13T19:17:40.737Z,1363202260.737 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2013-03-13T19:17:40.737Z,1363202260.737 [ThrusterServo](INFO): Powering down
2013-03-13T19:17:40.738Z,1363202260.738 [SBIT](DEBUG): Uninitialize SBIT Component.
2013-03-13T19:17:40.739Z,1363202260.739 [IBIT](DEBUG): Uninitialize IBIT Component.
2013-03-13T19:17:40.739Z,1363202260.739 [CBIT](DEBUG): Uninitialize CBIT Component.