2013-11-04T16:57:41.871Z,1383584261.871 [Supervisor](DEBUG): Initializing supervisor. 2013-11-04T16:57:41.874Z,1383584261.874 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0 2013-11-04T16:57:41.875Z,1383584261.875 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2013-11-04T16:57:41.876Z,1383584261.876 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0 2013-11-04T16:57:41.878Z,1383584261.878 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2013-11-04T16:57:41.889Z,1383584261.889 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2013-11-04T16:57:41.890Z,1383584261.890 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0 2013-11-04T16:57:41.892Z,1383584261.892 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2013-11-04T16:57:41.893Z,1383584261.893 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0 2013-11-04T16:57:41.893Z,1383584261.893 [Supervisor](INFO): Looking for Config files in directory: Config/ 2013-11-04T16:57:41.894Z,1383584261.894 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2013-11-04T16:57:42.176Z,1383584262.176 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2013-11-04T16:57:42.176Z,1383584262.176 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2013-11-04T16:57:42.364Z,1383584262.364 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2013-11-04T16:57:42.365Z,1383584262.365 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2013-11-04T16:57:42.451Z,1383584262.451 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2013-11-04T16:57:42.451Z,1383584262.451 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2013-11-04T16:57:42.565Z,1383584262.565 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2013-11-04T16:57:42.565Z,1383584262.565 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2013-11-04T16:57:42.705Z,1383584262.705 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2013-11-04T16:57:42.706Z,1383584262.706 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2013-11-04T16:57:42.947Z,1383584262.947 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2013-11-04T16:57:42.948Z,1383584262.948 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2013-11-04T16:57:43.113Z,1383584263.113 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2013-11-04T16:57:43.114Z,1383584263.114 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2013-11-04T16:57:43.380Z,1383584263.380 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2013-11-04T16:57:43.380Z,1383584263.380 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2013-11-04T16:57:43.481Z,1383584263.481 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2013-11-04T16:57:43.482Z,1383584263.482 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2013-11-04T16:57:43.894Z,1383584263.894 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2013-11-04T16:57:43.895Z,1383584263.895 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2013-11-04T16:57:44.006Z,1383584264.006 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2013-11-04T16:57:44.007Z,1383584264.007 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2013-11-04T16:57:44.093Z,1383584264.093 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2013-11-04T16:57:44.094Z,1383584264.094 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2013-11-04T16:57:44.193Z,1383584264.193 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2013-11-04T16:57:44.320Z,1383584264.320 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2013-11-04T16:57:44.420Z,1383584264.420 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2013-11-04T16:57:44.526Z,1383584264.526 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2013-11-04T16:57:44.622Z,1383584264.622 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2013-11-04T16:57:44.737Z,1383584264.737 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2013-11-04T16:57:44.833Z,1383584264.833 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2013-11-04T16:57:44.919Z,1383584264.919 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/LOGIN/ 2013-11-04T16:57:44.920Z,1383584264.920 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2013-11-04T16:57:44.921Z,1383584264.921 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2013-11-04T16:57:45.079Z,1383584265.079 [InternalSim] Loaded 2013-11-04T16:57:45.080Z,1383584265.080 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread. 2013-11-04T16:57:45.080Z,1383584265.080 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2013-11-04T16:57:45.081Z,1383584265.081 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2013-11-04T16:57:45.166Z,1383584265.166 [SBIT](DEBUG): Construct Startup Built In Test. 2013-11-04T16:57:45.194Z,1383584265.194 [SBIT] Loaded 2013-11-04T16:57:45.194Z,1383584265.194 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2013-11-04T16:57:45.195Z,1383584265.195 [IBIT](DEBUG): Construct Initiated Built In Test. 2013-11-04T16:57:45.223Z,1383584265.223 [IBIT] Loaded 2013-11-04T16:57:45.224Z,1383584265.224 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2013-11-04T16:57:45.226Z,1383584265.226 [CBIT](DEBUG): Construct CBIT Built In Test. 2013-11-04T16:57:45.339Z,1383584265.339 [CBIT] Loaded 2013-11-04T16:57:45.339Z,1383584265.339 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2013-11-04T16:57:45.340Z,1383584265.340 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2013-11-04T16:57:45.340Z,1383584265.340 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2013-11-04T16:57:45.506Z,1383584265.506 [BuoyancyServo] Loaded 2013-11-04T16:57:45.506Z,1383584265.506 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2013-11-04T16:57:45.518Z,1383584265.518 [ElevatorServo] Loaded 2013-11-04T16:57:45.518Z,1383584265.518 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2013-11-04T16:57:45.529Z,1383584265.529 [MassServo] Loaded 2013-11-04T16:57:45.529Z,1383584265.529 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2013-11-04T16:57:45.541Z,1383584265.541 [RudderServo] Loaded 2013-11-04T16:57:45.541Z,1383584265.541 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2013-11-04T16:57:45.552Z,1383584265.552 [ThrusterServo] Loaded 2013-11-04T16:57:45.552Z,1383584265.552 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2013-11-04T16:57:45.552Z,1383584265.552 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2013-11-04T16:57:45.553Z,1383584265.553 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2013-11-04T16:57:45.588Z,1383584265.588 [DepthRateCalculator] Loaded 2013-11-04T16:57:45.588Z,1383584265.588 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2013-11-04T16:57:48.084Z,1383584268.084 [HFRadarModelCalc] Loaded 2013-11-04T16:57:48.085Z,1383584268.085 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread. 2013-11-04T16:57:48.100Z,1383584268.100 [NavChart] Loaded 2013-11-04T16:57:48.101Z,1383584268.101 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2013-11-04T16:57:48.106Z,1383584268.106 [PitchRateCalculator] Loaded 2013-11-04T16:57:48.106Z,1383584268.106 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2013-11-04T16:57:48.117Z,1383584268.117 [SpeedCalculator] Loaded 2013-11-04T16:57:48.117Z,1383584268.117 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2013-11-04T16:57:48.133Z,1383584268.133 [TempGradientCalculator] Loaded 2013-11-04T16:57:48.133Z,1383584268.133 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2013-11-04T16:57:48.138Z,1383584268.138 [YawRateCalculator] Loaded 2013-11-04T16:57:48.139Z,1383584268.139 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2013-11-04T16:57:48.184Z,1383584268.184 [Navigation] Loaded 2013-11-04T16:57:48.185Z,1383584268.185 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread. 2013-11-04T16:57:48.185Z,1383584268.185 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2013-11-04T16:57:48.186Z,1383584268.186 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2013-11-04T16:57:48.416Z,1383584268.416 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2013-11-04T16:57:48.416Z,1383584268.416 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2013-11-04T16:57:48.439Z,1383584268.439 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2013-11-04T16:57:48.439Z,1383584268.439 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2013-11-04T16:57:48.486Z,1383584268.486 [VerticalControl](DEBUG): Construct VerticalControl. 2013-11-04T16:57:48.576Z,1383584268.576 [VerticalControl] Loaded 2013-11-04T16:57:48.576Z,1383584268.576 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2013-11-04T16:57:48.577Z,1383584268.577 [HorizontalControl](DEBUG): Construct HorizontalControl. 2013-11-04T16:57:48.633Z,1383584268.633 [HorizontalControl] Loaded 2013-11-04T16:57:48.633Z,1383584268.633 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2013-11-04T16:57:48.634Z,1383584268.634 [SpeedControl](DEBUG): Construct SpeedControl. 2013-11-04T16:57:48.635Z,1383584268.635 [SpeedControl] Loaded 2013-11-04T16:57:48.636Z,1383584268.636 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2013-11-04T16:57:48.636Z,1383584268.636 [LoopControl](DEBUG): Construct LoopControl. 2013-11-04T16:57:48.637Z,1383584268.637 [LoopControl] Loaded 2013-11-04T16:57:48.637Z,1383584268.637 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2013-11-04T16:57:48.638Z,1383584268.638 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2013-11-04T16:57:48.638Z,1383584268.638 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2013-11-04T16:57:48.644Z,1383584268.644 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator. 2013-11-04T16:57:48.649Z,1383584268.649 [AsyncPiEstimator] Loaded 2013-11-04T16:57:48.649Z,1383584268.649 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread. 2013-11-04T16:57:48.650Z,1383584268.650 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406474E0 2013-11-04T16:57:48.651Z,1383584268.651 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2013-11-04T16:57:48.651Z,1383584268.651 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2013-11-04T16:57:48.846Z,1383584268.846 [AHRS_sp3003D] Loaded 2013-11-04T16:57:48.846Z,1383584268.846 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread. 2013-11-04T16:57:48.860Z,1383584268.860 [Depth_Keller] Loaded 2013-11-04T16:57:48.860Z,1383584268.860 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2013-11-04T16:57:49.041Z,1383584269.041 [DVL_micro] Loaded 2013-11-04T16:57:49.041Z,1383584269.041 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread. 2013-11-04T16:57:49.042Z,1383584269.042 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 406D64E0 2013-11-04T16:57:49.129Z,1383584269.129 [NAL9602] Loaded 2013-11-04T16:57:49.129Z,1383584269.129 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2013-11-04T16:57:49.169Z,1383584269.169 [Onboard] Loaded 2013-11-04T16:57:49.169Z,1383584269.169 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2013-11-04T16:57:49.176Z,1383584269.176 [Radio_Freewave] Loaded 2013-11-04T16:57:49.176Z,1383584269.176 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread. 2013-11-04T16:57:49.319Z,1383584269.319 [DAT] Loaded 2013-11-04T16:57:49.319Z,1383584269.319 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2013-11-04T16:57:49.319Z,1383584269.319 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2013-11-04T16:57:49.320Z,1383584269.320 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2013-11-04T16:57:49.418Z,1383584269.418 [CTD_NeilBrown] Loaded 2013-11-04T16:57:49.418Z,1383584269.418 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2013-11-04T16:57:49.419Z,1383584269.419 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 407334E0 2013-11-04T16:57:49.451Z,1383584269.451 [WetLabsBB2FL] Loaded 2013-11-04T16:57:49.451Z,1383584269.451 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2013-11-04T16:57:49.452Z,1383584269.452 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407634E0 2013-11-04T16:57:49.453Z,1383584269.453 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2013-11-04T16:57:49.455Z,1383584269.455 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2013-11-04T16:57:49.456Z,1383584269.456 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2013-11-04T16:57:49.463Z,1383584269.463 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2013-11-04T16:57:49.464Z,1383584269.464 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 407934E0 2013-11-04T16:57:49.468Z,1383584269.468 [Supervisor](DEBUG): Running supervisor. 2013-11-04T16:57:49.469Z,1383584269.469 [CommandLine](INFO): Thread ID is 3259 2013-11-04T16:57:49.472Z,1383584269.472 [controlThread](INFO): Thread ID is 3258 2013-11-04T16:57:49.472Z,1383584269.472 [controlThread](DEBUG): Initializing ControlThread 2013-11-04T16:57:49.472Z,1383584269.472 [CycleStarter](INFO): Thread ID is 3257 2013-11-04T16:57:49.473Z,1383584269.473 [InternalSim](DEBUG): InternalSim initializing... 2013-11-04T16:57:49.507Z,1383584269.507 [logger](INFO): Thread ID is 3260 2013-11-04T16:57:49.533Z,1383584269.533 [SBIT](INFO): Initialize SBIT Component. 2013-11-04T16:57:49.534Z,1383584269.534 [SBIT](IMPORTANT): Tethys CM Info: $Rev:10711 2013-11-04T16:57:49.534Z,1383584269.534 [SBIT](IMPORTANT): Kernel Release:2.6.27.8 2013-11-04T16:57:49.534Z,1383584269.534 [SBIT](IMPORTANT): Kernel Version:#634 PREEMPT Wed Feb 13 10:21:48 PST 2013 2013-11-04T16:57:49.535Z,1383584269.535 [IBIT](INFO): Initialize IBIT Component. 2013-11-04T16:57:49.536Z,1383584269.536 [CBIT](DEBUG): Initialize CBIT Component. 2013-11-04T16:57:49.536Z,1383584269.536 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2013-11-04T16:57:49.547Z,1383584269.547 [AsyncPiEstimator](INFO): Thread ID is 3321 2013-11-04T16:57:49.548Z,1383584269.548 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator. 2013-11-04T16:57:49.560Z,1383584269.560 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2013-11-04T16:57:49.561Z,1383584269.561 [NavChart](DEBUG): Initialize NavChart Derivation. 2013-11-04T16:57:49.561Z,1383584269.561 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2013-11-04T16:57:49.561Z,1383584269.561 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2013-11-04T16:57:49.562Z,1383584269.562 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2013-11-04T16:57:49.562Z,1383584269.562 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2013-11-04T16:57:49.562Z,1383584269.562 [Navigation](DEBUG): Initializing Navigation. 2013-11-04T16:57:49.563Z,1383584269.563 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2013-11-04T16:57:49.565Z,1383584269.565 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2013-11-04T16:57:49.565Z,1383584269.565 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2013-11-04T16:57:49.566Z,1383584269.566 [LoopControl](DEBUG): Initialize LoopControlComponent. 2013-11-04T16:57:49.574Z,1383584269.574 [DVL_micro](INFO): Thread ID is 3322 2013-11-04T16:57:49.582Z,1383584269.582 [DVL_micro](INFO): Initializing 2013-11-04T16:57:49.583Z,1383584269.583 [DVL_micro](INFO): start:Powering up 2013-11-04T16:57:49.584Z,1383584269.584 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-11-04T16:57:49.584Z,1383584269.584 [DVL_micro](INFO): Cycling power to configure device. 2013-11-04T16:57:49.599Z,1383584269.599 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2013-11-04T16:57:49.608Z,1383584269.608 [CTD_NeilBrown](INFO): Thread ID is 3323 2013-11-04T16:57:49.608Z,1383584269.608 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown. 2013-11-04T16:57:49.620Z,1383584269.620 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4 2013-11-04T16:57:49.633Z,1383584269.633 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2013-11-04T16:57:49.635Z,1383584269.635 [WetLabsBB2FL](INFO): Thread ID is 3324 2013-11-04T16:57:49.636Z,1383584269.636 [WetLabsBB2FL](INFO): Powering down 2013-11-04T16:57:49.669Z,1383584269.669 [NavChartDb](INFO): Thread ID is 3325 2013-11-04T16:57:49.672Z,1383584269.672 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources 2013-11-04T16:57:49.673Z,1383584269.673 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2013-11-04T16:57:49.673Z,1383584269.673 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2013-11-04T16:57:49.673Z,1383584269.673 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2013-11-04T16:57:49.673Z,1383584269.673 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2013-11-04T16:57:49.674Z,1383584269.674 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2013-11-04T16:57:49.674Z,1383584269.674 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2013-11-04T16:57:49.674Z,1383584269.674 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2013-11-04T16:57:49.674Z,1383584269.674 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2013-11-04T16:57:49.695Z,1383584269.695 [MissionManager](DEBUG): 2013-11-04T16:57:49.696Z,1383584269.696 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2013-11-04T16:57:49.783Z,1383584269.783 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool 2013-11-04T16:57:49.785Z,1383584269.785 [Default:GPS:A.SetSpeed](DEBUG): Construct. 2013-11-04T16:57:49.800Z,1383584269.800 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface. 2013-11-04T16:57:49.808Z,1383584269.808 [Default:Iridium:A.SetSpeed](DEBUG): Construct. 2013-11-04T16:57:49.843Z,1383584269.843 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface. 2013-11-04T16:57:49.854Z,1383584269.854 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2013-11-04T16:57:49.886Z,1383584269.886 [Default:D.SetSpeed](DEBUG): Construct. 2013-11-04T16:57:49.890Z,1383584269.890 [Default:E.GoToSurface](DEBUG): Construct GoToSurface. 2013-11-04T16:57:49.894Z,1383584269.894 [Default:F.Wait](DEBUG): Construct Wait. 2013-11-04T16:57:49.910Z,1383584269.910 [MissionManager](DEBUG): 400 400 Burn 300 Dropped drop weight due to communications timeout 5.0 1.0 5 2013-11-04T16:57:49.922Z,1383584269.922 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Depth_Keller,NAL9602,Onboard,Radio_Freewave,DAT,Depth_Keller,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter, 2013-11-04T16:57:49.981Z,1383584269.981 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2013-11-04T16:57:50.004Z,1383584270.004 [Depth_Keller](ERROR): Pressure reading out of range: 1831.078247 decibar 2013-11-04T16:57:50.082Z,1383584270.082 [Radio_Freewave](INFO): Powering up 2013-11-04T16:57:50.092Z,1383584270.092 [DAT](INFO): Powering up 2013-11-04T16:57:50.092Z,1383584270.092 [DAT](DEBUG): Initializing DAT. 2013-11-04T16:57:50.298Z,1383584270.298 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2013-11-04T16:57:50.304Z,1383584270.304 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2013-11-04T16:57:50.326Z,1383584270.326 [ElevatorServo](DEBUG): Initializing EZServoServo. 2013-11-04T16:57:50.332Z,1383584270.332 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2013-11-04T16:57:50.342Z,1383584270.342 [MassServo](DEBUG): Initializing EZServoServo. 2013-11-04T16:57:50.348Z,1383584270.348 [MassServo](DEBUG): Initializing MassServo. 2013-11-04T16:57:50.363Z,1383584270.363 [RudderServo](DEBUG): Initializing EZServoServo. 2013-11-04T16:57:50.368Z,1383584270.368 [RudderServo](DEBUG): Initializing RudderServo. 2013-11-04T16:57:50.374Z,1383584270.374 [ThrusterServo](DEBUG): Initializing EZServoServo. 2013-11-04T16:57:50.380Z,1383584270.380 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2013-11-04T16:57:51.670Z,1383584271.670 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-11-04T16:57:51.671Z,1383584271.671 [DVL_micro](INFO): Querying output modes 2013-11-04T16:57:51.671Z,1383584271.671 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606 2013-11-04T16:57:51.683Z,1383584271.683 [DVL_micro](DEBUG): cmdResponse: 01 2013-11-04T16:57:51.683Z,1383584271.683 [DVL_micro](INFO): NQ1 output enabled 2013-11-04T16:57:51.683Z,1383584271.683 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525 2013-11-04T16:57:51.694Z,1383584271.694 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 2013-11-04T16:57:51.700Z,1383584271.700 [DVL_micro](INFO): pause:Powering down 2013-11-04T16:57:54.204Z,1383584274.204 [NAL9602](INFO): Powering up NAL9602 2013-11-04T16:58:04.923Z,1383584284.923 [NAL9602](INFO): NAL9602 initialized 2013-11-04T16:58:05.546Z,1383584285.546 [SBIT](IMPORTANT): Beginning Startup BIT 2013-11-04T16:58:05.548Z,1383584285.548 [CBIT](IMPORTANT): Beginning GF scan 2013-11-04T16:58:10.791Z,1383584290.791 [DAT](INFO): Powering down 2013-11-04T16:58:33.386Z,1383584313.386 [CBIT](IMPORTANT): No ground fault detected 2013-11-04T16:58:53.626Z,1383584333.626 [NAL9602](ERROR): getFix uart error: serial timeout 2013-11-04T16:58:59.008Z,1383584339.008 [NAL9602](IMPORTANT): GPS fix at: 1383584360.00 2013-11-04T16:58:59.439Z,1383584339.439 [SBIT](IMPORTANT): SBIT PASSED 2013-11-04T16:58:59.835Z,1383584339.835 [MissionManager](IMPORTANT): Started mission Startup 2013-11-04T16:58:59.835Z,1383584339.835 [Startup] Running Loop=1 2013-11-04T16:58:59.835Z,1383584339.835 [Startup](INFO): Aggregate::initialize Startup 2013-11-04T16:58:59.835Z,1383584339.835 [Startup:A.GoToSurface] Running Loop=1 2013-11-04T16:58:59.835Z,1383584339.835 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-11-04T16:58:59.842Z,1383584339.842 [Startup:StartupSatComms] Running Loop=1 2013-11-04T16:58:59.842Z,1383584339.842 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms 2013-11-04T16:58:59.842Z,1383584339.842 [Startup:StartupSatComms:A] Running Loop=1 2013-11-04T16:59:00.247Z,1383584340.247 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2013-11-04T16:59:01.474Z,1383584341.474 [NAL9602](IMPORTANT): GPS fix at: 1383584363.00 2013-11-04T16:59:01.488Z,1383584341.488 [Startup:StartupSatComms:A] Stopped 2013-11-04T16:59:01.488Z,1383584341.488 [Startup:StartupSatComms:B] Running Loop=1 2013-11-04T16:59:02.462Z,1383584342.462 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2013-11-04T16:59:11.738Z,1383584351.738 [NAL9602](INFO): Loading bytes: 33 2013-11-04T16:59:11.786Z,1383584351.786 [NAL9602](INFO): cxum: 1397 2013-11-04T16:59:17.594Z,1383584357.594 [NAL9602](INFO): SBD MO Status=1, MOMSN=20567, MT Status=0, MTMSN=0 2013-11-04T16:59:17.648Z,1383584357.648 [NAL9602](INFO): Sent 25 bytes from file Logs/20131104T165022/Courier0004.lzma 2013-11-04T16:59:17.648Z,1383584357.648 [NAL9602](INFO): Packets left to send: 0 2013-11-04T16:59:17.650Z,1383584357.650 [NAL9602](INFO): Stored copy of sent data in Logs/20131104T165022/Courier0004.lzma.parts/0000.sbd 2013-11-04T16:59:18.288Z,1383584358.288 [NAL9602](INFO): Loading bytes: 214 2013-11-04T16:59:18.336Z,1383584358.336 [NAL9602](INFO): cxum: 24810 2013-11-04T16:59:30.009Z,1383584370.009 [NAL9602](INFO): SBD MO Status=1, MOMSN=20568, MT Status=0, MTMSN=0 2013-11-04T16:59:30.059Z,1383584370.059 [NAL9602](INFO): Sent 206 bytes from file Logs/20131104T165741/Courier0000.lzma 2013-11-04T16:59:30.060Z,1383584370.060 [NAL9602](INFO): Packets left to send: 0 2013-11-04T16:59:30.061Z,1383584370.061 [NAL9602](INFO): Stored copy of sent data in Logs/20131104T165741/Courier0000.lzma.parts/0000.sbd 2013-11-04T16:59:30.992Z,1383584370.992 [NAL9602](INFO): Loading bytes: 340 2013-11-04T16:59:31.040Z,1383584371.040 [NAL9602](INFO): cxum: 41137 2013-11-04T16:59:43.690Z,1383584383.690 [NAL9602](INFO): SBD MO Status=1, MOMSN=20569, MT Status=0, MTMSN=0 2013-11-04T16:59:43.736Z,1383584383.736 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0005.lzma 2013-11-04T16:59:43.736Z,1383584383.736 [NAL9602](INFO): Packets left to send: 20 2013-11-04T16:59:43.737Z,1383584383.737 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0005.lzma.parts/0020.sbd 2013-11-04T16:59:44.129Z,1383584384.129 [NAL9602](INFO): Loading bytes: 340 2013-11-04T16:59:44.181Z,1383584384.181 [NAL9602](INFO): cxum: 40598 2013-11-04T16:59:56.606Z,1383584396.606 [NAL9602](INFO): SBD MO Status=1, MOMSN=20570, MT Status=0, MTMSN=0 2013-11-04T16:59:56.656Z,1383584396.656 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0005.lzma 2013-11-04T16:59:56.656Z,1383584396.656 [NAL9602](INFO): Packets left to send: 19 2013-11-04T16:59:56.657Z,1383584396.657 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0005.lzma.parts/0019.sbd 2013-11-04T16:59:57.081Z,1383584397.081 [NAL9602](INFO): Loading bytes: 340 2013-11-04T16:59:57.133Z,1383584397.133 [NAL9602](INFO): cxum: 42811 2013-11-04T17:00:01.607Z,1383584401.607 [Startup:StartupSatComms:B](INFO): Timed out from 2013-11-04T16:59:01.5Z 2013-11-04T17:00:01.607Z,1383584401.607 [Startup:StartupSatComms:B:A_Timeout] Running Loop=1 2013-11-04T17:00:01.607Z,1383584401.607 [Startup:StartupSatComms:B:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:B:A_Timeout 2013-11-04T17:00:01.608Z,1383584401.608 [Startup:StartupSatComms:B:A_Timeout](INFO): Completed Startup:StartupSatComms:B:A_Timeout 2013-11-04T17:00:01.608Z,1383584401.608 [Startup:StartupSatComms:B] Stopped 2013-11-04T17:00:01.608Z,1383584401.608 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2013-11-04T17:00:01.608Z,1383584401.608 [Startup:StartupSatComms] Stopped 2013-11-04T17:00:01.608Z,1383584401.608 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms 2013-11-04T17:00:01.609Z,1383584401.609 [Startup](INFO): Completed Startup 2013-11-04T17:00:01.609Z,1383584401.609 [Startup] Stopped 2013-11-04T17:00:01.609Z,1383584401.609 [Startup](INFO): Aggregate::uninitialize Startup 2013-11-04T17:00:01.609Z,1383584401.609 [Startup:A.GoToSurface] Stopped 2013-11-04T17:00:01.609Z,1383584401.609 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-11-04T17:00:02.037Z,1383584402.037 [MissionManager](IMPORTANT): Started mission Default 2013-11-04T17:00:02.037Z,1383584402.037 [Default] Running Loop=1 2013-11-04T17:00:02.037Z,1383584402.037 [Default](INFO): Aggregate::initialize Default 2013-11-04T17:00:02.037Z,1383584402.037 [Default:D.SetSpeed] Running Loop=1 2013-11-04T17:00:02.037Z,1383584402.037 [Default:D.SetSpeed](DEBUG): Initialize. 2013-11-04T17:00:02.037Z,1383584402.037 [Default:E.GoToSurface] Running Loop=1 2013-11-04T17:00:02.037Z,1383584402.037 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-11-04T17:00:02.037Z,1383584402.037 [Default:Iridium] Running Loop=1 2013-11-04T17:00:02.038Z,1383584402.038 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2013-11-04T17:00:02.038Z,1383584402.038 [Default:Iridium:A.SetSpeed] Running Loop=1 2013-11-04T17:00:02.038Z,1383584402.038 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2013-11-04T17:00:02.038Z,1383584402.038 [Default:Iridium:B.GoToSurface] Running Loop=1 2013-11-04T17:00:02.038Z,1383584402.038 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-11-04T17:00:02.038Z,1383584402.038 [Default:E.GoToSurface] Running Loop=1 2013-11-04T17:00:02.048Z,1383584402.048 [Default:D.SetSpeed] Running Loop=1 2013-11-04T17:00:02.054Z,1383584402.054 [Default:CallIridium] Running Loop=1 2013-11-04T17:00:02.054Z,1383584402.054 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2013-11-04T17:00:02.055Z,1383584402.055 [Default:CallIridium:A] Running Loop=1 2013-11-04T17:00:02.057Z,1383584402.057 [Default:CallIridium:A] Stopped 2013-11-04T17:00:02.057Z,1383584402.057 [Default:CallIridium:B] Running Loop=1 2013-11-04T17:00:02.057Z,1383584402.057 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2013-11-04T17:00:02.062Z,1383584402.062 [Default:Iridium:B.GoToSurface] Stopped 2013-11-04T17:00:02.062Z,1383584402.062 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-11-04T17:00:02.062Z,1383584402.062 [Default:Iridium:Read_Iridium] Running Loop=1 2013-11-04T17:00:02.062Z,1383584402.062 [Default:Iridium:A.SetSpeed] Running Loop=1 2013-11-04T17:00:02.067Z,1383584402.067 [Default:GPS] Running Loop=1 2013-11-04T17:00:02.067Z,1383584402.067 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2013-11-04T17:00:02.067Z,1383584402.067 [Default:GPS:A.SetSpeed] Running Loop=1 2013-11-04T17:00:02.067Z,1383584402.067 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2013-11-04T17:00:02.068Z,1383584402.068 [Default:GPS:B.GoToSurface] Running Loop=1 2013-11-04T17:00:02.068Z,1383584402.068 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-11-04T17:00:02.073Z,1383584402.073 [Default:GPS:B.GoToSurface] Stopped 2013-11-04T17:00:02.073Z,1383584402.073 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-11-04T17:00:02.073Z,1383584402.073 [Default:GPS:Read_GPS] Running Loop=1 2013-11-04T17:00:02.073Z,1383584402.073 [Default:GPS:A.SetSpeed] Running Loop=1 2013-11-04T17:00:02.447Z,1383584402.447 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2013-11-04T17:00:02.450Z,1383584402.450 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2013-11-04T17:00:14.057Z,1383584414.057 [NAL9602](INFO): SBD MO Status=1, MOMSN=20571, MT Status=0, MTMSN=0 2013-11-04T17:00:14.107Z,1383584414.107 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0005.lzma 2013-11-04T17:00:14.107Z,1383584414.107 [NAL9602](INFO): Packets left to send: 18 2013-11-04T17:00:14.108Z,1383584414.108 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0005.lzma.parts/0018.sbd 2013-11-04T17:00:14.532Z,1383584414.532 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:00:14.580Z,1383584414.580 [NAL9602](INFO): cxum: 44418 2013-11-04T17:00:28.608Z,1383584428.608 [NAL9602](INFO): SBD MO Status=1, MOMSN=20572, MT Status=0, MTMSN=0 2013-11-04T17:00:28.658Z,1383584428.658 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0005.lzma 2013-11-04T17:00:28.658Z,1383584428.658 [NAL9602](INFO): Packets left to send: 17 2013-11-04T17:00:28.659Z,1383584428.659 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0005.lzma.parts/0017.sbd 2013-11-04T17:00:29.082Z,1383584429.082 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:00:29.134Z,1383584429.134 [NAL9602](INFO): cxum: 43175 2013-11-04T17:00:44.007Z,1383584444.007 [NAL9602](INFO): SBD MO Status=1, MOMSN=20573, MT Status=0, MTMSN=0 2013-11-04T17:00:44.058Z,1383584444.058 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0005.lzma 2013-11-04T17:00:44.058Z,1383584444.058 [NAL9602](INFO): Packets left to send: 16 2013-11-04T17:00:44.059Z,1383584444.059 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0005.lzma.parts/0016.sbd 2013-11-04T17:00:44.486Z,1383584444.486 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:00:44.534Z,1383584444.534 [NAL9602](INFO): cxum: 40405 2013-11-04T17:01:00.599Z,1383584460.599 [NAL9602](INFO): SBD MO Status=1, MOMSN=20574, MT Status=0, MTMSN=0 2013-11-04T17:01:00.659Z,1383584460.659 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0005.lzma 2013-11-04T17:01:00.660Z,1383584460.660 [NAL9602](INFO): Packets left to send: 15 2013-11-04T17:01:00.660Z,1383584460.660 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0005.lzma.parts/0015.sbd 2013-11-04T17:01:01.080Z,1383584461.080 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:01:01.136Z,1383584461.136 [NAL9602](INFO): cxum: 43790 2013-11-04T17:01:11.220Z,1383584471.220 [NAL9602](INFO): SBD MO Status=1, MOMSN=20575, MT Status=0, MTMSN=0 2013-11-04T17:01:11.268Z,1383584471.268 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0005.lzma 2013-11-04T17:01:11.268Z,1383584471.268 [NAL9602](INFO): Packets left to send: 14 2013-11-04T17:01:11.269Z,1383584471.269 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0005.lzma.parts/0014.sbd 2013-11-04T17:01:11.704Z,1383584471.704 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:01:11.752Z,1383584471.752 [NAL9602](INFO): cxum: 43144 2013-11-04T17:01:22.603Z,1383584482.603 [NAL9602](INFO): SBD MO Status=1, MOMSN=20576, MT Status=0, MTMSN=0 2013-11-04T17:01:22.657Z,1383584482.657 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0005.lzma 2013-11-04T17:01:22.658Z,1383584482.658 [NAL9602](INFO): Packets left to send: 13 2013-11-04T17:01:22.658Z,1383584482.658 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0005.lzma.parts/0013.sbd 2013-11-04T17:01:23.086Z,1383584483.086 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:01:23.134Z,1383584483.134 [NAL9602](INFO): cxum: 43923 2013-11-04T17:01:35.203Z,1383584495.203 [NAL9602](INFO): SBD MO Status=1, MOMSN=20577, MT Status=0, MTMSN=0 2013-11-04T17:01:35.261Z,1383584495.261 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0005.lzma 2013-11-04T17:01:35.261Z,1383584495.261 [NAL9602](INFO): Packets left to send: 12 2013-11-04T17:01:35.262Z,1383584495.262 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0005.lzma.parts/0012.sbd 2013-11-04T17:01:35.693Z,1383584495.693 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:01:35.741Z,1383584495.741 [NAL9602](INFO): cxum: 45047 2013-11-04T17:01:45.002Z,1383584505.002 [NAL9602](INFO): SBD MO Status=1, MOMSN=20578, MT Status=0, MTMSN=0 2013-11-04T17:01:45.056Z,1383584505.056 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0005.lzma 2013-11-04T17:01:45.056Z,1383584505.056 [NAL9602](INFO): Packets left to send: 11 2013-11-04T17:01:45.057Z,1383584505.057 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0005.lzma.parts/0011.sbd 2013-11-04T17:01:45.449Z,1383584505.449 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:01:45.496Z,1383584505.496 [NAL9602](INFO): cxum: 42974 2013-11-04T17:01:58.017Z,1383584518.017 [NAL9602](INFO): SBD MO Status=1, MOMSN=20579, MT Status=0, MTMSN=0 2013-11-04T17:01:58.064Z,1383584518.064 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0005.lzma 2013-11-04T17:01:58.064Z,1383584518.064 [NAL9602](INFO): Packets left to send: 10 2013-11-04T17:01:58.065Z,1383584518.065 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0005.lzma.parts/0010.sbd 2013-11-04T17:01:58.501Z,1383584518.501 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:01:58.551Z,1383584518.551 [NAL9602](INFO): cxum: 40974 2013-11-04T17:02:11.006Z,1383584531.006 [NAL9602](INFO): SBD MO Status=1, MOMSN=20580, MT Status=0, MTMSN=0 2013-11-04T17:02:11.056Z,1383584531.056 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0005.lzma 2013-11-04T17:02:11.057Z,1383584531.057 [NAL9602](INFO): Packets left to send: 9 2013-11-04T17:02:11.057Z,1383584531.057 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0005.lzma.parts/0009.sbd 2013-11-04T17:02:11.485Z,1383584531.485 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:02:11.533Z,1383584531.533 [NAL9602](INFO): cxum: 41748 2013-11-04T17:02:19.604Z,1383584539.604 [NAL9602](INFO): SBD MO Status=1, MOMSN=20581, MT Status=0, MTMSN=0 2013-11-04T17:02:19.658Z,1383584539.658 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0005.lzma 2013-11-04T17:02:19.658Z,1383584539.658 [NAL9602](INFO): Packets left to send: 8 2013-11-04T17:02:19.659Z,1383584539.659 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0005.lzma.parts/0008.sbd 2013-11-04T17:02:20.086Z,1383584540.086 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:02:20.134Z,1383584540.134 [NAL9602](INFO): cxum: 43760 2013-11-04T17:02:32.924Z,1383584552.924 [NAL9602](INFO): SBD MO Status=1, MOMSN=20582, MT Status=0, MTMSN=0 2013-11-04T17:02:32.974Z,1383584552.974 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0005.lzma 2013-11-04T17:02:32.975Z,1383584552.975 [NAL9602](INFO): Packets left to send: 7 2013-11-04T17:02:32.975Z,1383584552.975 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0005.lzma.parts/0007.sbd 2013-11-04T17:02:33.407Z,1383584553.407 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:02:33.455Z,1383584553.455 [NAL9602](INFO): cxum: 41085 2013-11-04T17:02:45.231Z,1383584565.231 [NAL9602](INFO): SBD MO Status=1, MOMSN=20583, MT Status=0, MTMSN=0 2013-11-04T17:02:45.281Z,1383584565.281 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0005.lzma 2013-11-04T17:02:45.282Z,1383584565.282 [NAL9602](INFO): Packets left to send: 6 2013-11-04T17:02:45.283Z,1383584565.283 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0005.lzma.parts/0006.sbd 2013-11-04T17:02:45.730Z,1383584565.730 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:02:45.778Z,1383584565.778 [NAL9602](INFO): cxum: 42605 2013-11-04T17:02:53.805Z,1383584573.805 [NAL9602](INFO): SBD MO Status=1, MOMSN=20584, MT Status=0, MTMSN=0 2013-11-04T17:02:53.867Z,1383584573.867 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0005.lzma 2013-11-04T17:02:53.867Z,1383584573.867 [NAL9602](INFO): Packets left to send: 5 2013-11-04T17:02:53.868Z,1383584573.868 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0005.lzma.parts/0005.sbd 2013-11-04T17:02:54.307Z,1383584574.307 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:02:54.355Z,1383584574.355 [NAL9602](INFO): cxum: 41528 2013-11-04T17:03:07.604Z,1383584587.604 [NAL9602](INFO): SBD MO Status=1, MOMSN=20585, MT Status=0, MTMSN=0 2013-11-04T17:03:07.656Z,1383584587.656 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0005.lzma 2013-11-04T17:03:07.656Z,1383584587.656 [NAL9602](INFO): Packets left to send: 4 2013-11-04T17:03:07.657Z,1383584587.657 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0005.lzma.parts/0004.sbd 2013-11-04T17:03:08.077Z,1383584588.077 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:03:08.133Z,1383584588.133 [NAL9602](INFO): cxum: 41577 2013-11-04T17:03:20.516Z,1383584600.516 [NAL9602](INFO): SBD MO Status=1, MOMSN=20586, MT Status=0, MTMSN=0 2013-11-04T17:03:20.564Z,1383584600.564 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0005.lzma 2013-11-04T17:03:20.564Z,1383584600.564 [NAL9602](INFO): Packets left to send: 3 2013-11-04T17:03:20.565Z,1383584600.565 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0005.lzma.parts/0003.sbd 2013-11-04T17:03:20.989Z,1383584600.989 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:03:21.037Z,1383584601.037 [NAL9602](INFO): cxum: 46438 2013-11-04T17:03:28.718Z,1383584608.718 [NAL9602](INFO): SBD MO Status=1, MOMSN=20587, MT Status=0, MTMSN=0 2013-11-04T17:03:28.769Z,1383584608.769 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0005.lzma 2013-11-04T17:03:28.769Z,1383584608.769 [NAL9602](INFO): Packets left to send: 2 2013-11-04T17:03:28.770Z,1383584608.770 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0005.lzma.parts/0002.sbd 2013-11-04T17:03:29.253Z,1383584609.253 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:03:29.306Z,1383584609.306 [NAL9602](INFO): cxum: 41214 2013-11-04T17:03:37.308Z,1383584617.308 [NAL9602](INFO): SBD MO Status=1, MOMSN=20588, MT Status=0, MTMSN=0 2013-11-04T17:03:37.358Z,1383584617.358 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0005.lzma 2013-11-04T17:03:37.359Z,1383584617.359 [NAL9602](INFO): Packets left to send: 1 2013-11-04T17:03:37.360Z,1383584617.360 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0005.lzma.parts/0001.sbd 2013-11-04T17:03:37.787Z,1383584617.787 [NAL9602](INFO): Loading bytes: 85 2013-11-04T17:03:37.835Z,1383584617.835 [NAL9602](INFO): cxum: 10304 2013-11-04T17:03:44.275Z,1383584624.275 [NAL9602](INFO): SBD MO Status=1, MOMSN=20589, MT Status=0, MTMSN=0 2013-11-04T17:03:44.333Z,1383584624.333 [NAL9602](INFO): Sent 77 bytes from file Logs/20131031T231648/Express0005.lzma 2013-11-04T17:03:44.333Z,1383584624.333 [NAL9602](INFO): Packets left to send: 0 2013-11-04T17:03:44.334Z,1383584624.334 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0005.lzma.parts/0000.sbd 2013-11-04T17:03:45.399Z,1383584625.399 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:03:45.447Z,1383584625.447 [NAL9602](INFO): cxum: 37743 2013-11-04T17:03:54.307Z,1383584634.307 [NAL9602](INFO): SBD MO Status=1, MOMSN=20590, MT Status=0, MTMSN=0 2013-11-04T17:03:54.357Z,1383584634.357 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0009.lzma 2013-11-04T17:03:54.357Z,1383584634.357 [NAL9602](INFO): Packets left to send: 22 2013-11-04T17:03:54.360Z,1383584634.360 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0009.lzma.parts/0022.sbd 2013-11-04T17:03:54.789Z,1383584634.789 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:03:54.837Z,1383584634.837 [NAL9602](INFO): cxum: 43895 2013-11-04T17:04:02.921Z,1383584642.921 [NAL9602](INFO): SBD MO Status=1, MOMSN=20591, MT Status=0, MTMSN=0 2013-11-04T17:04:02.970Z,1383584642.970 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0009.lzma 2013-11-04T17:04:02.970Z,1383584642.970 [NAL9602](INFO): Packets left to send: 21 2013-11-04T17:04:02.971Z,1383584642.971 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0009.lzma.parts/0021.sbd 2013-11-04T17:04:03.419Z,1383584643.419 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:04:03.471Z,1383584643.471 [NAL9602](INFO): cxum: 43319 2013-11-04T17:04:14.398Z,1383584654.398 [NAL9602](INFO): SBD MO Status=1, MOMSN=20592, MT Status=0, MTMSN=0 2013-11-04T17:04:14.448Z,1383584654.448 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0009.lzma 2013-11-04T17:04:14.448Z,1383584654.448 [NAL9602](INFO): Packets left to send: 20 2013-11-04T17:04:14.449Z,1383584654.449 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0009.lzma.parts/0020.sbd 2013-11-04T17:04:14.840Z,1383584654.840 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:04:14.888Z,1383584654.888 [NAL9602](INFO): cxum: 42534 2013-11-04T17:04:22.518Z,1383584662.518 [NAL9602](INFO): SBD MO Status=1, MOMSN=20593, MT Status=0, MTMSN=0 2013-11-04T17:04:22.569Z,1383584662.569 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0009.lzma 2013-11-04T17:04:22.569Z,1383584662.569 [NAL9602](INFO): Packets left to send: 19 2013-11-04T17:04:22.570Z,1383584662.570 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0009.lzma.parts/0019.sbd 2013-11-04T17:04:23.016Z,1383584663.016 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:04:23.069Z,1383584663.069 [NAL9602](INFO): cxum: 45676 2013-11-04T17:04:31.917Z,1383584671.917 [NAL9602](INFO): SBD MO Status=1, MOMSN=20594, MT Status=0, MTMSN=0 2013-11-04T17:04:31.967Z,1383584671.967 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0009.lzma 2013-11-04T17:04:31.967Z,1383584671.967 [NAL9602](INFO): Packets left to send: 18 2013-11-04T17:04:31.968Z,1383584671.968 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0009.lzma.parts/0018.sbd 2013-11-04T17:04:32.407Z,1383584672.407 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:04:32.455Z,1383584672.455 [NAL9602](INFO): cxum: 44376 2013-11-04T17:04:47.307Z,1383584687.307 [NAL9602](INFO): SBD MO Status=1, MOMSN=20595, MT Status=0, MTMSN=0 2013-11-04T17:04:47.359Z,1383584687.359 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0009.lzma 2013-11-04T17:04:47.359Z,1383584687.359 [NAL9602](INFO): Packets left to send: 17 2013-11-04T17:04:47.360Z,1383584687.360 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0009.lzma.parts/0017.sbd 2013-11-04T17:04:47.779Z,1383584687.779 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:04:47.835Z,1383584687.835 [NAL9602](INFO): cxum: 41708 2013-11-04T17:04:59.021Z,1383584699.021 [NAL9602](INFO): SBD MO Status=1, MOMSN=20596, MT Status=0, MTMSN=0 2013-11-04T17:04:59.069Z,1383584699.069 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0009.lzma 2013-11-04T17:04:59.069Z,1383584699.069 [NAL9602](INFO): Packets left to send: 16 2013-11-04T17:04:59.070Z,1383584699.070 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0009.lzma.parts/0016.sbd 2013-11-04T17:04:59.517Z,1383584699.517 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:04:59.569Z,1383584699.569 [NAL9602](INFO): cxum: 44388 2013-11-04T17:05:27.323Z,1383584727.323 [NAL9602](INFO): SBD MO Status=2, MOMSN=20597, MT Status=0, MTMSN=0 2013-11-04T17:05:27.323Z,1383584727.323 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-11-04T17:05:27.323Z,1383584727.323 [NAL9602](INFO): XMIT Failed. Starting over. 2013-11-04T17:05:28.519Z,1383584728.519 [NAL9602](IMPORTANT): GPS fix at: 1383584750.00 2013-11-04T17:05:28.535Z,1383584728.535 [Default:GPS:Read_GPS] Stopped 2013-11-04T17:05:28.535Z,1383584728.535 [Default:GPS:D] Running Loop=1 2013-11-04T17:05:28.938Z,1383584728.938 [Default:GPS:D] Stopped 2013-11-04T17:05:28.938Z,1383584728.938 [Default:GPS](INFO): Completed Default:GPS 2013-11-04T17:05:28.938Z,1383584728.938 [Default:GPS] Stopped 2013-11-04T17:05:28.938Z,1383584728.938 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2013-11-04T17:05:28.938Z,1383584728.938 [Default:GPS:A.SetSpeed] Stopped 2013-11-04T17:05:28.938Z,1383584728.938 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2013-11-04T17:05:32.629Z,1383584732.629 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:05:32.677Z,1383584732.677 [NAL9602](INFO): cxum: 44388 2013-11-04T17:05:43.518Z,1383584743.518 [NAL9602](INFO): SBD MO Status=1, MOMSN=20597, MT Status=0, MTMSN=0 2013-11-04T17:05:43.566Z,1383584743.566 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0009.lzma 2013-11-04T17:05:43.566Z,1383584743.566 [NAL9602](INFO): Packets left to send: 15 2013-11-04T17:05:43.567Z,1383584743.567 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0009.lzma.parts/0015.sbd 2013-11-04T17:05:44.002Z,1383584744.002 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:05:44.050Z,1383584744.050 [NAL9602](INFO): cxum: 40346 2013-11-04T17:05:56.035Z,1383584756.035 [NAL9602](INFO): SBD MO Status=1, MOMSN=20598, MT Status=0, MTMSN=0 2013-11-04T17:05:56.085Z,1383584756.085 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0009.lzma 2013-11-04T17:05:56.086Z,1383584756.086 [NAL9602](INFO): Packets left to send: 14 2013-11-04T17:05:56.087Z,1383584756.087 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0009.lzma.parts/0014.sbd 2013-11-04T17:05:56.534Z,1383584756.534 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:05:56.582Z,1383584756.582 [NAL9602](INFO): cxum: 41616 2013-11-04T17:06:06.620Z,1383584766.620 [NAL9602](INFO): SBD MO Status=1, MOMSN=20599, MT Status=0, MTMSN=0 2013-11-04T17:06:06.670Z,1383584766.670 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0009.lzma 2013-11-04T17:06:06.670Z,1383584766.670 [NAL9602](INFO): Packets left to send: 13 2013-11-04T17:06:06.671Z,1383584766.671 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0009.lzma.parts/0013.sbd 2013-11-04T17:06:07.106Z,1383584767.106 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:06:07.154Z,1383584767.154 [NAL9602](INFO): cxum: 41908 2013-11-04T17:06:24.107Z,1383584784.107 [NAL9602](INFO): SBD MO Status=1, MOMSN=20600, MT Status=0, MTMSN=0 2013-11-04T17:06:24.157Z,1383584784.157 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0009.lzma 2013-11-04T17:06:24.157Z,1383584784.157 [NAL9602](INFO): Packets left to send: 12 2013-11-04T17:06:24.158Z,1383584784.158 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0009.lzma.parts/0012.sbd 2013-11-04T17:06:24.557Z,1383584784.557 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:06:24.606Z,1383584784.606 [NAL9602](INFO): cxum: 41339 2013-11-04T17:06:38.637Z,1383584798.637 [NAL9602](INFO): SBD MO Status=1, MOMSN=20601, MT Status=0, MTMSN=0 2013-11-04T17:06:38.687Z,1383584798.687 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0009.lzma 2013-11-04T17:06:38.688Z,1383584798.688 [NAL9602](INFO): Packets left to send: 11 2013-11-04T17:06:38.689Z,1383584798.689 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0009.lzma.parts/0011.sbd 2013-11-04T17:06:39.140Z,1383584799.140 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:06:39.192Z,1383584799.192 [NAL9602](INFO): cxum: 45772 2013-11-04T17:06:56.820Z,1383584816.820 [NAL9602](INFO): SBD MO Status=1, MOMSN=20602, MT Status=0, MTMSN=0 2013-11-04T17:06:56.868Z,1383584816.868 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0009.lzma 2013-11-04T17:06:56.868Z,1383584816.868 [NAL9602](INFO): Packets left to send: 10 2013-11-04T17:06:56.869Z,1383584816.869 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0009.lzma.parts/0010.sbd 2013-11-04T17:06:57.300Z,1383584817.300 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:06:57.348Z,1383584817.348 [NAL9602](INFO): cxum: 42420 2013-11-04T17:07:06.937Z,1383584826.937 [NAL9602](INFO): SBD MO Status=1, MOMSN=20603, MT Status=0, MTMSN=0 2013-11-04T17:07:06.987Z,1383584826.987 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0009.lzma 2013-11-04T17:07:06.987Z,1383584826.987 [NAL9602](INFO): Packets left to send: 9 2013-11-04T17:07:06.989Z,1383584826.989 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0009.lzma.parts/0009.sbd 2013-11-04T17:07:07.432Z,1383584827.432 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:07:07.480Z,1383584827.480 [NAL9602](INFO): cxum: 43632 2013-11-04T17:07:19.128Z,1383584839.128 [NAL9602](INFO): SBD MO Status=1, MOMSN=20604, MT Status=0, MTMSN=0 2013-11-04T17:07:19.178Z,1383584839.178 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0009.lzma 2013-11-04T17:07:19.178Z,1383584839.178 [NAL9602](INFO): Packets left to send: 8 2013-11-04T17:07:19.180Z,1383584839.180 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0009.lzma.parts/0008.sbd 2013-11-04T17:07:19.603Z,1383584839.603 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:07:19.651Z,1383584839.651 [NAL9602](INFO): cxum: 42764 2013-11-04T17:07:32.417Z,1383584852.417 [NAL9602](INFO): SBD MO Status=1, MOMSN=20605, MT Status=0, MTMSN=0 2013-11-04T17:07:32.467Z,1383584852.467 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0009.lzma 2013-11-04T17:07:32.467Z,1383584852.467 [NAL9602](INFO): Packets left to send: 7 2013-11-04T17:07:32.468Z,1383584852.468 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0009.lzma.parts/0007.sbd 2013-11-04T17:07:32.903Z,1383584852.903 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:07:32.951Z,1383584852.951 [NAL9602](INFO): cxum: 42922 2013-11-04T17:07:57.428Z,1383584877.428 [NAL9602](INFO): SBD MO Status=2, MOMSN=20606, MT Status=2, MTMSN=0 2013-11-04T17:07:57.428Z,1383584877.428 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-11-04T17:07:57.428Z,1383584877.428 [NAL9602](INFO): XMIT Failed. Starting over. 2013-11-04T17:08:02.741Z,1383584882.741 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:08:02.790Z,1383584882.790 [NAL9602](INFO): cxum: 42922 2013-11-04T17:08:15.708Z,1383584895.708 [NAL9602](INFO): SBD MO Status=1, MOMSN=20606, MT Status=0, MTMSN=0 2013-11-04T17:08:15.758Z,1383584895.758 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0009.lzma 2013-11-04T17:08:15.758Z,1383584895.758 [NAL9602](INFO): Packets left to send: 6 2013-11-04T17:08:15.759Z,1383584895.759 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0009.lzma.parts/0006.sbd 2013-11-04T17:08:16.178Z,1383584896.178 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:08:16.234Z,1383584896.234 [NAL9602](INFO): cxum: 39822 2013-11-04T17:08:26.223Z,1383584906.223 [NAL9602](INFO): SBD MO Status=1, MOMSN=20607, MT Status=0, MTMSN=0 2013-11-04T17:08:26.270Z,1383584906.270 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0009.lzma 2013-11-04T17:08:26.270Z,1383584906.270 [NAL9602](INFO): Packets left to send: 5 2013-11-04T17:08:26.272Z,1383584906.272 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0009.lzma.parts/0005.sbd 2013-11-04T17:08:26.699Z,1383584906.699 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:08:26.747Z,1383584906.747 [NAL9602](INFO): cxum: 42743 2013-11-04T17:08:39.221Z,1383584919.221 [NAL9602](INFO): SBD MO Status=1, MOMSN=20608, MT Status=0, MTMSN=0 2013-11-04T17:08:39.270Z,1383584919.270 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0009.lzma 2013-11-04T17:08:39.271Z,1383584919.271 [NAL9602](INFO): Packets left to send: 4 2013-11-04T17:08:39.272Z,1383584919.272 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0009.lzma.parts/0004.sbd 2013-11-04T17:08:39.711Z,1383584919.711 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:08:39.759Z,1383584919.759 [NAL9602](INFO): cxum: 44315 2013-11-04T17:08:50.602Z,1383584930.602 [NAL9602](INFO): SBD MO Status=1, MOMSN=20609, MT Status=0, MTMSN=0 2013-11-04T17:08:50.660Z,1383584930.660 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0009.lzma 2013-11-04T17:08:50.660Z,1383584930.660 [NAL9602](INFO): Packets left to send: 3 2013-11-04T17:08:50.661Z,1383584930.661 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0009.lzma.parts/0003.sbd 2013-11-04T17:08:51.084Z,1383584931.084 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:08:51.133Z,1383584931.133 [NAL9602](INFO): cxum: 42624 2013-11-04T17:09:09.219Z,1383584949.219 [NAL9602](INFO): SBD MO Status=1, MOMSN=20610, MT Status=0, MTMSN=0 2013-11-04T17:09:09.269Z,1383584949.269 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0009.lzma 2013-11-04T17:09:09.269Z,1383584949.269 [NAL9602](INFO): Packets left to send: 2 2013-11-04T17:09:09.270Z,1383584949.270 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0009.lzma.parts/0002.sbd 2013-11-04T17:09:09.717Z,1383584949.717 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:09:09.769Z,1383584949.769 [NAL9602](INFO): cxum: 43069 2013-11-04T17:09:22.209Z,1383584962.209 [NAL9602](INFO): SBD MO Status=1, MOMSN=20611, MT Status=0, MTMSN=0 2013-11-04T17:09:22.262Z,1383584962.262 [NAL9602](INFO): Sent 332 bytes from file Logs/20131031T231648/Express0009.lzma 2013-11-04T17:09:22.262Z,1383584962.262 [NAL9602](INFO): Packets left to send: 1 2013-11-04T17:09:22.263Z,1383584962.263 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0009.lzma.parts/0001.sbd 2013-11-04T17:09:22.689Z,1383584962.689 [NAL9602](INFO): Loading bytes: 330 2013-11-04T17:09:22.738Z,1383584962.738 [NAL9602](INFO): cxum: 41727 2013-11-04T17:09:32.026Z,1383584972.026 [NAL9602](INFO): SBD MO Status=1, MOMSN=20612, MT Status=0, MTMSN=0 2013-11-04T17:09:32.076Z,1383584972.076 [NAL9602](INFO): Sent 322 bytes from file Logs/20131031T231648/Express0009.lzma 2013-11-04T17:09:32.076Z,1383584972.076 [NAL9602](INFO): Packets left to send: 0 2013-11-04T17:09:32.078Z,1383584972.078 [NAL9602](INFO): Stored copy of sent data in Logs/20131031T231648/Express0009.lzma.parts/0000.sbd 2013-11-04T17:09:33.005Z,1383584973.005 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:09:33.054Z,1383584973.054 [NAL9602](INFO): cxum: 41108 2013-11-04T17:09:43.993Z,1383584983.993 [NAL9602](INFO): SBD MO Status=1, MOMSN=20613, MT Status=0, MTMSN=0 2013-11-04T17:09:44.043Z,1383584984.043 [NAL9602](INFO): Sent 332 bytes from file Logs/20131104T165022/Express0001.lzma 2013-11-04T17:09:44.043Z,1383584984.043 [NAL9602](INFO): Packets left to send: 7 2013-11-04T17:09:44.045Z,1383584984.045 [NAL9602](INFO): Stored copy of sent data in Logs/20131104T165022/Express0001.lzma.parts/0007.sbd 2013-11-04T17:09:44.443Z,1383584984.443 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:09:44.491Z,1383584984.491 [NAL9602](INFO): cxum: 41810 2013-11-04T17:10:02.921Z,1383585002.921 [NAL9602](INFO): SBD MO Status=2, MOMSN=20614, MT Status=2, MTMSN=0 2013-11-04T17:10:02.921Z,1383585002.921 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-11-04T17:10:02.921Z,1383585002.921 [NAL9602](INFO): XMIT Failed. Starting over. 2013-11-04T17:10:08.228Z,1383585008.228 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:10:08.280Z,1383585008.280 [NAL9602](INFO): cxum: 41810 2013-11-04T17:10:23.606Z,1383585023.606 [NAL9602](INFO): SBD MO Status=1, MOMSN=20614, MT Status=0, MTMSN=0 2013-11-04T17:10:23.656Z,1383585023.656 [NAL9602](INFO): Sent 332 bytes from file Logs/20131104T165022/Express0001.lzma 2013-11-04T17:10:23.657Z,1383585023.657 [NAL9602](INFO): Packets left to send: 6 2013-11-04T17:10:23.658Z,1383585023.658 [NAL9602](INFO): Stored copy of sent data in Logs/20131104T165022/Express0001.lzma.parts/0006.sbd 2013-11-04T17:10:24.081Z,1383585024.081 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:10:24.133Z,1383585024.133 [NAL9602](INFO): cxum: 43119 2013-11-04T17:10:36.586Z,1383585036.586 [NAL9602](INFO): SBD MO Status=1, MOMSN=20615, MT Status=0, MTMSN=0 2013-11-04T17:10:36.644Z,1383585036.644 [NAL9602](INFO): Sent 332 bytes from file Logs/20131104T165022/Express0001.lzma 2013-11-04T17:10:36.644Z,1383585036.644 [NAL9602](INFO): Packets left to send: 5 2013-11-04T17:10:36.646Z,1383585036.646 [NAL9602](INFO): Stored copy of sent data in Logs/20131104T165022/Express0001.lzma.parts/0005.sbd 2013-11-04T17:10:37.045Z,1383585037.045 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:10:37.093Z,1383585037.093 [NAL9602](INFO): cxum: 41849 2013-11-04T17:10:49.190Z,1383585049.190 [NAL9602](INFO): SBD MO Status=1, MOMSN=20616, MT Status=0, MTMSN=0 2013-11-04T17:10:49.236Z,1383585049.236 [NAL9602](INFO): Sent 332 bytes from file Logs/20131104T165022/Express0001.lzma 2013-11-04T17:10:49.236Z,1383585049.236 [NAL9602](INFO): Packets left to send: 4 2013-11-04T17:10:49.237Z,1383585049.237 [NAL9602](INFO): Stored copy of sent data in Logs/20131104T165022/Express0001.lzma.parts/0004.sbd 2013-11-04T17:10:49.644Z,1383585049.644 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:10:49.696Z,1383585049.696 [NAL9602](INFO): cxum: 42597 2013-11-04T17:11:02.108Z,1383585062.108 [NAL9602](INFO): SBD MO Status=1, MOMSN=20617, MT Status=0, MTMSN=0 2013-11-04T17:11:02.160Z,1383585062.160 [NAL9602](INFO): Sent 332 bytes from file Logs/20131104T165022/Express0001.lzma 2013-11-04T17:11:02.160Z,1383585062.160 [NAL9602](INFO): Packets left to send: 3 2013-11-04T17:11:02.161Z,1383585062.161 [NAL9602](INFO): Stored copy of sent data in Logs/20131104T165022/Express0001.lzma.parts/0003.sbd 2013-11-04T17:11:02.564Z,1383585062.564 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:11:02.620Z,1383585062.620 [NAL9602](INFO): cxum: 41836 2013-11-04T17:11:15.005Z,1383585075.005 [NAL9602](INFO): SBD MO Status=1, MOMSN=20618, MT Status=0, MTMSN=0 2013-11-04T17:11:15.060Z,1383585075.060 [NAL9602](INFO): Sent 332 bytes from file Logs/20131104T165022/Express0001.lzma 2013-11-04T17:11:15.060Z,1383585075.060 [NAL9602](INFO): Packets left to send: 2 2013-11-04T17:11:15.061Z,1383585075.061 [NAL9602](INFO): Stored copy of sent data in Logs/20131104T165022/Express0001.lzma.parts/0002.sbd 2013-11-04T17:11:15.484Z,1383585075.484 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:11:15.532Z,1383585075.532 [NAL9602](INFO): cxum: 41728 2013-11-04T17:11:28.831Z,1383585088.831 [NAL9602](INFO): SBD MO Status=1, MOMSN=20619, MT Status=0, MTMSN=0 2013-11-04T17:11:28.884Z,1383585088.884 [NAL9602](INFO): Sent 332 bytes from file Logs/20131104T165022/Express0001.lzma 2013-11-04T17:11:28.884Z,1383585088.884 [NAL9602](INFO): Packets left to send: 1 2013-11-04T17:11:28.885Z,1383585088.885 [NAL9602](INFO): Stored copy of sent data in Logs/20131104T165022/Express0001.lzma.parts/0001.sbd 2013-11-04T17:11:29.322Z,1383585089.322 [NAL9602](INFO): Loading bytes: 11 2013-11-04T17:11:29.370Z,1383585089.370 [NAL9602](INFO): cxum: 905 2013-11-04T17:11:39.819Z,1383585099.819 [NAL9602](INFO): SBD MO Status=1, MOMSN=20620, MT Status=0, MTMSN=0 2013-11-04T17:11:39.866Z,1383585099.866 [NAL9602](INFO): Sent 3 bytes from file Logs/20131104T165022/Express0001.lzma 2013-11-04T17:11:39.867Z,1383585099.867 [NAL9602](INFO): Packets left to send: 0 2013-11-04T17:11:39.868Z,1383585099.868 [NAL9602](INFO): Stored copy of sent data in Logs/20131104T165022/Express0001.lzma.parts/0000.sbd 2013-11-04T17:11:40.812Z,1383585100.812 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:11:40.860Z,1383585100.860 [NAL9602](INFO): cxum: 41060 2013-11-04T17:11:51.717Z,1383585111.717 [NAL9602](INFO): SBD MO Status=1, MOMSN=20621, MT Status=0, MTMSN=0 2013-11-04T17:11:51.765Z,1383585111.765 [NAL9602](INFO): Sent 332 bytes from file Logs/20131104T165022/Express0005.lzma 2013-11-04T17:11:51.765Z,1383585111.765 [NAL9602](INFO): Packets left to send: 9 2013-11-04T17:11:51.767Z,1383585111.767 [NAL9602](INFO): Stored copy of sent data in Logs/20131104T165022/Express0005.lzma.parts/0009.sbd 2013-11-04T17:11:52.197Z,1383585112.197 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:11:52.245Z,1383585112.245 [NAL9602](INFO): cxum: 42735 2013-11-04T17:12:03.593Z,1383585123.593 [NAL9602](INFO): SBD MO Status=2, MOMSN=20622, MT Status=2, MTMSN=0 2013-11-04T17:12:03.594Z,1383585123.594 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-11-04T17:12:03.594Z,1383585123.594 [NAL9602](INFO): XMIT Failed. Starting over. 2013-11-04T17:14:23.035Z,1383585263.035 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:14:23.083Z,1383585263.083 [NAL9602](INFO): cxum: 42735 2013-11-04T17:14:36.688Z,1383585276.688 [NAL9602](INFO): SBD MO Status=2, MOMSN=20622, MT Status=2, MTMSN=0 2013-11-04T17:14:36.689Z,1383585276.689 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-11-04T17:14:36.689Z,1383585276.689 [NAL9602](INFO): XMIT Failed. Starting over. 2013-11-04T17:14:42.117Z,1383585282.117 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:14:42.165Z,1383585282.165 [NAL9602](INFO): cxum: 42735 2013-11-04T17:15:01.409Z,1383585301.409 [NAL9602](INFO): SBD MO Status=2, MOMSN=20622, MT Status=2, MTMSN=0 2013-11-04T17:15:01.409Z,1383585301.409 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-11-04T17:15:01.409Z,1383585301.409 [NAL9602](INFO): XMIT Failed. Starting over. 2013-11-04T17:15:48.540Z,1383585348.540 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:15:48.588Z,1383585348.588 [NAL9602](INFO): cxum: 42735 2013-11-04T17:16:13.015Z,1383585373.015 [NAL9602](INFO): SBD MO Status=1, MOMSN=20622, MT Status=0, MTMSN=0 2013-11-04T17:16:13.062Z,1383585373.062 [NAL9602](INFO): Sent 332 bytes from file Logs/20131104T165022/Express0005.lzma 2013-11-04T17:16:13.062Z,1383585373.062 [NAL9602](INFO): Packets left to send: 8 2013-11-04T17:16:13.063Z,1383585373.063 [NAL9602](INFO): Stored copy of sent data in Logs/20131104T165022/Express0005.lzma.parts/0008.sbd 2013-11-04T17:16:13.490Z,1383585373.490 [NAL9602](INFO): Loading bytes: 340 2013-11-04T17:16:13.538Z,1383585373.538 [NAL9602](INFO): cxum: 43144 2013-11-04T17:16:17.369Z,1383585377.369 [CommandLine](IMPORTANT): got command quit 2013-11-04T17:16:18.446Z,1383585378.446 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2013-11-04T17:16:18.446Z,1383585378.446 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2013-11-04T17:16:18.790Z,1383585378.790 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2013-11-04T17:16:19.127Z,1383585379.127 [WetLabsBB2FL](INFO): Powering down 2013-11-04T17:16:19.143Z,1383585379.143 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler 2013-11-04T17:16:19.428Z,1383585379.428 [CTD_NeilBrown](INFO): Powering down 2013-11-04T17:16:19.445Z,1383585379.445 [ComponentRegistry](INFO): Shutting down DVL_micro ThreadHandler 2013-11-04T17:16:19.588Z,1383585379.588 [DVL_micro](INFO): uninitialize:Powering down 2013-11-04T17:16:19.604Z,1383585379.604 [ComponentRegistry](INFO): Shutting down AsyncPiEstimator ThreadHandler 2013-11-04T17:16:19.884Z,1383585379.884 [AsyncPiEstimator](DEBUG): Uninitialize AsyncPiEstimator. 2013-11-04T17:16:19.905Z,1383585379.905 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2013-11-04T17:16:19.925Z,1383585379.925 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2013-11-04T17:16:19.927Z,1383585379.927 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2013-11-04T17:16:20.024Z,1383585380.024 [controlThread](DEBUG): Uninitializing ControlThread 2013-11-04T17:16:20.025Z,1383585380.025 [AHRS_sp3003D](INFO): Powering down 2013-11-04T17:16:20.113Z,1383585380.113 [NAL9602](INFO): Powering down 2013-11-04T17:16:20.115Z,1383585380.115 [DAT](INFO): Powering down 2013-11-04T17:16:20.116Z,1383585380.116 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2013-11-04T17:16:20.116Z,1383585380.116 [NavChart](DEBUG): Uninitialize NavChart Derivation. 2013-11-04T17:16:20.117Z,1383585380.117 [Default] Stopped 2013-11-04T17:16:20.117Z,1383585380.117 [Default](INFO): Aggregate::uninitialize Default 2013-11-04T17:16:20.118Z,1383585380.118 [Default:Iridium] Stopped 2013-11-04T17:16:20.118Z,1383585380.118 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2013-11-04T17:16:20.118Z,1383585380.118 [Default:Iridium:A.SetSpeed] Stopped 2013-11-04T17:16:20.118Z,1383585380.118 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2013-11-04T17:16:20.118Z,1383585380.118 [Default:Iridium:Read_Iridium] Stopped 2013-11-04T17:16:20.118Z,1383585380.118 [Default:CallIridium] Stopped 2013-11-04T17:16:20.118Z,1383585380.118 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2013-11-04T17:16:20.118Z,1383585380.118 [Default:CallIridium:B] Stopped 2013-11-04T17:16:20.118Z,1383585380.118 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2013-11-04T17:16:20.118Z,1383585380.118 [Default:D.SetSpeed] Stopped 2013-11-04T17:16:20.118Z,1383585380.118 [Default:D.SetSpeed](DEBUG): Uninitialize. 2013-11-04T17:16:20.118Z,1383585380.118 [Default:E.GoToSurface] Stopped 2013-11-04T17:16:20.119Z,1383585380.119 [Default:E.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-11-04T17:16:20.123Z,1383585380.123 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2013-11-04T17:16:20.123Z,1383585380.123 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2013-11-04T17:16:20.123Z,1383585380.123 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2013-11-04T17:16:20.124Z,1383585380.124 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2013-11-04T17:16:20.124Z,1383585380.124 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2013-11-04T17:16:20.124Z,1383585380.124 [BuoyancyServo](INFO): Powering down 2013-11-04T17:16:20.137Z,1383585380.137 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2013-11-04T17:16:20.137Z,1383585380.137 [ElevatorServo](INFO): Powering down 2013-11-04T17:16:20.138Z,1383585380.138 [MassServo](DEBUG): Uninitialize Mass Servo. 2013-11-04T17:16:20.138Z,1383585380.138 [MassServo](INFO): Powering down 2013-11-04T17:16:20.139Z,1383585380.139 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2013-11-04T17:16:20.139Z,1383585380.139 [RudderServo](INFO): Powering down 2013-11-04T17:16:20.140Z,1383585380.140 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2013-11-04T17:16:20.140Z,1383585380.140 [ThrusterServo](INFO): Powering down 2013-11-04T17:16:20.141Z,1383585380.141 [SBIT](DEBUG): Uninitialize SBIT Component. 2013-11-04T17:16:20.141Z,1383585380.141 [IBIT](DEBUG): Uninitialize IBIT Component. 2013-11-04T17:16:20.142Z,1383585380.142 [CBIT](DEBUG): Uninitialize CBIT Component.