2013-05-09T19:56:26.164Z,1368129386.164 [Supervisor](DEBUG): Initializing supervisor. 2013-05-09T19:56:26.167Z,1368129386.167 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0 2013-05-09T19:56:26.167Z,1368129386.167 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2013-05-09T19:56:26.168Z,1368129386.168 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0 2013-05-09T19:56:26.172Z,1368129386.172 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2013-05-09T19:56:26.182Z,1368129386.182 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2013-05-09T19:56:26.183Z,1368129386.183 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0 2013-05-09T19:56:26.184Z,1368129386.184 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2013-05-09T19:56:26.184Z,1368129386.184 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0 2013-05-09T19:56:26.185Z,1368129386.185 [Supervisor](INFO): Looking for Config files in directory: Config/ 2013-05-09T19:56:26.190Z,1368129386.190 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2013-05-09T19:56:26.536Z,1368129386.536 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2013-05-09T19:56:26.537Z,1368129386.537 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2013-05-09T19:56:26.724Z,1368129386.724 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2013-05-09T19:56:26.725Z,1368129386.725 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2013-05-09T19:56:26.811Z,1368129386.811 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2013-05-09T19:56:26.813Z,1368129386.813 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2013-05-09T19:56:27.011Z,1368129387.011 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2013-05-09T19:56:27.012Z,1368129387.012 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2013-05-09T19:56:27.149Z,1368129387.149 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2013-05-09T19:56:27.151Z,1368129387.151 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2013-05-09T19:56:27.380Z,1368129387.380 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2013-05-09T19:56:27.381Z,1368129387.381 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2013-05-09T19:56:27.566Z,1368129387.566 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2013-05-09T19:56:27.572Z,1368129387.572 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2013-05-09T19:56:27.845Z,1368129387.845 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2013-05-09T19:56:27.847Z,1368129387.847 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2013-05-09T19:56:27.947Z,1368129387.947 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2013-05-09T19:56:27.947Z,1368129387.947 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2013-05-09T19:56:28.343Z,1368129388.343 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2013-05-09T19:56:28.344Z,1368129388.344 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2013-05-09T19:56:28.563Z,1368129388.563 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2013-05-09T19:56:28.564Z,1368129388.564 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2013-05-09T19:56:28.653Z,1368129388.653 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2013-05-09T19:56:28.656Z,1368129388.656 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2013-05-09T19:56:28.763Z,1368129388.763 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2013-05-09T19:56:28.893Z,1368129388.893 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2013-05-09T19:56:29.030Z,1368129389.030 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2013-05-09T19:56:29.134Z,1368129389.134 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2013-05-09T19:56:29.235Z,1368129389.235 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2013-05-09T19:56:29.354Z,1368129389.354 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2013-05-09T19:56:29.451Z,1368129389.451 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2013-05-09T19:56:29.538Z,1368129389.538 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2013-05-09T19:56:29.563Z,1368129389.563 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2013-05-09T19:56:29.738Z,1368129389.738 [InternalSim] Loaded 2013-05-09T19:56:29.738Z,1368129389.738 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread. 2013-05-09T19:56:29.739Z,1368129389.739 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2013-05-09T19:56:29.740Z,1368129389.740 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2013-05-09T19:56:29.817Z,1368129389.817 [SBIT](DEBUG): Construct Startup Built In Test. 2013-05-09T19:56:29.846Z,1368129389.846 [SBIT] Loaded 2013-05-09T19:56:29.846Z,1368129389.846 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2013-05-09T19:56:29.847Z,1368129389.847 [IBIT](DEBUG): Construct Initiated Built In Test. 2013-05-09T19:56:29.875Z,1368129389.875 [IBIT] Loaded 2013-05-09T19:56:29.875Z,1368129389.875 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2013-05-09T19:56:29.879Z,1368129389.879 [CBIT](DEBUG): Construct CBIT Built In Test. 2013-05-09T19:56:29.993Z,1368129389.993 [CBIT] Loaded 2013-05-09T19:56:29.993Z,1368129389.993 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2013-05-09T19:56:29.993Z,1368129389.993 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2013-05-09T19:56:29.994Z,1368129389.994 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2013-05-09T19:56:30.161Z,1368129390.161 [BuoyancyServo] Loaded 2013-05-09T19:56:30.161Z,1368129390.161 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2013-05-09T19:56:30.174Z,1368129390.174 [ElevatorServo] Loaded 2013-05-09T19:56:30.174Z,1368129390.174 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2013-05-09T19:56:30.185Z,1368129390.185 [MassServo] Loaded 2013-05-09T19:56:30.185Z,1368129390.185 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2013-05-09T19:56:30.197Z,1368129390.197 [RudderServo] Loaded 2013-05-09T19:56:30.197Z,1368129390.197 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2013-05-09T19:56:30.209Z,1368129390.209 [ThrusterServo] Loaded 2013-05-09T19:56:30.209Z,1368129390.209 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2013-05-09T19:56:30.209Z,1368129390.210 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2013-05-09T19:56:30.210Z,1368129390.210 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2013-05-09T19:56:30.239Z,1368129390.239 [DepthRateCalculator] Loaded 2013-05-09T19:56:30.239Z,1368129390.239 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2013-05-09T19:56:33.182Z,1368129393.182 [HFRadarModelCalc] Loaded 2013-05-09T19:56:33.182Z,1368129393.182 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread. 2013-05-09T19:56:33.198Z,1368129393.198 [NavChart] Loaded 2013-05-09T19:56:33.198Z,1368129393.198 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2013-05-09T19:56:33.204Z,1368129393.204 [PitchRateCalculator] Loaded 2013-05-09T19:56:33.204Z,1368129393.204 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2013-05-09T19:56:33.215Z,1368129393.215 [SpeedCalculator] Loaded 2013-05-09T19:56:33.215Z,1368129393.215 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2013-05-09T19:56:33.230Z,1368129393.230 [TempGradientCalculator] Loaded 2013-05-09T19:56:33.230Z,1368129393.230 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2013-05-09T19:56:33.236Z,1368129393.236 [YawRateCalculator] Loaded 2013-05-09T19:56:33.236Z,1368129393.236 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2013-05-09T19:56:33.282Z,1368129393.282 [Navigation] Loaded 2013-05-09T19:56:33.282Z,1368129393.282 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread. 2013-05-09T19:56:33.282Z,1368129393.282 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2013-05-09T19:56:33.283Z,1368129393.283 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2013-05-09T19:56:33.522Z,1368129393.522 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2013-05-09T19:56:33.522Z,1368129393.522 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2013-05-09T19:56:33.590Z,1368129393.590 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2013-05-09T19:56:33.591Z,1368129393.591 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2013-05-09T19:56:33.641Z,1368129393.641 [VerticalControl](DEBUG): Construct VerticalControl. 2013-05-09T19:56:33.732Z,1368129393.732 [VerticalControl] Loaded 2013-05-09T19:56:33.733Z,1368129393.733 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2013-05-09T19:56:33.734Z,1368129393.734 [HorizontalControl](DEBUG): Construct HorizontalControl. 2013-05-09T19:56:33.789Z,1368129393.789 [HorizontalControl] Loaded 2013-05-09T19:56:33.789Z,1368129393.789 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2013-05-09T19:56:33.790Z,1368129393.790 [SpeedControl](DEBUG): Construct SpeedControl. 2013-05-09T19:56:33.792Z,1368129393.792 [SpeedControl] Loaded 2013-05-09T19:56:33.792Z,1368129393.792 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2013-05-09T19:56:33.793Z,1368129393.793 [LoopControl](DEBUG): Construct LoopControl. 2013-05-09T19:56:33.794Z,1368129393.794 [LoopControl] Loaded 2013-05-09T19:56:33.794Z,1368129393.794 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2013-05-09T19:56:33.794Z,1368129393.794 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2013-05-09T19:56:33.795Z,1368129393.795 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2013-05-09T19:56:33.806Z,1368129393.806 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator. 2013-05-09T19:56:33.812Z,1368129393.812 [AsyncPiEstimator] Loaded 2013-05-09T19:56:33.813Z,1368129393.813 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread. 2013-05-09T19:56:33.814Z,1368129393.814 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 4063B4E0 2013-05-09T19:56:33.814Z,1368129393.814 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2013-05-09T19:56:33.815Z,1368129393.815 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2013-05-09T19:56:33.973Z,1368129393.973 [AHRS_sp3003D] Loaded 2013-05-09T19:56:33.973Z,1368129393.973 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread. 2013-05-09T19:56:34.225Z,1368129394.225 [Batt_Ocean_Server] Loaded 2013-05-09T19:56:34.225Z,1368129394.225 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread. 2013-05-09T19:56:34.239Z,1368129394.239 [Depth_Keller] Loaded 2013-05-09T19:56:34.239Z,1368129394.239 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2013-05-09T19:56:34.245Z,1368129394.245 [DropWeight] Loaded 2013-05-09T19:56:34.245Z,1368129394.245 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2013-05-09T19:56:34.414Z,1368129394.414 [DVL_micro] Loaded 2013-05-09T19:56:34.414Z,1368129394.414 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread. 2013-05-09T19:56:34.415Z,1368129394.415 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 406C04E0 2013-05-09T19:56:34.496Z,1368129394.496 [NAL9602] Loaded 2013-05-09T19:56:34.496Z,1368129394.496 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2013-05-09T19:56:34.546Z,1368129394.546 [Onboard] Loaded 2013-05-09T19:56:34.546Z,1368129394.546 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2013-05-09T19:56:34.553Z,1368129394.553 [Radio_Freewave] Loaded 2013-05-09T19:56:34.553Z,1368129394.553 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread. 2013-05-09T19:56:34.554Z,1368129394.554 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2013-05-09T19:56:34.554Z,1368129394.554 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2013-05-09T19:56:34.643Z,1368129394.643 [CTD_NeilBrown] Loaded 2013-05-09T19:56:34.643Z,1368129394.643 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2013-05-09T19:56:34.645Z,1368129394.645 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 407124E0 2013-05-09T19:56:34.674Z,1368129394.674 [WetLabsBB2FL] Loaded 2013-05-09T19:56:34.675Z,1368129394.675 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2013-05-09T19:56:34.676Z,1368129394.676 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407424E0 2013-05-09T19:56:34.676Z,1368129394.676 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2013-05-09T19:56:34.679Z,1368129394.679 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2013-05-09T19:56:34.680Z,1368129394.680 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2013-05-09T19:56:34.686Z,1368129394.686 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2013-05-09T19:56:34.687Z,1368129394.687 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 407724E0 2013-05-09T19:56:34.691Z,1368129394.691 [Supervisor](DEBUG): Running supervisor. 2013-05-09T19:56:34.692Z,1368129394.692 [CommandLine](INFO): Thread ID is 3859 2013-05-09T19:56:34.695Z,1368129394.695 [controlThread](INFO): Thread ID is 3858 2013-05-09T19:56:34.695Z,1368129394.695 [controlThread](DEBUG): Initializing ControlThread 2013-05-09T19:56:34.696Z,1368129394.696 [CycleStarter](INFO): Thread ID is 3857 2013-05-09T19:56:34.696Z,1368129394.696 [InternalSim](DEBUG): InternalSim initializing... 2013-05-09T19:56:34.731Z,1368129394.731 [logger](INFO): Thread ID is 3860 2013-05-09T19:56:34.752Z,1368129394.752 [SBIT](INFO): Initialize SBIT Component. 2013-05-09T19:56:34.753Z,1368129394.753 [SBIT](IMPORTANT): Tethys CM Info: $Rev:10327 2013-05-09T19:56:34.753Z,1368129394.753 [SBIT](IMPORTANT): Kernel Release:2.6.27.8 2013-05-09T19:56:34.753Z,1368129394.753 [SBIT](IMPORTANT): Kernel Version:#634 PREEMPT Wed Feb 13 10:21:48 PST 2013 2013-05-09T19:56:34.754Z,1368129394.754 [IBIT](INFO): Initialize IBIT Component. 2013-05-09T19:56:34.755Z,1368129394.755 [CBIT](DEBUG): Initialize CBIT Component. 2013-05-09T19:56:34.755Z,1368129394.755 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2013-05-09T19:56:34.764Z,1368129394.764 [AsyncPiEstimator](INFO): Thread ID is 3922 2013-05-09T19:56:34.765Z,1368129394.764 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator. 2013-05-09T19:56:34.785Z,1368129394.785 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2013-05-09T19:56:34.786Z,1368129394.786 [NavChart](DEBUG): Initialize NavChart Derivation. 2013-05-09T19:56:34.786Z,1368129394.786 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2013-05-09T19:56:34.786Z,1368129394.786 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2013-05-09T19:56:34.787Z,1368129394.787 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2013-05-09T19:56:34.789Z,1368129394.789 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2013-05-09T19:56:34.789Z,1368129394.789 [Navigation](DEBUG): Initializing Navigation. 2013-05-09T19:56:34.789Z,1368129394.789 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2013-05-09T19:56:34.791Z,1368129394.791 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2013-05-09T19:56:34.792Z,1368129394.792 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2013-05-09T19:56:34.793Z,1368129394.793 [LoopControl](DEBUG): Initialize LoopControlComponent. 2013-05-09T19:56:34.796Z,1368129394.796 [DVL_micro](INFO): Thread ID is 3923 2013-05-09T19:56:34.805Z,1368129394.805 [DVL_micro](INFO): Initializing 2013-05-09T19:56:34.806Z,1368129394.806 [DVL_micro](INFO): start:Powering up 2013-05-09T19:56:34.806Z,1368129394.806 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-05-09T19:56:34.807Z,1368129394.807 [DVL_micro](INFO): Cycling power to configure device. 2013-05-09T19:56:34.817Z,1368129394.817 [CTD_NeilBrown](INFO): Thread ID is 3924 2013-05-09T19:56:34.817Z,1368129394.817 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown. 2013-05-09T19:56:34.820Z,1368129394.820 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4 2013-05-09T19:56:34.829Z,1368129394.829 [WetLabsBB2FL](INFO): Thread ID is 3925 2013-05-09T19:56:34.830Z,1368129394.830 [WetLabsBB2FL](INFO): Powering down 2013-05-09T19:56:34.873Z,1368129394.872 [NavChartDb](INFO): Thread ID is 3926 2013-05-09T19:56:34.881Z,1368129394.881 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources 2013-05-09T19:56:34.882Z,1368129394.882 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2013-05-09T19:56:34.882Z,1368129394.882 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2013-05-09T19:56:34.882Z,1368129394.882 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2013-05-09T19:56:34.882Z,1368129394.882 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2013-05-09T19:56:34.883Z,1368129394.883 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2013-05-09T19:56:34.883Z,1368129394.883 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2013-05-09T19:56:34.883Z,1368129394.883 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2013-05-09T19:56:34.884Z,1368129394.884 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2013-05-09T19:56:36.786Z,1368129396.786 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized 2013-05-09T19:56:36.818Z,1368129396.818 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2013-05-09T19:56:36.851Z,1368129396.851 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2013-05-09T19:56:36.884Z,1368129396.884 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-05-09T19:56:36.884Z,1368129396.884 [DVL_micro](INFO): Querying output modes 2013-05-09T19:56:36.885Z,1368129396.885 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606 2013-05-09T19:56:36.893Z,1368129396.893 [MissionManager](DEBUG): 2013-05-09T19:56:36.894Z,1368129396.894 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2013-05-09T19:56:36.896Z,1368129396.896 [DVL_micro](DEBUG): cmdResponse: 01 2013-05-09T19:56:36.896Z,1368129396.896 [DVL_micro](INFO): NQ1 output enabled 2013-05-09T19:56:36.896Z,1368129396.896 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525 2013-05-09T19:56:36.908Z,1368129396.908 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 2013-05-09T19:56:36.913Z,1368129396.913 [DVL_micro](INFO): pause:Powering down 2013-05-09T19:56:36.996Z,1368129396.996 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool 2013-05-09T19:56:36.998Z,1368129396.998 [Default:GPS:A.SetSpeed](DEBUG): Construct. 2013-05-09T19:56:37.001Z,1368129397.001 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface. 2013-05-09T19:56:37.021Z,1368129397.021 [Default:Iridium:A.SetSpeed](DEBUG): Construct. 2013-05-09T19:56:37.024Z,1368129397.024 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface. 2013-05-09T19:56:37.058Z,1368129397.058 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2013-05-09T19:56:37.083Z,1368129397.083 [Default:D.SetSpeed](DEBUG): Construct. 2013-05-09T19:56:37.086Z,1368129397.086 [Default:E.GoToSurface](DEBUG): Construct GoToSurface. 2013-05-09T19:56:37.107Z,1368129397.107 [Default:F.Wait](DEBUG): Construct Wait. 2013-05-09T19:56:37.112Z,1368129397.112 [MissionManager](DEBUG): 400 400 Burn 300 Dropped drop weight due to communications timeout 5.0 1.0 5 2013-05-09T19:56:37.116Z,1368129397.116 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,NAL9602,Onboard,Radio_Freewave,Depth_Keller,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter, 2013-05-09T19:56:37.179Z,1368129397.179 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2013-05-09T19:56:37.228Z,1368129397.228 [Depth_Keller](ERROR): Pressure reading out of range: 1831.078247 decibar 2013-05-09T19:56:37.292Z,1368129397.292 [Radio_Freewave](INFO): Powering up 2013-05-09T19:56:37.484Z,1368129397.484 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2013-05-09T19:56:37.491Z,1368129397.490 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2013-05-09T19:56:37.509Z,1368129397.509 [ElevatorServo](DEBUG): Initializing EZServoServo. 2013-05-09T19:56:37.516Z,1368129397.516 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2013-05-09T19:56:37.522Z,1368129397.522 [MassServo](DEBUG): Initializing EZServoServo. 2013-05-09T19:56:37.528Z,1368129397.528 [MassServo](DEBUG): Initializing MassServo. 2013-05-09T19:56:37.546Z,1368129397.546 [RudderServo](DEBUG): Initializing EZServoServo. 2013-05-09T19:56:37.552Z,1368129397.552 [RudderServo](DEBUG): Initializing RudderServo. 2013-05-09T19:56:37.570Z,1368129397.570 [ThrusterServo](DEBUG): Initializing EZServoServo. 2013-05-09T19:56:37.576Z,1368129397.576 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2013-05-09T19:56:39.556Z,1368129399.556 [NAL9602](INFO): Powering up NAL9602 2013-05-09T19:56:50.260Z,1368129410.260 [NAL9602](INFO): NAL9602 initialized 2013-05-09T19:56:50.312Z,1368129410.312 [SBIT](IMPORTANT): Beginning Startup BIT 2013-05-09T19:56:50.314Z,1368129410.314 [CBIT](IMPORTANT): Beginning GF scan 2013-05-09T19:57:02.840Z,1368129422.840 [NAL9602](IMPORTANT): GPS fix at: 1368129542.00 2013-05-09T19:57:10.185Z,1368129430.185 [NAL9602](INFO): Powering down 2013-05-09T19:57:17.049Z,1368129437.049 [CBIT](IMPORTANT): No ground fault detected 2013-05-09T19:57:44.352Z,1368129464.352 [SBIT](IMPORTANT): SBIT PASSED 2013-05-09T19:57:44.775Z,1368129464.775 [MissionManager](IMPORTANT): Started mission Startup 2013-05-09T19:57:44.775Z,1368129464.775 [Startup] Running Loop=1 2013-05-09T19:57:44.775Z,1368129464.775 [Startup](INFO): Aggregate::initialize Startup 2013-05-09T19:57:44.775Z,1368129464.775 [Startup:A.GoToSurface] Running Loop=1 2013-05-09T19:57:44.775Z,1368129464.775 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-05-09T19:57:44.782Z,1368129464.782 [Startup:StartupSatComms] Running Loop=1 2013-05-09T19:57:44.782Z,1368129464.782 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms 2013-05-09T19:57:44.782Z,1368129464.782 [Startup:StartupSatComms:A] Running Loop=1 2013-05-09T19:57:45.146Z,1368129465.146 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2013-05-09T19:57:45.528Z,1368129465.528 [NAL9602](INFO): Powering up 2013-05-09T19:57:55.964Z,1368129475.964 [NAL9602](INFO): NAL9602 initialized 2013-05-09T19:58:28.327Z,1368129508.327 [NAL9602](IMPORTANT): GPS fix at: 1368129628.00 2013-05-09T19:58:28.350Z,1368129508.350 [Startup:StartupSatComms:A] Stopped 2013-05-09T19:58:28.350Z,1368129508.350 [Startup:StartupSatComms:B] Running Loop=1 2013-05-09T19:58:28.759Z,1368129508.759 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2013-05-09T19:58:52.125Z,1368129532.125 [NAL9602](INFO): SBD MO Status=1, MOMSN=11737, MT Status=0, MTMSN=0 2013-05-09T19:58:52.176Z,1368129532.176 [NAL9602](INFO): Sent 272 bytes from file Logs/20130508T210559/shore0063.lzma 2013-05-09T19:58:52.176Z,1368129532.176 [NAL9602](INFO): Packets left to send: 0 2013-05-09T19:58:52.178Z,1368129532.178 [NAL9602](INFO): Stored copy of sent data in Logs/20130508T210559/shore0063.lzma.parts/0000.sbd 2013-05-09T19:59:04.794Z,1368129544.794 [NAL9602](INFO): SBD MO Status=1, MOMSN=11738, MT Status=0, MTMSN=0 2013-05-09T19:59:04.852Z,1368129544.852 [NAL9602](INFO): Sent 332 bytes from file Logs/20130509T195626/shore0000.lzma 2013-05-09T19:59:04.852Z,1368129544.852 [NAL9602](INFO): Packets left to send: 2 2013-05-09T19:59:04.854Z,1368129544.854 [NAL9602](INFO): Stored copy of sent data in Logs/20130509T195626/shore0000.lzma.parts/0002.sbd 2013-05-09T19:59:16.690Z,1368129556.690 [NAL9602](INFO): SBD MO Status=1, MOMSN=11739, MT Status=0, MTMSN=0 2013-05-09T19:59:16.740Z,1368129556.740 [NAL9602](INFO): Sent 332 bytes from file Logs/20130509T195626/shore0000.lzma 2013-05-09T19:59:16.740Z,1368129556.740 [NAL9602](INFO): Packets left to send: 1 2013-05-09T19:59:16.741Z,1368129556.741 [NAL9602](INFO): Stored copy of sent data in Logs/20130509T195626/shore0000.lzma.parts/0001.sbd 2013-05-09T19:59:25.767Z,1368129565.767 [NAL9602](INFO): SBD MO Status=1, MOMSN=11740, MT Status=0, MTMSN=0 2013-05-09T19:59:25.816Z,1368129565.816 [NAL9602](INFO): Sent 142 bytes from file Logs/20130509T195626/shore0000.lzma 2013-05-09T19:59:25.816Z,1368129565.816 [NAL9602](INFO): Packets left to send: 0 2013-05-09T19:59:25.817Z,1368129565.817 [NAL9602](INFO): Stored copy of sent data in Logs/20130509T195626/shore0000.lzma.parts/0000.sbd 2013-05-09T19:59:28.550Z,1368129568.550 [Startup:StartupSatComms:B](INFO): Timed out from 2013-05-09T19:58:28.4Z 2013-05-09T19:59:28.550Z,1368129568.550 [Startup:StartupSatComms:B:A_Timeout] Running Loop=1 2013-05-09T19:59:28.550Z,1368129568.550 [Startup:StartupSatComms:B:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:B:A_Timeout 2013-05-09T19:59:28.550Z,1368129568.550 [Startup:StartupSatComms:B:A_Timeout](INFO): Completed Startup:StartupSatComms:B:A_Timeout 2013-05-09T19:59:28.550Z,1368129568.550 [Startup:StartupSatComms:B] Stopped 2013-05-09T19:59:28.550Z,1368129568.550 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2013-05-09T19:59:28.550Z,1368129568.550 [Startup:StartupSatComms] Stopped 2013-05-09T19:59:28.551Z,1368129568.551 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms 2013-05-09T19:59:28.552Z,1368129568.552 [Startup](INFO): Completed Startup 2013-05-09T19:59:28.552Z,1368129568.552 [Startup] Stopped 2013-05-09T19:59:28.552Z,1368129568.552 [Startup](INFO): Aggregate::uninitialize Startup 2013-05-09T19:59:28.552Z,1368129568.552 [Startup:A.GoToSurface] Stopped 2013-05-09T19:59:28.552Z,1368129568.552 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-05-09T19:59:28.971Z,1368129568.971 [MissionManager](IMPORTANT): Started mission Default 2013-05-09T19:59:28.971Z,1368129568.971 [Default] Running Loop=1 2013-05-09T19:59:28.971Z,1368129568.971 [Default](INFO): Aggregate::initialize Default 2013-05-09T19:59:28.971Z,1368129568.971 [Default:D.SetSpeed] Running Loop=1 2013-05-09T19:59:28.971Z,1368129568.971 [Default:D.SetSpeed](DEBUG): Initialize. 2013-05-09T19:59:28.971Z,1368129568.971 [Default:E.GoToSurface] Running Loop=1 2013-05-09T19:59:28.971Z,1368129568.971 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-05-09T19:59:28.972Z,1368129568.972 [Default:Iridium] Running Loop=1 2013-05-09T19:59:28.972Z,1368129568.972 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2013-05-09T19:59:28.972Z,1368129568.972 [Default:Iridium:A.SetSpeed] Running Loop=1 2013-05-09T19:59:28.972Z,1368129568.972 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2013-05-09T19:59:28.972Z,1368129568.972 [Default:Iridium:B.GoToSurface] Running Loop=1 2013-05-09T19:59:28.972Z,1368129568.972 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-05-09T19:59:28.973Z,1368129568.973 [Default:E.GoToSurface] Running Loop=1 2013-05-09T19:59:28.978Z,1368129568.978 [Default:D.SetSpeed] Running Loop=1 2013-05-09T19:59:28.983Z,1368129568.983 [Default:CallIridium] Running Loop=1 2013-05-09T19:59:28.983Z,1368129568.983 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2013-05-09T19:59:28.983Z,1368129568.983 [Default:CallIridium:A] Running Loop=1 2013-05-09T19:59:28.985Z,1368129568.985 [Default:CallIridium:A] Stopped 2013-05-09T19:59:28.985Z,1368129568.985 [Default:CallIridium:B] Running Loop=1 2013-05-09T19:59:28.985Z,1368129568.985 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2013-05-09T19:59:28.990Z,1368129568.990 [Default:Iridium:B.GoToSurface] Stopped 2013-05-09T19:59:28.990Z,1368129568.990 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-05-09T19:59:28.990Z,1368129568.990 [Default:Iridium:Read_Iridium] Running Loop=1 2013-05-09T19:59:28.990Z,1368129568.990 [Default:Iridium:A.SetSpeed] Running Loop=1 2013-05-09T19:59:28.995Z,1368129568.995 [Default:GPS] Running Loop=1 2013-05-09T19:59:28.995Z,1368129568.995 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2013-05-09T19:59:28.995Z,1368129568.995 [Default:GPS:A.SetSpeed] Running Loop=1 2013-05-09T19:59:28.995Z,1368129568.995 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2013-05-09T19:59:28.995Z,1368129568.995 [Default:GPS:B.GoToSurface] Running Loop=1 2013-05-09T19:59:28.996Z,1368129568.996 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-05-09T19:59:29.001Z,1368129569.001 [Default:GPS:B.GoToSurface] Stopped 2013-05-09T19:59:29.001Z,1368129569.001 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-05-09T19:59:29.001Z,1368129569.001 [Default:GPS:Read_GPS] Running Loop=1 2013-05-09T19:59:29.001Z,1368129569.001 [Default:GPS:A.SetSpeed] Running Loop=1 2013-05-09T19:59:29.351Z,1368129569.351 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2013-05-09T19:59:29.354Z,1368129569.354 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2013-05-09T19:59:33.737Z,1368129573.737 [NAL9602](INFO): SBD MO Status=0, MOMSN=11741, MT Status=0, MTMSN=0 2013-05-09T19:59:37.294Z,1368129577.295 [Default:Iridium:Read_Iridium] Stopped 2013-05-09T19:59:37.295Z,1368129577.295 [Default:Iridium](INFO): Completed Default:Iridium 2013-05-09T19:59:37.295Z,1368129577.295 [Default:Iridium] Stopped 2013-05-09T19:59:37.295Z,1368129577.295 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2013-05-09T19:59:37.295Z,1368129577.295 [Default:Iridium:A.SetSpeed] Stopped 2013-05-09T19:59:37.295Z,1368129577.295 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2013-05-09T19:59:37.296Z,1368129577.296 [Default:F.Wait] Running Loop=1 2013-05-09T19:59:37.296Z,1368129577.296 [Default:F.Wait](DEBUG): Initialize Wait Component. 2013-05-09T19:59:37.665Z,1368129577.665 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2013-05-09T19:59:37.666Z,1368129577.666 [Default:CallIridium:B] Stopped 2013-05-09T19:59:37.666Z,1368129577.666 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2013-05-09T19:59:37.666Z,1368129577.666 [Default:CallIridium](INFO): Completed Default:CallIridium 2013-05-09T19:59:37.666Z,1368129577.666 [Default:CallIridium] Stopped 2013-05-09T19:59:37.666Z,1368129577.666 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2013-05-09T19:59:38.296Z,1368129578.296 [NAL9602](IMPORTANT): GPS fix at: 1368129698.00 2013-05-09T19:59:38.311Z,1368129578.311 [Default:GPS:Read_GPS] Stopped 2013-05-09T19:59:38.311Z,1368129578.311 [Default:GPS:D] Running Loop=1 2013-05-09T19:59:38.757Z,1368129578.757 [Default:GPS:D] Stopped 2013-05-09T19:59:38.757Z,1368129578.757 [Default:GPS](INFO): Completed Default:GPS 2013-05-09T19:59:38.757Z,1368129578.757 [Default:GPS] Stopped 2013-05-09T19:59:38.758Z,1368129578.758 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2013-05-09T19:59:38.758Z,1368129578.758 [Default:GPS:A.SetSpeed] Stopped 2013-05-09T19:59:38.758Z,1368129578.758 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2013-05-09T19:59:59.310Z,1368129599.310 [NAL9602](INFO): Powering down 2013-05-09T20:04:34.320Z,1368129874.320 [Default:CallIridium] Running Loop=1 2013-05-09T20:04:34.320Z,1368129874.320 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2013-05-09T20:04:34.320Z,1368129874.320 [Default:CallIridium:A] Running Loop=1 2013-05-09T20:04:34.321Z,1368129874.321 [Default:CallIridium:A] Stopped 2013-05-09T20:04:34.321Z,1368129874.321 [Default:CallIridium:B] Running Loop=1 2013-05-09T20:04:34.321Z,1368129874.321 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2013-05-09T20:04:39.249Z,1368129879.249 [Default:Iridium] Running Loop=1 2013-05-09T20:04:39.249Z,1368129879.249 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2013-05-09T20:04:39.249Z,1368129879.249 [Default:Iridium:A.SetSpeed] Running Loop=1 2013-05-09T20:04:39.249Z,1368129879.249 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2013-05-09T20:04:39.249Z,1368129879.249 [Default:Iridium:B.GoToSurface] Running Loop=1 2013-05-09T20:04:39.249Z,1368129879.249 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-05-09T20:04:39.250Z,1368129879.250 [Default:Iridium:B.GoToSurface] Stopped 2013-05-09T20:04:39.250Z,1368129879.250 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-05-09T20:04:39.250Z,1368129879.250 [Default:Iridium:Read_Iridium] Running Loop=1 2013-05-09T20:04:39.251Z,1368129879.251 [Default:GPS] Running Loop=1 2013-05-09T20:04:39.251Z,1368129879.251 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2013-05-09T20:04:39.251Z,1368129879.251 [Default:GPS:A.SetSpeed] Running Loop=1 2013-05-09T20:04:39.251Z,1368129879.251 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2013-05-09T20:04:39.251Z,1368129879.251 [Default:GPS:B.GoToSurface] Running Loop=1 2013-05-09T20:04:39.251Z,1368129879.251 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-05-09T20:04:39.252Z,1368129879.252 [Default:GPS:B.GoToSurface] Stopped 2013-05-09T20:04:39.252Z,1368129879.252 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-05-09T20:04:39.252Z,1368129879.253 [Default:GPS:Read_GPS] Running Loop=1 2013-05-09T20:04:39.893Z,1368129879.893 [NAL9602](INFO): Powering up 2013-05-09T20:04:50.328Z,1368129890.328 [NAL9602](INFO): NAL9602 initialized 2013-05-09T20:05:27.670Z,1368129927.671 [NAL9602](INFO): SBD MO Status=2, MOMSN=11742, MT Status=2, MTMSN=0 2013-05-09T20:05:27.671Z,1368129927.671 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-05-09T20:05:28.872Z,1368129928.872 [NAL9602](IMPORTANT): GPS fix at: 1368130049.00 2013-05-09T20:05:28.888Z,1368129928.888 [Default:GPS:Read_GPS] Stopped 2013-05-09T20:05:28.888Z,1368129928.888 [Default:GPS:D] Running Loop=1 2013-05-09T20:05:29.348Z,1368129929.348 [Default:GPS:D] Stopped 2013-05-09T20:05:29.349Z,1368129929.349 [Default:GPS](INFO): Completed Default:GPS 2013-05-09T20:05:29.349Z,1368129929.349 [Default:GPS] Stopped 2013-05-09T20:05:29.349Z,1368129929.349 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2013-05-09T20:05:29.349Z,1368129929.349 [Default:GPS:A.SetSpeed] Stopped 2013-05-09T20:05:29.349Z,1368129929.349 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2013-05-09T20:05:38.642Z,1368129938.642 [NAL9602](INFO): SBD MO Status=1, MOMSN=11742, MT Status=0, MTMSN=0 2013-05-09T20:05:38.692Z,1368129938.692 [NAL9602](INFO): Sent 188 bytes from file Logs/20130509T195626/shore0001.lzma 2013-05-09T20:05:38.692Z,1368129938.692 [NAL9602](INFO): Packets left to send: 0 2013-05-09T20:05:38.694Z,1368129938.694 [NAL9602](INFO): Stored copy of sent data in Logs/20130509T195626/shore0001.lzma.parts/0000.sbd 2013-05-09T20:05:51.502Z,1368129951.503 [NAL9602](INFO): SBD MO Status=0, MOMSN=11743, MT Status=0, MTMSN=0 2013-05-09T20:05:55.044Z,1368129955.044 [Default:Iridium:Read_Iridium] Stopped 2013-05-09T20:05:55.045Z,1368129955.045 [Default:Iridium](INFO): Completed Default:Iridium 2013-05-09T20:05:55.045Z,1368129955.045 [Default:Iridium] Stopped 2013-05-09T20:05:55.045Z,1368129955.045 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2013-05-09T20:05:55.045Z,1368129955.045 [Default:Iridium:A.SetSpeed] Stopped 2013-05-09T20:05:55.045Z,1368129955.045 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2013-05-09T20:05:55.381Z,1368129955.381 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2013-05-09T20:05:55.381Z,1368129955.381 [Default:CallIridium:B] Stopped 2013-05-09T20:05:55.381Z,1368129955.381 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2013-05-09T20:05:55.381Z,1368129955.381 [Default:CallIridium](INFO): Completed Default:CallIridium 2013-05-09T20:05:55.381Z,1368129955.381 [Default:CallIridium] Stopped 2013-05-09T20:05:55.381Z,1368129955.381 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2013-05-09T20:06:05.454Z,1368129965.454 [NAL9602](INFO): Powering down 2013-05-09T20:10:55.435Z,1368130255.435 [Default:CallIridium] Running Loop=1 2013-05-09T20:10:55.435Z,1368130255.435 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2013-05-09T20:10:55.435Z,1368130255.435 [Default:CallIridium:A] Running Loop=1 2013-05-09T20:10:55.436Z,1368130255.436 [Default:CallIridium:A] Stopped 2013-05-09T20:10:55.436Z,1368130255.436 [Default:CallIridium:B] Running Loop=1 2013-05-09T20:10:55.436Z,1368130255.436 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2013-05-09T20:11:00.412Z,1368130260.412 [Default:Iridium] Running Loop=1 2013-05-09T20:11:00.412Z,1368130260.412 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2013-05-09T20:11:00.412Z,1368130260.412 [Default:Iridium:A.SetSpeed] Running Loop=1 2013-05-09T20:11:00.412Z,1368130260.412 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2013-05-09T20:11:00.413Z,1368130260.413 [Default:Iridium:B.GoToSurface] Running Loop=1 2013-05-09T20:11:00.413Z,1368130260.413 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-05-09T20:11:00.413Z,1368130260.413 [Default:Iridium:B.GoToSurface] Stopped 2013-05-09T20:11:00.414Z,1368130260.414 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-05-09T20:11:00.414Z,1368130260.414 [Default:Iridium:Read_Iridium] Running Loop=1 2013-05-09T20:11:00.414Z,1368130260.414 [Default:GPS] Running Loop=1 2013-05-09T20:11:00.414Z,1368130260.414 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2013-05-09T20:11:00.414Z,1368130260.414 [Default:GPS:A.SetSpeed] Running Loop=1 2013-05-09T20:11:00.414Z,1368130260.414 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2013-05-09T20:11:00.414Z,1368130260.414 [Default:GPS:B.GoToSurface] Running Loop=1 2013-05-09T20:11:00.415Z,1368130260.415 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-05-09T20:11:00.415Z,1368130260.415 [Default:GPS:B.GoToSurface] Stopped 2013-05-09T20:11:00.415Z,1368130260.415 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-05-09T20:11:00.416Z,1368130260.416 [Default:GPS:Read_GPS] Running Loop=1 2013-05-09T20:11:01.041Z,1368130261.041 [NAL9602](INFO): Powering up 2013-05-09T20:11:11.472Z,1368130271.472 [NAL9602](INFO): NAL9602 initialized 2013-05-09T20:11:29.211Z,1368130289.211 [NAL9602](INFO): SBD MO Status=1, MOMSN=11744, MT Status=0, MTMSN=0 2013-05-09T20:11:29.264Z,1368130289.264 [NAL9602](INFO): Sent 152 bytes from file Logs/20130509T195626/shore0002.lzma 2013-05-09T20:11:29.265Z,1368130289.265 [NAL9602](INFO): Packets left to send: 0 2013-05-09T20:11:29.270Z,1368130289.270 [NAL9602](INFO): Stored copy of sent data in Logs/20130509T195626/shore0002.lzma.parts/0000.sbd 2013-05-09T20:11:38.014Z,1368130298.014 [NAL9602](INFO): SBD MO Status=0, MOMSN=11745, MT Status=0, MTMSN=0 2013-05-09T20:11:41.790Z,1368130301.790 [Default:Iridium:Read_Iridium] Stopped 2013-05-09T20:11:41.791Z,1368130301.791 [Default:Iridium](INFO): Completed Default:Iridium 2013-05-09T20:11:41.791Z,1368130301.791 [Default:Iridium] Stopped 2013-05-09T20:11:41.791Z,1368130301.791 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2013-05-09T20:11:41.791Z,1368130301.791 [Default:Iridium:A.SetSpeed] Stopped 2013-05-09T20:11:41.791Z,1368130301.791 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2013-05-09T20:11:42.181Z,1368130302.181 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2013-05-09T20:11:42.181Z,1368130302.181 [Default:CallIridium:B] Stopped 2013-05-09T20:11:42.181Z,1368130302.181 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2013-05-09T20:11:42.181Z,1368130302.181 [Default:CallIridium](INFO): Completed Default:CallIridium 2013-05-09T20:11:42.181Z,1368130302.181 [Default:CallIridium] Stopped 2013-05-09T20:11:42.181Z,1368130302.181 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2013-05-09T20:11:42.788Z,1368130302.788 [NAL9602](IMPORTANT): GPS fix at: 1368130423.00 2013-05-09T20:11:42.803Z,1368130302.803 [Default:GPS:Read_GPS] Stopped 2013-05-09T20:11:42.803Z,1368130302.803 [Default:GPS:D] Running Loop=1 2013-05-09T20:11:43.225Z,1368130303.225 [Default:GPS:D] Stopped 2013-05-09T20:11:43.225Z,1368130303.225 [Default:GPS](INFO): Completed Default:GPS 2013-05-09T20:11:43.225Z,1368130303.225 [Default:GPS] Stopped 2013-05-09T20:11:43.225Z,1368130303.225 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2013-05-09T20:11:43.225Z,1368130303.225 [Default:GPS:A.SetSpeed] Stopped 2013-05-09T20:11:43.226Z,1368130303.226 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2013-05-09T20:12:03.773Z,1368130323.773 [NAL9602](INFO): Powering down 2013-05-09T20:16:38.778Z,1368130598.778 [Default:CallIridium] Running Loop=1 2013-05-09T20:16:38.778Z,1368130598.778 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2013-05-09T20:16:38.778Z,1368130598.778 [Default:CallIridium:A] Running Loop=1 2013-05-09T20:16:38.779Z,1368130598.779 [Default:CallIridium:A] Stopped 2013-05-09T20:16:38.779Z,1368130598.779 [Default:CallIridium:B] Running Loop=1 2013-05-09T20:16:38.779Z,1368130598.779 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2013-05-09T20:16:43.786Z,1368130603.786 [Default:Iridium] Running Loop=1 2013-05-09T20:16:43.786Z,1368130603.786 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2013-05-09T20:16:43.786Z,1368130603.786 [Default:Iridium:A.SetSpeed] Running Loop=1 2013-05-09T20:16:43.786Z,1368130603.786 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2013-05-09T20:16:43.787Z,1368130603.787 [Default:Iridium:B.GoToSurface] Running Loop=1 2013-05-09T20:16:43.787Z,1368130603.787 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-05-09T20:16:43.788Z,1368130603.788 [Default:Iridium:B.GoToSurface] Stopped 2013-05-09T20:16:43.788Z,1368130603.788 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-05-09T20:16:43.788Z,1368130603.788 [Default:Iridium:Read_Iridium] Running Loop=1 2013-05-09T20:16:43.788Z,1368130603.788 [Default:GPS] Running Loop=1 2013-05-09T20:16:43.788Z,1368130603.788 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2013-05-09T20:16:43.789Z,1368130603.789 [Default:GPS:A.SetSpeed] Running Loop=1 2013-05-09T20:16:43.789Z,1368130603.789 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2013-05-09T20:16:43.789Z,1368130603.789 [Default:GPS:B.GoToSurface] Running Loop=1 2013-05-09T20:16:43.789Z,1368130603.789 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-05-09T20:16:43.790Z,1368130603.790 [Default:GPS:B.GoToSurface] Stopped 2013-05-09T20:16:43.790Z,1368130603.790 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-05-09T20:16:43.790Z,1368130603.790 [Default:GPS:Read_GPS] Running Loop=1 2013-05-09T20:16:44.380Z,1368130604.380 [NAL9602](INFO): Powering up 2013-05-09T20:16:54.820Z,1368130614.820 [NAL9602](INFO): NAL9602 initialized 2013-05-09T20:17:12.583Z,1368130632.583 [NAL9602](INFO): SBD MO Status=1, MOMSN=11746, MT Status=0, MTMSN=0 2013-05-09T20:17:12.632Z,1368130632.632 [NAL9602](INFO): Sent 265 bytes from file Logs/20130509T195626/shore0003.lzma 2013-05-09T20:17:12.632Z,1368130632.632 [NAL9602](INFO): Packets left to send: 0 2013-05-09T20:17:12.634Z,1368130632.634 [NAL9602](INFO): Stored copy of sent data in Logs/20130509T195626/shore0003.lzma.parts/0000.sbd 2013-05-09T20:17:25.354Z,1368130645.354 [NAL9602](INFO): SBD MO Status=0, MOMSN=11747, MT Status=0, MTMSN=0 2013-05-09T20:17:28.893Z,1368130648.893 [Default:Iridium:Read_Iridium] Stopped 2013-05-09T20:17:28.894Z,1368130648.894 [Default:Iridium](INFO): Completed Default:Iridium 2013-05-09T20:17:28.894Z,1368130648.894 [Default:Iridium] Stopped 2013-05-09T20:17:28.894Z,1368130648.894 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2013-05-09T20:17:28.894Z,1368130648.894 [Default:Iridium:A.SetSpeed] Stopped 2013-05-09T20:17:28.894Z,1368130648.894 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2013-05-09T20:17:29.283Z,1368130649.283 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2013-05-09T20:17:29.283Z,1368130649.283 [Default:CallIridium:B] Stopped 2013-05-09T20:17:29.283Z,1368130649.283 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2013-05-09T20:17:29.283Z,1368130649.283 [Default:CallIridium](INFO): Completed Default:CallIridium 2013-05-09T20:17:29.283Z,1368130649.283 [Default:CallIridium] Stopped 2013-05-09T20:17:29.284Z,1368130649.284 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2013-05-09T20:17:29.896Z,1368130649.896 [NAL9602](IMPORTANT): GPS fix at: 1368130771.00 2013-05-09T20:17:29.911Z,1368130649.911 [Default:GPS:Read_GPS] Stopped 2013-05-09T20:17:29.911Z,1368130649.911 [Default:GPS:D] Running Loop=1 2013-05-09T20:17:30.315Z,1368130650.315 [Default:GPS:D] Stopped 2013-05-09T20:17:30.315Z,1368130650.315 [Default:GPS](INFO): Completed Default:GPS 2013-05-09T20:17:30.315Z,1368130650.315 [Default:GPS] Stopped 2013-05-09T20:17:30.315Z,1368130650.315 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2013-05-09T20:17:30.315Z,1368130650.315 [Default:GPS:A.SetSpeed] Stopped 2013-05-09T20:17:30.316Z,1368130650.316 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2013-05-09T20:17:50.890Z,1368130670.890 [NAL9602](INFO): Powering down 2013-05-09T20:22:25.872Z,1368130945.872 [Default:CallIridium] Running Loop=1 2013-05-09T20:22:25.872Z,1368130945.872 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2013-05-09T20:22:25.872Z,1368130945.872 [Default:CallIridium:A] Running Loop=1 2013-05-09T20:22:25.873Z,1368130945.873 [Default:CallIridium:A] Stopped 2013-05-09T20:22:25.873Z,1368130945.873 [Default:CallIridium:B] Running Loop=1 2013-05-09T20:22:25.873Z,1368130945.873 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2013-05-09T20:22:30.852Z,1368130950.852 [Default:Iridium] Running Loop=1 2013-05-09T20:22:30.852Z,1368130950.852 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2013-05-09T20:22:30.852Z,1368130950.852 [Default:Iridium:A.SetSpeed] Running Loop=1 2013-05-09T20:22:30.853Z,1368130950.852 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2013-05-09T20:22:30.853Z,1368130950.853 [Default:Iridium:B.GoToSurface] Running Loop=1 2013-05-09T20:22:30.853Z,1368130950.853 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-05-09T20:22:30.854Z,1368130950.853 [Default:Iridium:B.GoToSurface] Stopped 2013-05-09T20:22:30.854Z,1368130950.854 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-05-09T20:22:30.854Z,1368130950.854 [Default:Iridium:Read_Iridium] Running Loop=1 2013-05-09T20:22:30.854Z,1368130950.854 [Default:GPS] Running Loop=1 2013-05-09T20:22:30.854Z,1368130950.854 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2013-05-09T20:22:30.854Z,1368130950.854 [Default:GPS:A.SetSpeed] Running Loop=1 2013-05-09T20:22:30.854Z,1368130950.854 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2013-05-09T20:22:30.855Z,1368130950.855 [Default:GPS:B.GoToSurface] Running Loop=1 2013-05-09T20:22:30.855Z,1368130950.855 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-05-09T20:22:30.872Z,1368130950.872 [Default:GPS:B.GoToSurface] Stopped 2013-05-09T20:22:30.872Z,1368130950.872 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-05-09T20:22:30.872Z,1368130950.872 [Default:GPS:Read_GPS] Running Loop=1 2013-05-09T20:22:31.517Z,1368130951.517 [NAL9602](INFO): Powering up 2013-05-09T20:22:41.964Z,1368130961.964 [NAL9602](INFO): NAL9602 initialized 2013-05-09T20:23:08.134Z,1368130988.134 [NAL9602](INFO): SBD MO Status=1, MOMSN=11748, MT Status=0, MTMSN=0 2013-05-09T20:23:08.188Z,1368130988.188 [NAL9602](INFO): Sent 139 bytes from file Logs/20130509T195626/shore0004.lzma 2013-05-09T20:23:08.188Z,1368130988.188 [NAL9602](INFO): Packets left to send: 0 2013-05-09T20:23:08.190Z,1368130988.190 [NAL9602](INFO): Stored copy of sent data in Logs/20130509T195626/shore0004.lzma.parts/0000.sbd 2013-05-09T20:24:13.786Z,1368131053.786 [NAL9602](ERROR): Verify xmit timeout failure. 2013-05-09T20:24:30.129Z,1368131070.129 [NAL9602](INFO): SBD MO Status=2, MOMSN=11749, MT Status=2, MTMSN=0 2013-05-09T20:24:30.130Z,1368131070.130 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-05-09T20:24:31.341Z,1368131071.341 [NAL9602](IMPORTANT): GPS fix at: 1368131193.00 2013-05-09T20:24:31.373Z,1368131071.374 [Default:GPS:Read_GPS] Stopped 2013-05-09T20:24:31.374Z,1368131071.374 [Default:GPS:D] Running Loop=1 2013-05-09T20:24:31.774Z,1368131071.773 [Default:GPS:D] Stopped 2013-05-09T20:24:31.774Z,1368131071.774 [Default:GPS](INFO): Completed Default:GPS 2013-05-09T20:24:31.774Z,1368131071.774 [Default:GPS] Stopped 2013-05-09T20:24:31.774Z,1368131071.774 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2013-05-09T20:24:31.774Z,1368131071.774 [Default:GPS:A.SetSpeed] Stopped 2013-05-09T20:24:31.774Z,1368131071.774 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2013-05-09T20:24:47.261Z,1368131087.261 [NAL9602](INFO): SBD MO Status=2, MOMSN=11749, MT Status=2, MTMSN=0 2013-05-09T20:24:47.261Z,1368131087.261 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-05-09T20:24:57.175Z,1368131097.174 [NAL9602](INFO): SBD MO Status=0, MOMSN=11749, MT Status=0, MTMSN=0 2013-05-09T20:25:00.738Z,1368131100.737 [Default:Iridium:Read_Iridium] Stopped 2013-05-09T20:25:00.738Z,1368131100.738 [Default:Iridium](INFO): Completed Default:Iridium 2013-05-09T20:25:00.738Z,1368131100.738 [Default:Iridium] Stopped 2013-05-09T20:25:00.738Z,1368131100.738 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2013-05-09T20:25:00.738Z,1368131100.738 [Default:Iridium:A.SetSpeed] Stopped 2013-05-09T20:25:00.738Z,1368131100.738 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2013-05-09T20:25:01.112Z,1368131101.112 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2013-05-09T20:25:01.112Z,1368131101.112 [Default:CallIridium:B] Stopped 2013-05-09T20:25:01.113Z,1368131101.113 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2013-05-09T20:25:01.113Z,1368131101.113 [Default:CallIridium](INFO): Completed Default:CallIridium 2013-05-09T20:25:01.113Z,1368131101.113 [Default:CallIridium] Stopped 2013-05-09T20:25:01.113Z,1368131101.113 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2013-05-09T20:25:11.114Z,1368131111.114 [NAL9602](INFO): Powering down 2013-05-09T20:28:41.095Z,1368131321.095 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2013-05-09T20:28:46.099Z,1368131326.099 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2013-05-09T20:28:51.102Z,1368131331.102 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2013-05-09T20:28:56.099Z,1368131336.099 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2013-05-09T20:30:01.119Z,1368131401.119 [Default:CallIridium] Running Loop=1 2013-05-09T20:30:01.119Z,1368131401.119 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2013-05-09T20:30:01.119Z,1368131401.119 [Default:CallIridium:A] Running Loop=1 2013-05-09T20:30:01.120Z,1368131401.120 [Default:CallIridium:A] Stopped 2013-05-09T20:30:01.120Z,1368131401.120 [Default:CallIridium:B] Running Loop=1 2013-05-09T20:30:01.120Z,1368131401.120 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2013-05-09T20:30:06.123Z,1368131406.122 [Default:Iridium] Running Loop=1 2013-05-09T20:30:06.123Z,1368131406.123 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2013-05-09T20:30:06.123Z,1368131406.123 [Default:Iridium:A.SetSpeed] Running Loop=1 2013-05-09T20:30:06.123Z,1368131406.123 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2013-05-09T20:30:06.123Z,1368131406.123 [Default:Iridium:B.GoToSurface] Running Loop=1 2013-05-09T20:30:06.123Z,1368131406.123 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-05-09T20:30:06.124Z,1368131406.124 [Default:Iridium:B.GoToSurface] Stopped 2013-05-09T20:30:06.124Z,1368131406.124 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-05-09T20:30:06.124Z,1368131406.124 [Default:Iridium:Read_Iridium] Running Loop=1 2013-05-09T20:30:06.125Z,1368131406.125 [Default:GPS] Running Loop=1 2013-05-09T20:30:06.125Z,1368131406.125 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2013-05-09T20:30:06.125Z,1368131406.125 [Default:GPS:A.SetSpeed] Running Loop=1 2013-05-09T20:30:06.125Z,1368131406.125 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2013-05-09T20:30:06.125Z,1368131406.125 [Default:GPS:B.GoToSurface] Running Loop=1 2013-05-09T20:30:06.125Z,1368131406.125 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-05-09T20:30:06.126Z,1368131406.126 [Default:GPS:B.GoToSurface] Stopped 2013-05-09T20:30:06.126Z,1368131406.126 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-05-09T20:30:06.126Z,1368131406.126 [Default:GPS:Read_GPS] Running Loop=1 2013-05-09T20:30:06.737Z,1368131406.737 [NAL9602](INFO): Powering up 2013-05-09T20:30:17.624Z,1368131417.624 [NAL9602](INFO): NAL9602 initialized 2013-05-09T20:30:40.903Z,1368131440.903 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=11750, MT Status=1, MTMSN=856 2013-05-09T20:30:40.952Z,1368131440.952 [NAL9602](INFO): Sent 166 bytes from file Logs/20130509T195626/shore0005.lzma 2013-05-09T20:30:40.952Z,1368131440.952 [NAL9602](INFO): Packets left to send: 0 2013-05-09T20:30:40.954Z,1368131440.954 [NAL9602](INFO): Stored copy of sent data in Logs/20130509T195626/shore0005.lzma.parts/0000.sbd 2013-05-09T20:30:41.639Z,1368131441.639 [NAL9602](IMPORTANT): Initialized file: Data/HFRadarModel/2013050919 2013-05-09T20:30:41.738Z,1368131441.738 [NAL9602](IMPORTANT): Success executing cat Logs/latest/518C0750.part > Data/HFRadarModel/2013050919 2013-05-09T20:30:41.812Z,1368131441.812 [CommandLine](IMPORTANT): 533fd36f04f84b4052b90c54b232cbba Data/HFRadarModel/2013050919 2013-05-09T20:30:42.840Z,1368131442.840 [NAL9602](IMPORTANT): GPS fix at: 1368131565.00 2013-05-09T20:30:42.874Z,1368131442.874 [Default:GPS:Read_GPS] Stopped 2013-05-09T20:30:42.874Z,1368131442.874 [Default:GPS:D] Running Loop=1 2013-05-09T20:30:43.325Z,1368131443.325 [Default:GPS:D] Stopped 2013-05-09T20:30:43.326Z,1368131443.326 [Default:GPS](INFO): Completed Default:GPS 2013-05-09T20:30:43.326Z,1368131443.326 [Default:GPS] Stopped 2013-05-09T20:30:43.326Z,1368131443.326 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2013-05-09T20:30:43.326Z,1368131443.326 [Default:GPS:A.SetSpeed] Stopped 2013-05-09T20:30:43.326Z,1368131443.326 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2013-05-09T20:31:01.978Z,1368131461.978 [NAL9602](INFO): SBD MO Status=0, MOMSN=11751, MT Status=0, MTMSN=0 2013-05-09T20:31:24.531Z,1368131484.531 [NAL9602](INFO): SBD MO Status=1, MOMSN=11752, MT Status=0, MTMSN=0 2013-05-09T20:31:24.580Z,1368131484.580 [NAL9602](INFO): Sent 332 bytes from file Logs/20130509T195626/shore0006.lzma 2013-05-09T20:31:24.580Z,1368131484.580 [NAL9602](INFO): Packets left to send: 1 2013-05-09T20:31:24.582Z,1368131484.582 [NAL9602](INFO): Stored copy of sent data in Logs/20130509T195626/shore0006.lzma.parts/0001.sbd 2013-05-09T20:31:36.370Z,1368131496.370 [NAL9602](INFO): SBD MO Status=1, MOMSN=11753, MT Status=0, MTMSN=0 2013-05-09T20:31:36.420Z,1368131496.420 [NAL9602](INFO): Sent 23 bytes from file Logs/20130509T195626/shore0006.lzma 2013-05-09T20:31:36.420Z,1368131496.420 [NAL9602](INFO): Packets left to send: 0 2013-05-09T20:31:36.421Z,1368131496.421 [NAL9602](INFO): Stored copy of sent data in Logs/20130509T195626/shore0006.lzma.parts/0000.sbd 2013-05-09T20:31:47.199Z,1368131507.199 [NAL9602](INFO): SBD MO Status=0, MOMSN=11754, MT Status=0, MTMSN=0 2013-05-09T20:31:50.936Z,1368131510.936 [Default:Iridium:Read_Iridium] Stopped 2013-05-09T20:31:50.937Z,1368131510.937 [Default:Iridium](INFO): Completed Default:Iridium 2013-05-09T20:31:50.937Z,1368131510.937 [Default:Iridium] Stopped 2013-05-09T20:31:50.937Z,1368131510.937 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2013-05-09T20:31:50.937Z,1368131510.937 [Default:Iridium:A.SetSpeed] Stopped 2013-05-09T20:31:50.937Z,1368131510.937 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2013-05-09T20:31:51.309Z,1368131511.309 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2013-05-09T20:31:51.309Z,1368131511.309 [Default:CallIridium:B] Stopped 2013-05-09T20:31:51.310Z,1368131511.309 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2013-05-09T20:31:51.310Z,1368131511.310 [Default:CallIridium](INFO): Completed Default:CallIridium 2013-05-09T20:31:51.310Z,1368131511.310 [Default:CallIridium] Stopped 2013-05-09T20:31:51.310Z,1368131511.310 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2013-05-09T20:32:01.282Z,1368131521.282 [NAL9602](INFO): Powering down 2013-05-09T20:36:51.284Z,1368131811.284 [Default:CallIridium] Running Loop=1 2013-05-09T20:36:51.284Z,1368131811.284 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2013-05-09T20:36:51.284Z,1368131811.284 [Default:CallIridium:A] Running Loop=1 2013-05-09T20:36:51.284Z,1368131811.284 [Default:CallIridium:A] Stopped 2013-05-09T20:36:51.285Z,1368131811.284 [Default:CallIridium:B] Running Loop=1 2013-05-09T20:36:51.285Z,1368131811.285 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2013-05-09T20:36:56.312Z,1368131816.312 [Default:Iridium] Running Loop=1 2013-05-09T20:36:56.312Z,1368131816.312 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2013-05-09T20:36:56.312Z,1368131816.312 [Default:Iridium:A.SetSpeed] Running Loop=1 2013-05-09T20:36:56.312Z,1368131816.312 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2013-05-09T20:36:56.312Z,1368131816.312 [Default:Iridium:B.GoToSurface] Running Loop=1 2013-05-09T20:36:56.312Z,1368131816.312 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-05-09T20:36:56.313Z,1368131816.313 [Default:Iridium:B.GoToSurface] Stopped 2013-05-09T20:36:56.313Z,1368131816.313 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-05-09T20:36:56.313Z,1368131816.313 [Default:Iridium:Read_Iridium] Running Loop=1 2013-05-09T20:36:56.314Z,1368131816.314 [Default:GPS] Running Loop=1 2013-05-09T20:36:56.314Z,1368131816.314 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2013-05-09T20:36:56.314Z,1368131816.314 [Default:GPS:A.SetSpeed] Running Loop=1 2013-05-09T20:36:56.314Z,1368131816.314 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2013-05-09T20:36:56.314Z,1368131816.314 [Default:GPS:B.GoToSurface] Running Loop=1 2013-05-09T20:36:56.314Z,1368131816.314 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-05-09T20:36:56.315Z,1368131816.315 [Default:GPS:B.GoToSurface] Stopped 2013-05-09T20:36:56.315Z,1368131816.315 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-05-09T20:36:56.315Z,1368131816.315 [Default:GPS:Read_GPS] Running Loop=1 2013-05-09T20:36:57.005Z,1368131817.006 [NAL9602](INFO): Powering up 2013-05-09T20:37:07.766Z,1368131827.766 [NAL9602](INFO): NAL9602 initialized 2013-05-09T20:37:41.547Z,1368131861.547 [NAL9602](INFO): SBD MO Status=2, MOMSN=11755, MT Status=2, MTMSN=0 2013-05-09T20:37:41.547Z,1368131861.547 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-05-09T20:37:54.055Z,1368131874.055 [NAL9602](INFO): SBD MO Status=1, MOMSN=11755, MT Status=0, MTMSN=0 2013-05-09T20:37:54.104Z,1368131874.104 [NAL9602](INFO): Sent 105 bytes from file Logs/20130509T195626/shore0007.lzma 2013-05-09T20:37:54.104Z,1368131874.104 [NAL9602](INFO): Packets left to send: 0 2013-05-09T20:37:54.106Z,1368131874.106 [NAL9602](INFO): Stored copy of sent data in Logs/20130509T195626/shore0007.lzma.parts/0000.sbd 2013-05-09T20:38:04.861Z,1368131884.861 [NAL9602](INFO): SBD MO Status=0, MOMSN=11756, MT Status=0, MTMSN=0 2013-05-09T20:38:08.414Z,1368131888.414 [Default:Iridium:Read_Iridium] Stopped 2013-05-09T20:38:08.414Z,1368131888.414 [Default:Iridium](INFO): Completed Default:Iridium 2013-05-09T20:38:08.414Z,1368131888.414 [Default:Iridium] Stopped 2013-05-09T20:38:08.415Z,1368131888.415 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2013-05-09T20:38:08.415Z,1368131888.415 [Default:Iridium:A.SetSpeed] Stopped 2013-05-09T20:38:08.415Z,1368131888.415 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2013-05-09T20:38:08.787Z,1368131888.787 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2013-05-09T20:38:08.787Z,1368131888.787 [Default:CallIridium:B] Stopped 2013-05-09T20:38:08.788Z,1368131888.787 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2013-05-09T20:38:08.788Z,1368131888.788 [Default:CallIridium](INFO): Completed Default:CallIridium 2013-05-09T20:38:08.788Z,1368131888.788 [Default:CallIridium] Stopped 2013-05-09T20:38:08.788Z,1368131888.788 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2013-05-09T20:38:23.870Z,1368131903.870 [NAL9602](IMPORTANT): GPS fix at: 1368132027.00 2013-05-09T20:38:23.885Z,1368131903.885 [Default:GPS:Read_GPS] Stopped 2013-05-09T20:38:23.885Z,1368131903.885 [Default:GPS:D] Running Loop=1 2013-05-09T20:38:24.284Z,1368131904.284 [Default:GPS:D] Stopped 2013-05-09T20:38:24.284Z,1368131904.284 [Default:GPS](INFO): Completed Default:GPS 2013-05-09T20:38:24.285Z,1368131904.284 [Default:GPS] Stopped 2013-05-09T20:38:24.285Z,1368131904.285 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2013-05-09T20:38:24.285Z,1368131904.285 [Default:GPS:A.SetSpeed] Stopped 2013-05-09T20:38:24.285Z,1368131904.285 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2013-05-09T20:38:44.821Z,1368131924.821 [Depth_Keller](ERROR): Pressure reading out of range: 1830.660889 decibar 2013-05-09T20:38:44.822Z,1368131924.822 [NAL9602](INFO): Powering down 2013-05-09T20:38:59.809Z,1368131939.809 [Depth_Keller](ERROR): Pressure reading out of range: 1830.686279 decibar 2013-05-09T20:39:19.768Z,1368131959.768 [Depth_Keller](ERROR): Pressure reading out of range: 1830.682739 decibar 2013-05-09T20:39:29.769Z,1368131969.769 [Depth_Keller](ERROR): Pressure reading out of range: 1830.653076 decibar 2013-05-09T20:39:59.785Z,1368131999.785 [Depth_Keller](ERROR): Pressure reading out of range: 1830.646118 decibar 2013-05-09T20:40:19.785Z,1368132019.785 [Depth_Keller](ERROR): Pressure reading out of range: 1830.652344 decibar 2013-05-09T20:40:29.773Z,1368132029.773 [Depth_Keller](ERROR): Pressure reading out of range: 1830.681030 decibar 2013-05-09T20:40:39.774Z,1368132039.774 [Depth_Keller](ERROR): Pressure reading out of range: 1830.654907 decibar 2013-05-09T20:40:49.772Z,1368132049.772 [Depth_Keller](ERROR): Pressure reading out of range: 1830.660156 decibar 2013-05-09T20:40:59.792Z,1368132059.792 [Depth_Keller](ERROR): Pressure reading out of range: 1830.648804 decibar 2013-05-09T20:41:29.789Z,1368132089.789 [Depth_Keller](ERROR): Pressure reading out of range: 1830.705444 decibar 2013-05-09T20:42:39.773Z,1368132159.773 [Depth_Keller](ERROR): Pressure reading out of range: 1830.699341 decibar 2013-05-09T20:42:49.772Z,1368132169.772 [Depth_Keller](ERROR): Pressure reading out of range: 1830.653076 decibar 2013-05-09T20:43:09.777Z,1368132189.777 [Default:CallIridium] Running Loop=1 2013-05-09T20:43:09.777Z,1368132189.777 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2013-05-09T20:43:09.777Z,1368132189.777 [Default:CallIridium:A] Running Loop=1 2013-05-09T20:43:09.778Z,1368132189.778 [Default:CallIridium:A] Stopped 2013-05-09T20:43:09.778Z,1368132189.778 [Default:CallIridium:B] Running Loop=1 2013-05-09T20:43:09.778Z,1368132189.778 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2013-05-09T20:43:14.804Z,1368132194.804 [Default:Iridium] Running Loop=1 2013-05-09T20:43:14.804Z,1368132194.804 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2013-05-09T20:43:14.804Z,1368132194.804 [Default:Iridium:A.SetSpeed] Running Loop=1 2013-05-09T20:43:14.804Z,1368132194.804 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2013-05-09T20:43:14.804Z,1368132194.804 [Default:Iridium:B.GoToSurface] Running Loop=1 2013-05-09T20:43:14.804Z,1368132194.804 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-05-09T20:43:14.805Z,1368132194.805 [Default:Iridium:B.GoToSurface] Stopped 2013-05-09T20:43:14.805Z,1368132194.805 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-05-09T20:43:14.805Z,1368132194.805 [Default:Iridium:Read_Iridium] Running Loop=1 2013-05-09T20:43:14.806Z,1368132194.806 [Default:GPS] Running Loop=1 2013-05-09T20:43:14.806Z,1368132194.806 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2013-05-09T20:43:14.806Z,1368132194.806 [Default:GPS:A.SetSpeed] Running Loop=1 2013-05-09T20:43:14.806Z,1368132194.806 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2013-05-09T20:43:14.806Z,1368132194.806 [Default:GPS:B.GoToSurface] Running Loop=1 2013-05-09T20:43:14.806Z,1368132194.806 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-05-09T20:43:14.807Z,1368132194.807 [Default:GPS:B.GoToSurface] Stopped 2013-05-09T20:43:14.807Z,1368132194.807 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-05-09T20:43:14.807Z,1368132194.807 [Default:GPS:Read_GPS] Running Loop=1 2013-05-09T20:43:15.449Z,1368132195.449 [NAL9602](INFO): Powering up 2013-05-09T20:43:26.252Z,1368132206.252 [NAL9602](INFO): NAL9602 initialized 2013-05-09T20:43:44.779Z,1368132224.779 [NAL9602](INFO): SBD MO Status=1, MOMSN=11757, MT Status=0, MTMSN=0 2013-05-09T20:43:44.828Z,1368132224.828 [NAL9602](INFO): Sent 155 bytes from file Logs/20130509T195626/shore0008.lzma 2013-05-09T20:43:44.828Z,1368132224.828 [NAL9602](INFO): Packets left to send: 0 2013-05-09T20:43:44.830Z,1368132224.830 [NAL9602](INFO): Stored copy of sent data in Logs/20130509T195626/shore0008.lzma.parts/0000.sbd 2013-05-09T20:44:03.170Z,1368132243.171 [NAL9602](INFO): SBD MO Status=2, MOMSN=11758, MT Status=2, MTMSN=0 2013-05-09T20:44:03.171Z,1368132243.171 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-05-09T20:44:08.318Z,1368132248.318 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-05-09T20:44:29.814Z,1368132269.814 [NAL9602](INFO): SBD MO Status=0, MOMSN=11758, MT Status=0, MTMSN=0 2013-05-09T20:44:33.562Z,1368132273.562 [Default:Iridium:Read_Iridium] Stopped 2013-05-09T20:44:33.562Z,1368132273.562 [Default:Iridium](INFO): Completed Default:Iridium 2013-05-09T20:44:33.562Z,1368132273.562 [Default:Iridium] Stopped 2013-05-09T20:44:33.563Z,1368132273.563 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2013-05-09T20:44:33.563Z,1368132273.563 [Default:Iridium:A.SetSpeed] Stopped 2013-05-09T20:44:33.563Z,1368132273.563 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2013-05-09T20:44:33.925Z,1368132273.925 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2013-05-09T20:44:33.925Z,1368132273.925 [Default:CallIridium:B] Stopped 2013-05-09T20:44:33.925Z,1368132273.925 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2013-05-09T20:44:33.925Z,1368132273.925 [Default:CallIridium](INFO): Completed Default:CallIridium 2013-05-09T20:44:33.925Z,1368132273.925 [Default:CallIridium] Stopped 2013-05-09T20:44:33.925Z,1368132273.925 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2013-05-09T20:44:48.969Z,1368132288.969 [NAL9602](IMPORTANT): GPS fix at: 1368132413.00 2013-05-09T20:44:49.051Z,1368132289.051 [Default:GPS:Read_GPS] Stopped 2013-05-09T20:44:49.051Z,1368132289.051 [Default:GPS:D] Running Loop=1 2013-05-09T20:44:49.391Z,1368132289.391 [Default:GPS:D] Stopped 2013-05-09T20:44:49.391Z,1368132289.391 [Default:GPS](INFO): Completed Default:GPS 2013-05-09T20:44:49.391Z,1368132289.391 [Default:GPS] Stopped 2013-05-09T20:44:49.391Z,1368132289.391 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2013-05-09T20:44:49.392Z,1368132289.392 [Default:GPS:A.SetSpeed] Stopped 2013-05-09T20:44:49.392Z,1368132289.392 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2013-05-09T20:44:54.984Z,1368132294.984 [Depth_Keller](ERROR): Pressure reading out of range: 1830.660156 decibar 2013-05-09T20:45:09.914Z,1368132309.914 [NAL9602](INFO): Powering down 2013-05-09T20:46:34.988Z,1368132394.988 [Depth_Keller](ERROR): Pressure reading out of range: 1830.662720 decibar 2013-05-09T20:46:44.928Z,1368132404.928 [Depth_Keller](ERROR): Pressure reading out of range: 1830.670532 decibar 2013-05-09T20:46:54.929Z,1368132414.929 [Depth_Keller](ERROR): Pressure reading out of range: 1830.674927 decibar 2013-05-09T20:47:04.929Z,1368132424.929 [Depth_Keller](ERROR): Pressure reading out of range: 1372.973267 decibar 2013-05-09T20:47:14.929Z,1368132434.929 [Depth_Keller](ERROR): Pressure reading out of range: 1372.982056 decibar 2013-05-09T20:47:54.972Z,1368132474.972 [Depth_Keller](ERROR): Pressure reading out of range: 1830.647095 decibar 2013-05-09T20:48:24.928Z,1368132504.928 [Depth_Keller](ERROR): Pressure reading out of range: 1372.945312 decibar 2013-05-09T20:48:34.921Z,1368132514.921 [Depth_Keller](ERROR): Pressure reading out of range: 1372.927856 decibar 2013-05-09T20:48:44.928Z,1368132524.928 [Depth_Keller](ERROR): Pressure reading out of range: 1830.632202 decibar 2013-05-09T20:48:54.984Z,1368132534.984 [Depth_Keller](ERROR): Pressure reading out of range: 1830.646118 decibar 2013-05-09T20:49:04.929Z,1368132544.929 [Depth_Keller](ERROR): Pressure reading out of range: 1830.661865 decibar 2013-05-09T20:49:14.929Z,1368132554.929 [Depth_Keller](ERROR): Pressure reading out of range: 1830.649536 decibar 2013-05-09T20:49:24.929Z,1368132564.929 [Depth_Keller](ERROR): Pressure reading out of range: 1830.686279 decibar 2013-05-09T20:49:29.925Z,1368132569.925 [Default:CallIridium] Running Loop=1 2013-05-09T20:49:29.925Z,1368132569.925 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2013-05-09T20:49:29.925Z,1368132569.925 [Default:CallIridium:A] Running Loop=1 2013-05-09T20:49:29.926Z,1368132569.926 [Default:CallIridium:A] Stopped 2013-05-09T20:49:29.926Z,1368132569.926 [Default:CallIridium:B] Running Loop=1 2013-05-09T20:49:29.926Z,1368132569.926 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2013-05-09T20:49:34.929Z,1368132574.929 [Depth_Keller](ERROR): Pressure reading out of range: 1830.664429 decibar 2013-05-09T20:49:34.944Z,1368132574.944 [Default:Iridium] Running Loop=1 2013-05-09T20:49:34.945Z,1368132574.944 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2013-05-09T20:49:34.945Z,1368132574.945 [Default:Iridium:A.SetSpeed] Running Loop=1 2013-05-09T20:49:34.945Z,1368132574.945 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2013-05-09T20:49:34.945Z,1368132574.945 [Default:Iridium:B.GoToSurface] Running Loop=1 2013-05-09T20:49:34.945Z,1368132574.945 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-05-09T20:49:34.946Z,1368132574.946 [Default:Iridium:B.GoToSurface] Stopped 2013-05-09T20:49:34.946Z,1368132574.946 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-05-09T20:49:34.946Z,1368132574.946 [Default:Iridium:Read_Iridium] Running Loop=1 2013-05-09T20:49:34.946Z,1368132574.946 [Default:GPS] Running Loop=1 2013-05-09T20:49:34.946Z,1368132574.946 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2013-05-09T20:49:34.947Z,1368132574.947 [Default:GPS:A.SetSpeed] Running Loop=1 2013-05-09T20:49:34.947Z,1368132574.947 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2013-05-09T20:49:34.947Z,1368132574.947 [Default:GPS:B.GoToSurface] Running Loop=1 2013-05-09T20:49:34.947Z,1368132574.947 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-05-09T20:49:34.948Z,1368132574.948 [Default:GPS:B.GoToSurface] Stopped 2013-05-09T20:49:34.948Z,1368132574.948 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-05-09T20:49:34.948Z,1368132574.948 [Default:GPS:Read_GPS] Running Loop=1 2013-05-09T20:49:35.577Z,1368132575.577 [NAL9602](INFO): Powering up 2013-05-09T20:49:46.412Z,1368132586.412 [NAL9602](INFO): NAL9602 initialized 2013-05-09T20:50:51.419Z,1368132651.419 [NAL9602](INFO): SBD MO Status=2, MOMSN=11759, MT Status=2, MTMSN=0 2013-05-09T20:50:51.419Z,1368132651.419 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-05-09T20:50:54.368Z,1368132654.368 [CommandLine](IMPORTANT): got command ! chmod 755 /mnt/mmc/LRAUV/Tools/*.sh